Backup client - Operations from one or more SCMs did not finish within the allotted timeout

Symptoms

Stash backup fails:

The following appears in the atlassian-stash-YYYY-MM-DD.log:

2014-08-21 22:30:08,280 INFO  [http-bio-7990-exec-1995] stashadmin 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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.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.stash.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (0ms) of total (0ms)
2014-08-21 22:31:08,844 WARN  [threadpool:thread-10328] stashadmin 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.stash.internal.scm.git.DefaultGitScm@3c7485cd in remaining allocated time (60000ms) of total (60000ms)
2014-08-21 22:31:08,844 WARN  [threadpool:thread-10328] stashadmin 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] stashadmin 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.stash.internal.backup.BackupException: A backup file could not be created.
	at com.atlassian.stash.internal.maintenance.backup.BackupPhase.run(BackupPhase.java:78) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.MaintenanceModePhase.run(MaintenanceModePhase.java:27) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.backup.AbstractBackupTask.run(AbstractBackupTask.java:84) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.DefaultMaintenanceTaskMonitor.run(DefaultMaintenanceTaskMonitor.java:169) ~[stash-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.stash.internal.concurrent.StateTransferringExecutor$StateTransferringRunnable.run(StateTransferringExecutor.java:69) ~[stash-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.stash.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.stash.internal.maintenance.LatchAndDrainScmStep.newDrainFailedException(LatchAndDrainScmStep.java:31) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.AbstractLatchAndDrainTask.run(AbstractLatchAndDrainTask.java:75) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask$Step.run(CompositeMaintenanceTask.java:130) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.CompositeMaintenanceTask.run(CompositeMaintenanceTask.java:69) ~[stash-service-impl-3.1.1.jar:na]
	at com.atlassian.stash.internal.maintenance.backup.BackupPhase.run(BackupPhase.java:74) ~[stash-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 Stash and the backup client. For Stash, update stash-config.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 Stash:

  • 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 Stash server and the backup client.

Last modified on Nov 2, 2018

Was this helpful?

Yes
No
Provide feedback about this article
Powered by Confluence and Scroll Viewport.