Mirror takes a long time to update repositories

お困りですか?

アトラシアン コミュニティをご利用ください。

コミュニティに質問

プラットフォームについて: Data Center のみ - この記事は、Data Center プラットフォームのアトラシアン製品にのみ適用されます。

この KB は Data Center バージョンの製品用に作成されています。Data Center 固有ではない機能の Data Center KB は、製品のサーバー バージョンでも動作する可能性はありますが、テストは行われていません。サーバー*製品のサポートは 2024 年 2 月 15 日に終了しました。サーバー製品を利用している場合は、アトラシアンのサーバー製品のサポート終了のお知らせページにて移行オプションをご確認ください。

*Fisheye および Crucible は除く

要約

Mirror updates multiple repositories with a serious delay, which may take up to 30 minutes.
Other mirrors may be updating repositories almost instantaneously.

環境

This issue may affect Mirrors in various environments.
It has been seen on Bitbucket Data Center version 7.21.4 with a stand-alone Mirror version 7.21.4, but it may also affect other versions and multi-node Mirror Farms.

診断

The delay may be caused by two different issues described below.
You should check if any of these issues occurs in your instance, and apply the corresponding solution.

Issue #1

The Upstream Cluster fails to send the notifications of the repository updates to the Mirror.
In the application logs of the Upstream Cluster nodes you may see messages similar to the following:

(info) The following error will only show in the stack trace if there is debug logging enabled on class com.atlassian.webhooks, for example:

curl -X PUT -H "Accept: application/json" -H "Content-Type: application/json" -u <admin> $BITBUCKET_URL/rest/api/latest/logs/logger/com.atlassian.webhooks/debug
atlassian-bitbucket.log
2022-09-14 10:33:42,424 INFO  [ForkJoinPool.commonPool-worker-27]  c.a.w.i.p.DefaultWebhookDispatcher Webhook invocation [80740cd2-f8ee-42aa-9c9b-a46d37286deb] to [<Mirror's_URL>/rest/mirroring/latest/upstreamServers/40632034-531d-1a84-7323-cf2b66dc8527/addon/events] failed with an error
java.lang.RuntimeException: javax.net.ssl.SSLHandshakeException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target
	at com.atlassian.httpclient.apache.httpcomponents.ApacheAsyncHttpClient.lambda$doExecute$5(ApacheAsyncHttpClient.java:328)
	at io.atlassian.util.concurrent.Promises.lambda$biFunction$7(Promises.java:424)
	at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:836)
	at java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:811)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
	at com.atlassian.httpclient.apache.httpcomponents.SettableFuturePromiseHttpPromiseAsyncClient$1.lambda$doFailed$1(SettableFuturePromiseHttpPromiseAsyncClient.java:42)
	at com.atlassian.httpclient.apache.httpcomponents.SettableFuturePromiseHttpPromiseAsyncClient.runInContext(SettableFuturePromiseHttpPromiseAsyncClient.java:61)
	at com.atlassian.httpclient.apache.httpcomponents.SettableFuturePromiseHttpPromiseAsyncClient$ThreadLocalDelegateRunnable.run(SettableFuturePromiseHttpPromiseAsyncClient.java:129)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.lang.Thread.run(Thread.java:750)
	... 1 frame trimmed
Caused by: javax.net.ssl.SSLHandshakeException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target
	at sun.security.ssl.Alert.createSSLException(Alert.java:131)
	at sun.security.ssl.TransportContext.fatal(TransportContext.java:324)
	at sun.security.ssl.TransportContext.fatal(TransportContext.java:267)
	at sun.security.ssl.TransportContext.fatal(TransportContext.java:262)
	at sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkServerCerts(CertificateMessage.java:654)
	at sun.security.ssl.CertificateMessage$T12CertificateConsumer.onCertificate(CertificateMessage.java:473)
	at sun.security.ssl.CertificateMessage$T12CertificateConsumer.consume(CertificateMessage.java:369)
	at sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:377)
	at sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:444)
	at sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:981)
	at sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:968)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.security.ssl.SSLEngineImpl$DelegatedTask.run(SSLEngineImpl.java:915)
	at org.apache.http.nio.reactor.ssl.SSLIOSession.doRunTask(SSLIOSession.java:288)
	at org.apache.http.nio.reactor.ssl.SSLIOSession.doHandshake(SSLIOSession.java:356)
	at org.apache.http.nio.reactor.ssl.SSLIOSession.isAppInputReady(SSLIOSession.java:541)
	at org.apache.http.impl.nio.reactor.AbstractIODispatch.inputReady(AbstractIODispatch.java:120)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvents(AbstractIOReactor.java:315)
	at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:276)
	at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
	at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:591)
	at java.lang.Thread.run(Thread.java:750)
Caused by: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target
	at sun.security.validator.PKIXValidator.doBuild(PKIXValidator.java:456)

(info) The debug logging should be disabled after troubleshooting with:

curl -X PUT -H "Accept: application/json" -H "Content-Type: application/json" -u <admin> $BITBUCKET_URL/rest/api/latest/logs/logger/com.atlassian.webhooks/info



Issue #2

On the Mirror itself, a long-running operation may have set a lock, which keeps the repository updates waiting.
In such case, in the application logs of the Mirror, you could see messages similar to the following:

atlassian-bitbucket.log
2022-09-16 12:12:33,581 ERROR [farm-operation-2] @1PMB2TCx723x1753918131x1678 c.a.b.i.m.m.f.t.ReplyingTopicListener Error while processing request TopicRequest{message=RefChangeChunk{farmSynchronizationRequest=FarmSynchronizationRequest{externalRepositoryId=12345, type=snapshot}, last=true, index=0, digest=c0a4ced2f2e81ce803ada4e05d8fcaa862a1833b, payload.length=1357}, replyTopic=refChangeChunk_325eb5f4-b816-43ef-8e43-cd297c953783_reply, anticipatedResponders=1}
com.atlassian.bitbucket.scm.CommandFailedException: '/usr/local/git/bin/git -c core.abbrev=40 -c credential.helper= -c gc.auto=0 fetch --force --progress --no-tags ssh://git@bitbucket:7999/project/repository.git 598cba0ef82c5bc2d60725f41b35067fcd7b8eb2 b3da67e395052fb7cb1ef4f4ec8245c4b0adc08c 84bf97d81a25e64d1d0c4cd41e729b93340b394e 6832554dc8223345e8d0173b5f6e53c459f83515 318ad6bbac570881956969430fef1bd6cde732d7' exited with code 128 saying: Warning: Permanently added '[bitbucket]:7999,[10.123.134.156]:7999' (RSA) to the list of known hosts.
fatal: cannot read existing object info 75a826854f17487ba4610eff3fd50a6d87fb2ed9
fatal: index-pack failed
	at com.atlassian.bitbucket.scm.DefaultCommandExitHandler.onError(DefaultCommandExitHandler.java:47)
	at com.atlassian.bitbucket.scm.git.command.GitCommandExitHandler.evaluateThrowable(GitCommandExitHandler.java:130)
	at com.atlassian.bitbucket.scm.git.command.GitCommandExitHandler.onError(GitCommandExitHandler.java:239)
	at com.atlassian.bitbucket.scm.DefaultCommandExitHandler.onExit(DefaultCommandExitHandler.java:32)
	at com.atlassian.stash.internal.scm.git.command.fetch.FetchExitHandler.onExit(FetchExitHandler.java:39)
	at com.atlassian.bitbucket.internal.process.nu.NioNuProcessHandler.callExitHandler(NioNuProcessHandler.java:340)
	at com.atlassian.bitbucket.internal.process.nu.NioNuProcessHandler.finish(NioNuProcessHandler.java:381)
	at com.atlassian.bitbucket.internal.process.nu.NioNuProcessHandler.onExit(NioNuProcessHandler.java:136)
	at com.zaxxer.nuprocess.internal.BasePosixProcess.onExit(BasePosixProcess.java:315)
	at com.zaxxer.nuprocess.linux.ProcessEpoll.handleExit(ProcessEpoll.java:367)
	at com.zaxxer.nuprocess.linux.ProcessEpoll.cleanupProcess(ProcessEpoll.java:320)
	at com.zaxxer.nuprocess.linux.ProcessEpoll.process(ProcessEpoll.java:255)
	at com.zaxxer.nuprocess.internal.BaseEventProcessor.run(BaseEventProcessor.java:82)
	at com.zaxxer.nuprocess.linux.ProcessEpoll.run(ProcessEpoll.java:156)
	at com.zaxxer.nuprocess.linux.LinuxProcess.run(LinuxProcess.java:110)
	at com.zaxxer.nuprocess.linux.LinProcessFactory.runProcess(LinProcessFactory.java:50)
	at com.zaxxer.nuprocess.NuProcessBuilder.run(NuProcessBuilder.java:277)
	at com.atlassian.bitbucket.internal.process.nu.NuNioProcessHelper.run(NuNioProcessHelper.java:76)
	at com.atlassian.bitbucket.internal.process.NioCommand.call(NioCommand.java:46)
	at com.atlassian.stash.internal.scm.git.command.SimpleGitCommand.configureAndCall(SimpleGitCommand.java:84)
	at com.atlassian.stash.internal.scm.git.command.fetch.MirrorSynchronizeCommand.doFetch(MirrorSynchronizeCommand.java:126)
	at com.atlassian.stash.internal.scm.git.command.fetch.MirrorSynchronizeCommand.call(MirrorSynchronizeCommand.java:97)
	at com.atlassian.stash.internal.scm.git.command.fetch.MirrorSynchronizeCommand.call(MirrorSynchronizeCommand.java:35)
	at com.atlassian.bitbucket.internal.mirroring.mirror.command.MirroringCommandFactory$CredentialRefreshingCommandDecorator.call(MirroringCommandFactory.java:156)
	at com.atlassian.bitbucket.internal.mirroring.mirror.command.MirroringCommandFactory$CredentialRefreshingCommandDecorator.call(MirroringCommandFactory.java:132)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.synchronization.ObjectFetchHelper.lambda$perform$0(ObjectFetchHelper.java:66)
	at java.util.Iterator.forEachRemaining(Iterator.java:116)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.synchronization.ObjectFetchHelper.perform(ObjectFetchHelper.java:56)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.synchronization.RepositorySynchronizationOperation.perform(RepositorySynchronizationOperation.java:125)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.synchronization.RepositorySynchronizationOperation.perform(RepositorySynchronizationOperation.java:41)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.topic.operation.MetricCollectingMirrorOperation.perform(MetricCollectingMirrorOperation.java:66)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.refchange.RefChangeChunkOperation.perform(RefChangeChunkOperation.java:101)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.refchange.RefChangeChunkOperation.perform(RefChangeChunkOperation.java:63)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.topic.operation.AuthenticatedMirrorOperation.lambda$perform$0(AuthenticatedMirrorOperation.java:37)
	at com.atlassian.stash.internal.user.DefaultEscalatedSecurityContext.call(DefaultEscalatedSecurityContext.java:59)
	at com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamUserHelper.performAsUpstreamUser(DefaultUpstreamUserHelper.java:93)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.topic.operation.AuthenticatedMirrorOperation.perform(AuthenticatedMirrorOperation.java:37)
	at com.atlassian.bitbucket.internal.mirroring.mirror.farm.topic.operation.MultiThreadedMirrorOperation.lambda$perform$0(MultiThreadedMirrorOperation.java:45)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:57)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
	at com.atlassian.sal.core.executor.ThreadLocalDelegateRunnable.run(ThreadLocalDelegateRunnable.java:34)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.lang.Thread.run(Thread.java:750)
	... 1 frame trimmed
Caused by: com.atlassian.utils.process.ProcessException: Non-zero exit code: 128
	at com.atlassian.bitbucket.internal.process.nu.NioNuProcessHandler.callExitHandler(NioNuProcessHandler.java:332)
	... 39 common frames omitted


原因

Issue #1

This error indicates that the Upstream Cluster node does not trust the SSL certificate of the affected Mirror.
When the Upstream Cluster node processes a change to a repository, it runs a webhook that sends a notification of the change to the Mirror.
This notification uses HTTPS protocol, and since the Mirror's SSL certificate is not trusted, the webhook fails, and the notification is never sent.
The Mirror never receives any such notifications, so it may only update the change repositories later, when the FarmVet runs and detects the inconsistency, which explains the observed delay.

Issue #2

A broken Git repository on the affected Mirror makes it impossible to update it. Each time the FarmVet runs, it detects the inconsistency and tries to repair this repository. Each such attempt has to fail, but sometimes it may take a very long time to fail (in some cases, we saw it take almost 8 minutes). Meanwhile, all the other updates have to wait for this long-running operation to finish. This would explain the observed delay in updating all the other repositories.



ソリューション

Once you have confirmed which of these two issues is affecting your Mirror, please apply the corresponding solution below.

Issue #1

Use a trusted SSL certificate on the Mirror, or configure all the Upstream Cluster nodes to trust the SSL certificate that the Mirror is currently using.
For more information, please refer to: Set up a mirror, section: 2. Set up HTTPS on the mirror
Confirm that the aforementioned INFO message no longer logged on any of your Upstream Cluster nodes.

Issue #2

Ideally, repair the broken repository, or remove it from the affected Mirror (for example, you could move this repository to a different project, which is not mirrored).
If this is not immediately possible, as a temporary workaround, you could edit the Mirror's bitbucket.properties file and add a line similar to the one below, then restart the Mirror:

Mirror's bitbucket.properties
plugin.mirroring.lock.harvest.interval=180

This will reduce the frequency of harvesting the lock (from default 1 minute to 3 minutes) and lower the chance of the updates for healthy repositories to wait on the long-running operation.

最終更新日 2023 年 8 月 4 日

この内容はお役に立ちましたか?

はい
いいえ
この記事についてのフィードバックを送信する
Powered by Confluence and Scroll Viewport.