Uploaded image for project: 'Bitbucket Data Center'
  1. Bitbucket Data Center
  2. BSERV-19136

Mirror synchronisation stops when H2's FileChannel is closed

XMLWordPrintable

      Issue Summary

      It is possible for the FileChannel the embedded H2 database uses to be closed in the case a thread in a FileChannel operation is interrupted. This results in the mirror node failing to synchronise changes, which also blocks all nodes in the mirror farm from being synchrnonised.

      When this happens errors like the below will appear in the application logs of one or more mirror nodes:

      2024-01-22 06:36:35,509 ERROR [AtlassianEvent::thread-25] *10OKSS7x395x-1086689803x565 c.a.s.i.e.AsyncBatchingInvokersTransformer There was an exception thrown trying to dispatch event 'com.atlassian.bitbucket.mirroring.mirror.RepositorySynchronizedEvent[source=com.atlassian.bitbucket.internal.mirroring.mirror.farm.synchronization.UpdateRefHelper@311ed5cf]' for the invoker 'com.atlassian.event.internal.ComparableListenerInvoker@391c35e7'
java.lang.RuntimeException: Listener: com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamService event: com.atlassian.bitbucket.mirroring.mirror.RepositorySynchronizedEvent
        at com.atlassian.event.internal.SingleParameterMethodListenerInvoker.invoke(SingleParameterMethodListenerInvoker.java:49)
        at com.atlassian.diagnostics.internal.platform.monitor.event.EventSystemMonitor.invokeMonitored(EventSystemMonitor.java:105)
        at com.atlassian.diagnostics.internal.platform.monitor.event.MonitoredListenerInvoker.invoke(MonitoredListenerInvoker.java:38)
        at com.atlassian.event.internal.ComparableListenerInvoker.invoke(ComparableListenerInvoker.java:48)
        at com.atlassian.stash.internal.event.AsyncBatchingInvokersTransformer$AsyncInvokerBatch.invoke(AsyncBatchingInvokersTransformer.java:111)
        at com.atlassian.event.internal.AsynchronousAbleEventDispatcher.lambda$null$0(AsynchronousAbleEventDispatcher.java:37)
        at com.atlassian.sal.core.executor.ThreadLocalDelegateRunnable.run(ThreadLocalDelegateRunnable.java:34)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at com.atlassian.stash.internal.event.EventThreadFactory.lambda$createThread$0(EventThreadFactory.java:35)
        at java.base/java.lang.Thread.run(Thread.java:840)
        ... 1 frame trimmed
Caused by: java.lang.reflect.UndeclaredThrowableException: null
        at jdk.proxy54/jdk.proxy54.$Proxy1454.save(Unknown Source)
        at com.atlassian.bitbucket.internal.mirroring.mirror.dao.AoRepositoryMappingDao.update(AoRepositoryMappingDao.java:230)
        at com.atlassian.bitbucket.internal.mirroring.mirror.dao.AoRepositoryMappingDao.updateSyncDate(AoRepositoryMappingDao.java:211)
        at com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamService.lambda$onRepositorySynchronized$8(DefaultUpstreamService.java:281)
        at com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamService.lambda$inTransactionVoid$18(DefaultUpstreamService.java:730)
        at com.atlassian.sal.core.transaction.HostContextTransactionTemplate$1.doInTransaction(HostContextTransactionTemplate.java:21)
        at com.atlassian.stash.internal.sal.spi.HostContextAccessorImpl.doInTransaction(HostContextAccessorImpl.java:54)
        at jdk.internal.reflect.GeneratedMethodAccessor395.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at jdk.proxy3/jdk.proxy3.$Proxy451.doInTransaction(Unknown Source)
        at com.atlassian.sal.core.transaction.HostContextTransactionTemplate.execute(HostContextTransactionTemplate.java:18)
        at jdk.internal.reflect.GeneratedMethodAccessor389.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at com.atlassian.plugin.util.ContextClassLoaderSettingInvocationHandler.invoke(ContextClassLoaderSettingInvocationHandler.java:26)
        at jdk.proxy2/jdk.proxy2.$Proxy707.execute(Unknown Source)
        at jdk.internal.reflect.GeneratedMethodAccessor389.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:56)
        at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:60)
        at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:70)
        at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:53)
        at org.eclipse.gemini.blueprint.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:57)
        at jdk.proxy53/jdk.proxy53.$Proxy1423.execute(Unknown Source)
        at com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamService.inTransaction(DefaultUpstreamService.java:725)
        at com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamService.inTransactionVoid(DefaultUpstreamService.java:729)
        at com.atlassian.bitbucket.internal.mirroring.mirror.DefaultUpstreamService.onRepositorySynchronized(DefaultUpstreamService.java:280)
        at jdk.internal.reflect.GeneratedMethodAccessor690.invoke(Unknown Source)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at com.atlassian.event.internal.SingleParameterMethodListenerInvoker.invoke(SingleParameterMethodListenerInvoker.java:42)
        ... 10 common frames omitted
Caused by: org.h2.jdbc.JdbcSQLNonTransientException: IO Exception: "/var/atlassian/application-data/bitbucket/shared/data/db.mv.db"; SQL statement:
UPDATE AO_8E6075_REPO_MAPPING SET FAILED_SYNC_COUNT = ?, LAST_SYNC = ? WHERE LOCAL_ID = ? [90028-214]
        at org.h2.message.DbException.getJdbcSQLException(DbException.java:554)
        at org.h2.message.DbException.getJdbcSQLException(DbException.java:477)
        at org.h2.message.DbException.get(DbException.java:212)
        at org.h2.mvstore.db.Store.convertMVStoreException(Store.java:171)
        at org.h2.mvstore.db.MVTable.convertException(MVTable.java:687)
        at org.h2.mvstore.db.MVSecondaryIndex.remove(MVSecondaryIndex.java:241)
        at org.h2.mvstore.db.MVTable.removeRow(MVTable.java:485)
        at org.h2.table.Table.updateRows(Table.java:546)
        at org.h2.command.dml.Update.doUpdate(Update.java:109)
        at org.h2.command.dml.Update.update(Update.java:93)
        at org.h2.command.dml.DataChangeStatement.update(DataChangeStatement.java:74)
        at org.h2.command.CommandContainer.update(CommandContainer.java:169)
        at org.h2.command.Command.executeUpdate(Command.java:252)
        at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:209)
        at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:169)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
        at net.java.ao.ForwardingPreparedStatement.executeUpdate(ForwardingPreparedStatement.java:45)
        at net.java.ao.ParameterMetadataCachingPreparedStatement.executeUpdate(ParameterMetadataCachingPreparedStatement.java:10)
        at net.java.ao.EntityProxy.save(EntityProxy.java:574)
        at net.java.ao.EntityProxy.invoke(EntityProxy.java:116)
        ... 39 common frames omitted
Caused by: org.h2.mvstore.MVStoreException: Reading from file sun.nio.ch.FileChannelImpl@3a4d7030 failed at 62075916 (length -1), read 0, remaining 512 [2.1.214/1]
        at org.h2.mvstore.DataUtils.newMVStoreException(DataUtils.java:1004)
        at org.h2.mvstore.DataUtils.readFully(DataUtils.java:470)
        at org.h2.mvstore.FileStore.readFully(FileStore.java:98)
        at org.h2.mvstore.Chunk.readBufferForPage(Chunk.java:422)
        at org.h2.mvstore.MVStore.readPage(MVStore.java:2569)
        at org.h2.mvstore.MVMap.readPage(MVMap.java:633)
        at org.h2.mvstore.Page$NonLeaf.getChildPage(Page.java:1125)
        at org.h2.mvstore.CursorPos.traverseDown(CursorPos.java:61)
        at org.h2.mvstore.MVMap.operate(MVMap.java:1770)
        at org.h2.mvstore.tx.TransactionMap.set(TransactionMap.java:346)
        at org.h2.mvstore.tx.TransactionMap.set(TransactionMap.java:333)
        at org.h2.mvstore.tx.TransactionMap.remove(TransactionMap.java:248)
        at org.h2.mvstore.db.MVSecondaryIndex.remove(MVSecondaryIndex.java:235)
        ... 54 common frames omitted
Caused by: java.nio.channels.ClosedChannelException: null
        at java.base/sun.nio.ch.FileChannelImpl.ensureOpen(FileChannelImpl.java:159)
        at java.base/sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:814)
        at org.h2.mvstore.DataUtils.readFully(DataUtils.java:456)
        ... 65 common frames omitted

      I've set the affects version to 8.0.0, as this was the first version of Bitbucket that bundles H2 1.4. This problem may effect older versions, but certainly not all older versions since at some point in the past H2 used file streams and not file channels, and this is a FileChannel specific problem. But it certainly impacts H2 1.4.

      Workaround

      Restart the mirror node(s) that encountered this problem.

              behumphreys Ben Humphreys
              behumphreys Ben Humphreys
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: