Mesh sidecar fails to start

[Paul Podgorsek]

I recently migrated from Bitbucket server 7.18.3 to 8.1.0.

I am unfortunately facing a problem with the new mesh approach for git. Given the abysmal lack of mesh-related documentation provided by Atlassian, it is very hard to understand how it works and what the issue might be.

The relevant log line I can see before Spring fails is:

WARN [spring-startup] c.a.s.i.s.g.m.DefaultSidecarManager Sidecar has not fully started after 15246ms. Bitbucket will continue starting. More details may be available in the Mesh logs

I am running Bitbucket server in Kubernetes, my deployment relies on the standard ports for http, ssh and Hazelcast. Moreover, I'm mounting an NFS share onto /var/atlassian/application-data/bitbucket. (apart from the Bitbucket version change, this is the exact same setup which was working for version 7.18.3)

Would anyone have any idea about what might cause this problem please?

---

Here are the complete logs from my server:

2022-06-16 21:40:24,556 INFO [main] c.a.b.i.b.BitbucketServerApplication Starting BitbucketServerApplication v8.1.0 using Java 11.0.15 on bitbucket-deployment-fd466845f-tb2wk with PID 8 (/opt/atlassian/bitbucket/app/WEB-INF/classes started by bitbucket in /var/atlassian/application-data/bitbucket)
2022-06-16 21:40:24,560 INFO [main] c.a.b.i.b.BitbucketServerApplication No active profile set, falling back to 1 default profile: "default"
2022-06-16 21:40:25,084 INFO [main] c.a.b.i.boot.log.BuildInfoLogger Starting Bitbucket 8.1.0 (490f8b1 built on Fri May 20 06:16:22 UTC 2022)
2022-06-16 21:40:25,085 INFO [main] c.a.b.i.boot.log.BuildInfoLogger JVM: Eclipse Adoptium OpenJDK 64-Bit Server VM 11.0.15+10
2022-06-16 21:40:26,310 INFO [main] c.a.b.i.b.BitbucketServerApplication Started BitbucketServerApplication in 3.009 seconds (JVM running for 3.718)
2022-06-16 21:40:28,771 INFO [spring-startup] c.a.s.internal.home.HomeLockAcquirer Successfully acquired lock on home directory /var/atlassian/application-data/bitbucket
2022-06-16 21:40:28,805 WARN [spring-startup] c.a.s.internal.home.HomeValidator Downgrading Bitbucket from 8.1.1 to 8.1.0
2022-06-16 21:40:32,550 INFO [spring-startup] c.a.s.internal.home.HomeLockAcquirer Successfully acquired lock on home directory /var/atlassian/application-data/bitbucket/shared
2022-06-16 21:40:34,168 WARN [spring-startup] com.hazelcast.instance.Node [10.0.0.151]:5701 [bitbucket] [3.12.12] No join method is enabled! Starting standalone.
2022-06-16 21:41:01,371 WARN [spring-startup] c.a.s.i.s.g.m.DefaultSidecarManager Sidecar has not fully started after 15246ms. Bitbucket will continue starting. More details may be available in the Mesh logs
2022-06-16 21:41:05,401 INFO [spring-startup] c.a.s.i.hook.DefaultHookService Hook callback socket listening on 127.0.0.1:43727
2022-06-16 21:41:08,957 INFO [hz.hazelcast.event-1] c.a.s.i.s.g.m.DefaultMeshSidebandRegistry Sidecar (http://localhost:7777): Opening sideband channel
2022-06-16 21:41:09,146 INFO [mesh-grpc-request:thread-1] c.a.s.i.mesh.DefaultMeshNodeRegistry Node Sidecar (http://localhost:7777) went offline
2022-06-16 21:41:09,166 INFO [mesh-grpc-request:thread-1] c.a.s.i.s.g.m.DefaultMeshSidebandRegistry Sidecar (http://localhost:7777): Sideband channel closed because node is unavailable
2022-06-16 21:41:09,192 WARN [spring-startup] o.s.w.c.s.XmlWebApplicationContext Exception encountered during context initialization - cancelling refresh attempt: org.springframework.context.ApplicationContextException: Failed to start bean 'meshController'; nested exception is com.atlassian.bitbucket.repository.RepositoryOfflineException: bitbucket.scm.repository.offline
2022-06-16 21:41:09,196 ERROR [hz.hazelcast.event-1] c.h.s.i.e.impl.EventServiceImpl [10.0.0.151]:5701 [bitbucket] [3.12.12] hz.hazelcast.event-1 caught an exception while processing:com.hazelcast.spi.impl.eventservice.impl.LocalEventDispatcher@42ad2858
com.atlassian.bitbucket.repository.RepositoryOfflineException: bitbucket.scm.repository.offline
at com.atlassian.stash.internal.scm.git.mesh.DefaultErrorTranslator.translateOffline(DefaultErrorTranslator.java:382)
at com.atlassian.stash.internal.scm.git.mesh.DefaultErrorTranslator.translateIfKnownCause(DefaultErrorTranslator.java:278)
at com.atlassian.stash.internal.scm.git.mesh.DefaultErrorTranslator.maybeTranslate(DefaultErrorTranslator.java:55)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver.maybeTranslate(AbstractFutureResponseObserver.java:203)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver$ResponseFuture.translateCause(AbstractFutureResponseObserver.java:292)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver$ResponseFuture.get(AbstractFutureResponseObserver.java:229)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver.asResult(AbstractFutureResponseObserver.java:145)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver.asResult(AbstractFutureResponseObserver.java:133)
at com.atlassian.stash.internal.scm.git.mesh.GrpcManagementClient.updateConfig(GrpcManagementClient.java:294)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at jdk.internal.reflect.GeneratedMethodAccessor202.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at com.atlassian.stash.internal.mesh.ConfigureSidecarTask.configure(ConfigureSidecarTask.java:75)
at com.atlassian.stash.internal.mesh.DefaultMeshController.maybeConfigureSidecar(DefaultMeshController.java:255)
at com.atlassian.stash.internal.mesh.DefaultMeshController.access$700(DefaultMeshController.java:70)
at com.atlassian.stash.internal.mesh.DefaultMeshController$ControlPlaneStateListener.lambda$onUpdated$0(DefaultMeshController.java:287)
at java.base/java.util.Optional.ifPresent(Optional.java:183)
at com.atlassian.stash.internal.mesh.DefaultMeshController$ControlPlaneStateListener.onUpdated(DefaultMeshController.java:286)
at com.atlassian.stash.internal.mesh.DefaultMeshController$ControlPlaneStateListener.entryAdded(DefaultMeshController.java:273)
at com.hazelcast.map.impl.MapListenerAdaptors$1$1.onEvent(MapListenerAdaptors.java:67)
at com.hazelcast.map.impl.MapListenerAdaptors$1$1.onEvent(MapListenerAdaptors.java:64)
at com.hazelcast.map.impl.InternalMapListenerAdapter.onEvent(InternalMapListenerAdapter.java:56)
at com.hazelcast.map.impl.InternalMapListenerAdapter.onEvent(InternalMapListenerAdapter.java:35)
at com.hazelcast.map.impl.event.MapEventPublishingService.callListener(MapEventPublishingService.java:172)
at com.hazelcast.map.impl.event.MapEventPublishingService.dispatchEntryEventData(MapEventPublishingService.java:184)
at com.hazelcast.map.impl.event.MapEventPublishingService.dispatchEvent(MapEventPublishingService.java:83)
at com.hazelcast.map.impl.event.MapEventPublishingService.dispatchEvent(MapEventPublishingService.java:47)
at com.hazelcast.map.impl.MapService.dispatchEvent(MapService.java:105)
at com.hazelcast.map.impl.MapService.dispatchEvent(MapService.java:78)
at com.hazelcast.spi.impl.eventservice.impl.LocalEventDispatcher.run(LocalEventDispatcher.java:64)
at com.hazelcast.util.executor.StripedExecutor$Worker.process(StripedExecutor.java:244)
at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:227)
... 15 frames trimmed
Caused by: io.grpc.StatusRuntimeException: UNAVAILABLE: io exception
at io.grpc.Status.asRuntimeException(Status.java:535)
at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:479)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at com.atlassian.stash.internal.scm.git.mesh.LastSeenClientInterceptor$LastSeenClientListener.onClose(LastSeenClientInterceptor.java:40)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at com.atlassian.stash.internal.scm.git.mesh.StatefulClientCallListener.onClose(StatefulClientCallListener.java:34)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at com.atlassian.stash.internal.scm.git.mesh.DeadlinePropagatingClientInterceptor$DeadlinePropagatingListener.onClose(DeadlinePropagatingClientInterceptor.java:156)
at com.atlassian.stash.internal.scm.git.mesh.ErrorHandlingClientInterceptor$ErrorHandlingCall$1.onClose(ErrorHandlingClientInterceptor.java:136)
at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562)
at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:743)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:722)
at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.lang.Thread.run(Thread.java:829)
... 1 common frames omitted
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: finishConnect(..) failed: Connection refused: localhost/127.0.0.1:7777
Caused by: java.net.ConnectException: finishConnect(..) failed: Connection refused
at io.netty.channel.unix.Errors.newConnectException0(Errors.java:155)
at io.netty.channel.unix.Errors.handleConnectErrno(Errors.java:128)
at io.netty.channel.unix.Socket.finishConnect(Socket.java:320)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.doFinishConnect(AbstractEpollChannel.java:710)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.finishConnect(AbstractEpollChannel.java:687)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.epollOutReady(AbstractEpollChannel.java:567)
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:470)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:829)
2022-06-16 21:41:39,307 WARN [spring-startup] c.a.s.i.s.g.m.DefaultSidecarManager Sidecar did not stop within the allotted delay; terminating
2022-06-16 21:41:39,379 INFO [spring-startup] c.a.s.internal.home.HomeLockAcquirer Releasing lock on /var/atlassian/application-data/bitbucket/shared
2022-06-16 21:41:39,411 INFO [spring-startup] c.a.s.internal.home.HomeLockAcquirer Releasing lock on /var/atlassian/application-data/bitbucket
2022-06-16 21:41:39,425 ERROR [spring-startup] c.a.j.s.w.s.JohnsonDispatcherServlet SpringMVC dispatcher [springMvc] could not be started
org.springframework.context.ApplicationContextException: Failed to start bean 'meshController'; nested exception is com.atlassian.bitbucket.repository.RepositoryOfflineException: bitbucket.scm.repository.offline
at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:181)
at org.springframework.context.support.DefaultLifecycleProcessor.access$200(DefaultLifecycleProcessor.java:54)
at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:356)
at java.base/java.lang.Iterable.forEach(Iterable.java:75)
at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:155)
at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:123)
at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:935)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:586)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at java.base/java.lang.Thread.run(Thread.java:829)
... 8 frames trimmed
Caused by: com.atlassian.bitbucket.repository.RepositoryOfflineException: bitbucket.scm.repository.offline
at com.atlassian.stash.internal.scm.git.mesh.DefaultErrorTranslator.translateOffline(DefaultErrorTranslator.java:382)
at com.atlassian.stash.internal.scm.git.mesh.DefaultErrorTranslator.translateIfKnownCause(DefaultErrorTranslator.java:278)
at com.atlassian.stash.internal.scm.git.mesh.DefaultErrorTranslator.maybeTranslate(DefaultErrorTranslator.java:55)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver.maybeTranslate(AbstractFutureResponseObserver.java:203)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver$ResponseFuture.translateCause(AbstractFutureResponseObserver.java:292)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver$ResponseFuture.get(AbstractFutureResponseObserver.java:229)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver.asResult(AbstractFutureResponseObserver.java:145)
at com.atlassian.stash.internal.scm.git.mesh.AbstractFutureResponseObserver.asResult(AbstractFutureResponseObserver.java:133)
at com.atlassian.stash.internal.scm.git.mesh.GrpcManagementClient.updateConfig(GrpcManagementClient.java:294)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at jdk.internal.reflect.GeneratedMethodAccessor202.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at com.atlassian.stash.internal.mesh.ConfigureSidecarTask.configure(ConfigureSidecarTask.java:75)
at com.atlassian.stash.internal.mesh.DefaultMeshController.maybeConfigureSidecar(DefaultMeshController.java:255)
at com.atlassian.stash.internal.mesh.DefaultMeshController.lambda$maybeConfigureSidecar$0(DefaultMeshController.java:249)
at java.base/java.util.Optional.ifPresent(Optional.java:183)
at com.atlassian.stash.internal.mesh.DefaultMeshController.maybeConfigureSidecar(DefaultMeshController.java:245)
at com.atlassian.stash.internal.mesh.DefaultMeshController.start(DefaultMeshController.java:232)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:178)
... 10 common frames omitted
Caused by: io.grpc.StatusRuntimeException: UNAVAILABLE: io exception
at io.grpc.Status.asRuntimeException(Status.java:535)
at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:479)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at com.atlassian.stash.internal.scm.git.mesh.LastSeenClientInterceptor$LastSeenClientListener.onClose(LastSeenClientInterceptor.java:40)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at com.atlassian.stash.internal.scm.git.mesh.StatefulClientCallListener.onClose(StatefulClientCallListener.java:34)
at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39)
at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23)
at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40)
at com.atlassian.stash.internal.scm.git.mesh.DeadlinePropagatingClientInterceptor$DeadlinePropagatingListener.onClose(DeadlinePropagatingClientInterceptor.java:156)
at com.atlassian.stash.internal.scm.git.mesh.ErrorHandlingClientInterceptor$ErrorHandlingCall$1.onClose(ErrorHandlingClientInterceptor.java:136)
at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562)
at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:743)
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:722)
at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
... 2 common frames omitted
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: finishConnect(..) failed: Connection refused: localhost/127.0.0.1:7777
Caused by: java.net.ConnectException: finishConnect(..) failed: Connection refused
at io.netty.channel.unix.Errors.newConnectException0(Errors.java:155)
at io.netty.channel.unix.Errors.handleConnectErrno(Errors.java:128)
at io.netty.channel.unix.Socket.finishConnect(Socket.java:320)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.doFinishConnect(AbstractEpollChannel.java:710)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.finishConnect(AbstractEpollChannel.java:687)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe.epollOutReady(AbstractEpollChannel.java:567)
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:470)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:829)
2022-06-16 21:46:17,623 WARN [http-nio-7990-exec-1] c.a.j.s.w.f.BypassableDelegatingFilterProxy Bypassing [hazelcastFilter]; no Spring WebApplicationContext is available
2022-06-16 21:46:17,624 WARN [http-nio-7990-exec-1] c.a.j.s.w.f.BypassableDelegatingFilterProxy Bypassing [requestAttributeFilter]; no Spring WebApplicationContext is available
2022-06-16 21:46:17,654 WARN [http-nio-7990-exec-2] c.a.j.s.w.f.BypassableDelegatingFilterProxy Bypassing [hazelcastFilter]; no Spring WebApplicationContext is available
2022-06-16 21:46:17,654 WARN [http-nio-7990-exec-2] c.a.j.s.w.f.BypassableDelegatingFilterProxy Bypassing [requestAttributeFilter]; no Spring WebApplicationContext is available

[Paul Podgorsek · Accepted solution]

I finally found the solution to this issue: deleting the mesh/ folder in the home directory forced it to be recreated which allowed the mesh sidecar to start without any errors.

[Craig Castle-Mead]

I had a similar error, but it was due to my git version being older than needed. https://community.atlassian.com/t5/Bitbucket-discussions/Warning-Ubuntu-20-04LTS-users-before-upgrading-to-Bitbucket-8-0/td-p/2030941 pointed me in the correct direction.

CCM

[Adrien Ragot _Requirement Yogi_]

Same happened for me: Debian 11 Bullseye only has git 2.30, while bullseye-backports contains 2.34, which allowed "bitbucket sidecar" to load. Thank you very much for the solution!

[stam_epicmorg]

you could add backports repo to /etc/apt/sources.list (example for debian 11)

deb http://httpredir.debian.org/debian/ bullseye-backports main contrib non-free
deb-src http://httpredir.debian.org/debian/ bullseye-backports main contrib non-free

 and install git from this repo via

apt install git/bullseye-backports

it will be installed 2.34.1 version