Move lockRelease() to the end of exitSafe().

Releasing the lock too early was allowing other async processes to sneak in and start running before the current process was completely shut down.

The only symptom seems to have been mixed up log messages so not a very serious issue.

doc/xml/release.xml

@@ -25,6 +25,10 @@
                 </release-bug-list>
 
                 <release-development-list>
+                    <release-item>
+                        <p>Move <code>lockRelease()</code> to the end of <code>exitSafe()</code>.</p>
+                    </release-item>
+
                     <release-item>
                         <p>Automatically generate constants for command and option names.</p>
                     </release-item>

src/common/exit.c

@@ -134,13 +134,6 @@ exitSafe(int result, bool error, SignalType signalType)
         result = errorCode();
     }
 
-    // Release any locks but ignore errors
-    TRY_BEGIN()
-    {
-        lockRelease(false);
-    }
-    TRY_END();
-
     // Free protocol objects but ignore errors
     TRY_BEGIN()
     {
@@ -185,6 +178,13 @@ exitSafe(int result, bool error, SignalType signalType)
         cmdEnd(result, errorMessage);
     }
 
+    // Release any locks but ignore errors
+    TRY_BEGIN()
+    {
+        lockRelease(false);
+    }
+    TRY_END();
+
     // Return result - caller should immediate pass this result to exit()
     FUNCTION_LOG_RETURN(INT, result);
 }

test/expect/mock-all-001.log

@@ -358,12 +358,12 @@ P00  DEBUG:     Backup::Info->current=>: bTest = true
 P00   INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: expire command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -530,12 +530,12 @@ P00  DEBUG:     Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExist
 P00   INFO: sent term signal to process [PROCESS-ID]
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: stop command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -646,12 +646,12 @@ P00  DEBUG:     Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExist
 P00  DEBUG:     Common::Lock::lockStopTest(): bStanzaStopRequired = <false>
 P00  ERROR: [062]: stop file exists for all stanzas
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: true, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 62
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: backup command end: aborted with exception [062]
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     common/exit::exitSafe: => 62
 P00  DEBUG:     main::main: => 62
 
@@ -666,12 +666,12 @@ P00  DEBUG:     Storage::Local->new(): bAllowTemp = <true>, hRule = [undef], lBu
 P00  DEBUG:     Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExists = true, strMode = 770, strPathExp = [TEST_PATH]/db-master/lock
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: stop command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -687,12 +687,12 @@ P00  DEBUG:     Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExist
 P00   WARN: stop file already exists for stanza db
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: stop command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -716,12 +716,12 @@ P00  DEBUG:     Storage::Local->pathCreate(): bCreateParent = true, bIgnoreExist
 P00  DEBUG:     Common::Lock::lockStopTest(): bStanzaStopRequired = <false>
 P00  ERROR: [062]: stop file exists for stanza db
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: true, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 62
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = false, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: backup command end: aborted with exception [062]
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     common/exit::exitSafe: => 62
 P00  DEBUG:     main::main: => 62
 
@@ -733,12 +733,12 @@ P00  DEBUG:     config/load::cfgLoad: => void
 P00  DEBUG:     perl/exec::perlExec: (void)
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: start command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -750,12 +750,12 @@ P00  DEBUG:     config/load::cfgLoad: => void
 P00  DEBUG:     perl/exec::perlExec: (void)
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: start command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -768,12 +768,12 @@ P00  DEBUG:     perl/exec::perlExec: (void)
 P00   WARN: stop file does not exist
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: start command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -1053,12 +1053,12 @@ P00  DEBUG:     Backup::Info->current=>: bTest = true
 P00   INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: expire command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -1565,12 +1565,12 @@ P00  DEBUG:     Storage::Local->remove=>: bRemoved = true
 P00  DEBUG:     Storage::Local->pathSync(): strPathExp = [TEST_PATH]/db-master/db/base
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: restore command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -2228,12 +2228,12 @@ P00  DEBUG:     Backup::Info->current=>: bTest = true
 P00   INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: expire command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -2747,12 +2747,12 @@ P00  DEBUG:     Backup::Info->current=>: bTest = true
 P00   INFO: option 'repo1-retention-archive' is not set - archive logs will not be expired
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: expire command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => true
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0
 
@@ -3658,12 +3658,12 @@ P00  DEBUG:     Storage::Local->remove=>: bRemoved = true
 P00  DEBUG:     Storage::Local->pathSync(): strPathExp = [TEST_PATH]/db-master/db/base-2
 P00  DEBUG:     perl/exec::perlExec: => 0
 P00  DEBUG:     common/exit::exitSafe: (result: 0, error: false, signalType: 0)
-P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
-P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     Main::mainCleanup(): iExitCode = 0
 P00  DEBUG:     Protocol::Helper::protocolDestroy(): bComplete = true, iRemoteIdx = [undef], strRemoteType = [undef]
 P00  DEBUG:     Protocol::Helper::protocolDestroy=>: iExitStatus = 0
 P00   INFO: restore command end: completed successfully
+P00  DEBUG:     common/lock::lockRelease: (failOnNoLock: false)
+P00  DEBUG:     common/lock::lockRelease: => false
 P00  DEBUG:     common/exit::exitSafe: => 0
 P00  DEBUG:     main::main: => 0