Loading...

Details

Type: Bug
Resolution: Fixed
Priority: Medium
Fix Version/s: 8.18.0, 8.9.10, 8.13.6, 8.17.1, 8.14.5, 8.15.4, 8.16.3
Affects Version/s: 8.0.0
Component/s: Smart Mirroring
Labels:
- ewt-ctb-improve-existing

Symptom Severity:
Severity 3 - Minor
Bug Fix Policy:
View Atlassian Server bug fix policy
EWT (CtB, RtB, DP):
CtB - Improve Existing

Description

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.

Attachments

Issue Links

mentioned in: Page Loading...; Page Loading...; Page Loading...

relates to: BBSDEV-30067 Loading...

Mirror synchronisation stops when H2's FileChannel is closed

Details

Description

Issue Summary

Workaround

Attachments

Issue Links

Activity

People

Dates