Backup client - Operations from one or more SCMs did not finish within the allotted timeout
Symptoms
Stash backup fails:
- The Backup Client times out and fails gracefully.
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.