From b258aec0adcf6fdaf7a2494c66f1540aa720e345 Mon Sep 17 00:00:00 2001 From: David Steele Date: Thu, 18 Apr 2019 13:19:05 -0400 Subject: [PATCH] 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 | 4 +++ src/common/exit.c | 14 ++++----- test/expect/mock-all-001.log | 56 ++++++++++++++++++------------------ 3 files changed, 39 insertions(+), 35 deletions(-) diff --git a/doc/xml/release.xml b/doc/xml/release.xml index d326148e7..e7ce6a962 100644 --- a/doc/xml/release.xml +++ b/doc/xml/release.xml @@ -25,6 +25,10 @@ + +

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

+ +

Automatically generate constants for command and option names.

 diff --git a/src/common/exit.c b/src/common/exit.c index 394cc6db6..c876b2e4e 100644 --- a/src/common/exit.c +++ b/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); } diff --git a/test/expect/mock-all-001.log b/test/expect/mock-all-001.log index f5496903a..5fde92705 100644 --- a/test/expect/mock-all-001.log +++ b/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 = 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 = , 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 = 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