Bitbucket Server fails with error: Operations from one or more SCMs did not finish within the allotted timeout
Problem
A backup of Bitbucket Server taken using the Bitbucket Server Backup Client fails because it times out.
From the command line, when the user is trying to perform backup using Backup client - an error such as the one below occurs:
com.atlassian.bitbucket.internal.backup.client.ScmDrainTimedOutException: Operations from one or more SCMs did not finish within the allotted timeout. To prevent corruption due to inconsistent state, the backup has been aborted. Please try backup again when the system is under less load.
The following appears in the atlassian-bitbucket.log
:
2014-08-21 22:30:08,280 INFO [http-bio-7990-exec-1995] bitbucketadmin 1350x13856715x1 1fypaao 10.67.168.14 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.DefaultMaintenanceService BACKUP started. It may be canceled with token: b002ed114828f2c6252ad02bd12b88d3319ab070
2014-08-21 22:30:11,290 WARN [http-bio-7990-exec-1992] 1350x13856718x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:16,282 WARN [http-bio-7990-exec-1997] 1350x13856719x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:21,287 WARN [http-bio-7990-exec-1997] 1350x13856720x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:26,287 WARN [http-bio-7990-exec-1998] 1350x13856721x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:31,287 WARN [http-bio-7990-exec-1994] 1350x13856722x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:36,288 WARN [http-bio-7990-exec-1994] 1350x13856725x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:41,289 WARN [http-bio-7990-exec-1986] 1350x13856726x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:46,287 WARN [http-bio-7990-exec-1913] 1350x13856727x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:51,287 WARN [http-bio-7990-exec-1913] 1350x13856728x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:30:56,287 WARN [http-bio-7990-exec-1966] 1350x13856729x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:31:01,286 WARN [http-bio-7990-exec-1985] 1351x13856730x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:31:06,288 WARN [http-bio-7990-exec-1997] 1351x13856731x1 10.67.168.14 "GET /mvc/maintenance HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:31:08,844 WARN [threadpool:thread-10328] bitbucketadmin 1350x13856715x1 1fypaao 10.67.168.14 "POST /mvc/admin/backups HTTP/1.1" c.a.s.internal.scm.PluginScmService Failed to drain SCM com.atlassian.bitbucket.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (60000ms) of total (60000ms)
2014-08-21 22:31:08,844 WARN [threadpool:thread-10328] bitbucketadmin 1350x13856715x1 1fypaao 10.67.168.14 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.LatchAndDrainScmStep The SCMs could not be drained. Aborting...
2014-08-21 22:31:08,848 WARN [threadpool:thread-10328] bitbucketadmin 1350x13856715x1 1fypaao 10.67.168.14 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.DefaultMaintenanceTaskMonitor BACKUP maintenance has failed (Cause: BackupException: A backup file could not be created.)
com.atlassian.bitbucket.internal.backup.BackupException: A backup file could not be created.
at com.atlassian.bitbucket.internal.maintenance.backup.BackupPhase.run(BackupPhase.java:78) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.MaintenanceModePhase.run(MaintenanceModePhase.java:27) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.backup.AbstractBackupTask.run(AbstractBackupTask.java:84) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.DefaultMaintenanceTaskMonitor.run(DefaultMaintenanceTaskMonitor.java:169) ~[bitbucket-service-impl-3.1.1.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_25]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) ~[na:1.7.0_25]
at java.util.concurrent.FutureTask.run(FutureTask.java:166) ~[na:1.7.0_25]
at com.atlassian.bitbucket.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[bitbucket-platform-3.1.1.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_25]
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) ~[na:1.7.0_25]
at java.util.concurrent.FutureTask.run(FutureTask.java:166) ~[na:1.7.0_25]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) ~[na:1.7.0_25]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) ~[na:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_25]
at java.lang.Thread.run(Thread.java:724) ~[na:1.7.0_25]
... 1 frame trimmed
Caused by: com.atlassian.bitbucket.internal.backup.BackupException: Operations from one or more SCMs did not finish within the allotted timeout. To prevent corruption due to inconsistent state, the backup has been aborted. Please try backup up again when the system is under less load.
at com.atlassian.bitbucket.internal.maintenance.LatchAndDrainScmStep.newDrainFailedException(LatchAndDrainScmStep.java:31) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.AbstractLatchAndDrainTask.run(AbstractLatchAndDrainTask.java:75) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) ~[bitbucket-service-impl-3.1.1.jar:na]
at com.atlassian.bitbucket.internal.maintenance.backup.BackupPhase.run(BackupPhase.java:74) ~[bitbucket-service-impl-3.1.1.jar:na]
... 17 common frames omitted
2014-08-21 22:31:11,421 INFO [http-bio-7990-exec-1913] 1351x13856734x1 10.67.168.14 "DELETE /mvc/maintenance/lock HTTP/1.1" c.a.s.i.m.DefaultMaintenanceLock Maintenance has been completed. The system lock has been released
Cause
There were Git processes active that didn't finish within the default 60 seconds expected by the backup client.
Resolution
Increase the timeout from 60 seconds to 2 minutes to give more time for the Git operations to be completed. The timeout setting needs to be updated for both Bitbucket Server and the backup client. For Bitbucket Server, update bitbucket.properties
with the following parameter and restart the application:
backup.drain.scm.timeout=120
For the backup client, add the following parameter to backup-config.properties
and match the timeout value set in Bitbucket Server:
backup.scmdrain.timeout=120
There is no exact answer to what the timeout value should be set to. Iterate until you find enough time so the SCM requests can be processed.
Notice
Please observe that the parameter names are slightly different between the Bitbucket Server instance and the backup client.
Location of Config file
Make sure that the Backup client is run from the directory that contains the backup-config.properties
file. The client looks for the properties file in the working directory when running and hence the config file needs to be in the working directory that the backup client is executed from.