You've already forked pgbackrest
mirror of
https://github.com/pgbackrest/pgbackrest.git
synced 2026-06-20 01:17:49 +02:00
Fix deadlock due to logging in signal handler.
Previously it was possible to achieve a deadlock in a signal handler, for example when SIGTERM (i.e. sent by `pgbackrest stop --force`) arrives when a lock used in `gmtime_r` is taken. Then the next time logging is done, it will deadlock on `gmtime_r`. In general, most stdlib functions are not safe to call in signal handlers, only so called async-signal safe functions are. In particular, `snprintf` isn't safe since it is allowed to internally call `malloc`. The `exitSafe` function isn't safe due to extensive use of allocations. Because of this, we need to use a simpler logging format in signal handlers, one that only uses async-signal safe functions.
This commit is contained in:
@@ -4,6 +4,20 @@
|
||||
<p><b>IMPORTANT NOTE</b>: The minimum values for the <setting>repo-storage-upload-chunk-size</setting> option have increased. They now represent the minimum allowed by the vendors.</p>
|
||||
</text>
|
||||
|
||||
<release-bug-list>
|
||||
<release-item>
|
||||
<github-issue id="2710"/>
|
||||
<github-pull-request id="2715"/>
|
||||
|
||||
<release-item-contributor-list>
|
||||
<release-item-contributor id="maxim.michkov"/>
|
||||
<release-item-reviewer id="david.steele"/>
|
||||
</release-item-contributor-list>
|
||||
|
||||
<p>Fix deadlock due to logging in signal handler.</p>
|
||||
</release-item>
|
||||
</release-bug-list>
|
||||
|
||||
<release-feature-list>
|
||||
<release-item>
|
||||
<github-issue id="2666"/>
|
||||
|
||||
+11
-26
@@ -30,15 +30,15 @@ exitSignalName(const SignalType signalType)
|
||||
switch (signalType)
|
||||
{
|
||||
case signalTypeHup:
|
||||
name = "HUP";
|
||||
name = "SIGHUP";
|
||||
break;
|
||||
|
||||
case signalTypeInt:
|
||||
name = "INT";
|
||||
name = "SIGINT";
|
||||
break;
|
||||
|
||||
case signalTypeTerm:
|
||||
name = "TERM";
|
||||
name = "SIGTERM";
|
||||
break;
|
||||
|
||||
case signalTypeNone:
|
||||
@@ -54,13 +54,14 @@ Catch signals
|
||||
static void
|
||||
exitOnSignal(const int signalType)
|
||||
{
|
||||
FUNCTION_LOG_BEGIN(logLevelTrace);
|
||||
FUNCTION_LOG_PARAM(INT, signalType);
|
||||
FUNCTION_LOG_END();
|
||||
FUNCTION_TEST_BEGIN();
|
||||
FUNCTION_TEST_PARAM(INT, signalType);
|
||||
FUNCTION_TEST_END();
|
||||
|
||||
exit(exitSafe(errorTypeCode(&TermError), false, (SignalType)signalType));
|
||||
logSignal(cfgLogLevelDefault(), signalType == signalTypeNone ? "from child process" : exitSignalName((SignalType)signalType));
|
||||
exit(errorTypeCode(&TermError));
|
||||
|
||||
FUNCTION_LOG_RETURN_VOID();
|
||||
FUNCTION_TEST_NO_RETURN();
|
||||
}
|
||||
|
||||
/**********************************************************************************************************************************/
|
||||
@@ -142,24 +143,8 @@ exitSafe(int result, const bool error, const SignalType signalType)
|
||||
{
|
||||
String *errorMessage = NULL;
|
||||
|
||||
if (result != 0)
|
||||
{
|
||||
// On process terminate
|
||||
if (result == errorTypeCode(&TermError))
|
||||
{
|
||||
errorMessage = strCatZ(strNew(), "terminated on signal ");
|
||||
|
||||
// Terminate from a child
|
||||
if (signalType == signalTypeNone)
|
||||
strCatZ(errorMessage, "from child process");
|
||||
// Else terminated directly
|
||||
else
|
||||
strCatFmt(errorMessage, "[SIG%s]", exitSignalName(signalType));
|
||||
}
|
||||
// Standard error exit message
|
||||
else if (error)
|
||||
errorMessage = strNewFmt("aborted with exception [%03d]", result);
|
||||
}
|
||||
if (result != 0 && error)
|
||||
errorMessage = strNewFmt("aborted with exception [%03d]", result);
|
||||
|
||||
cmdEnd(result, errorMessage);
|
||||
strFree(errorMessage);
|
||||
|
||||
@@ -508,6 +508,34 @@ logPost(LogPreResult *const logData, const LogLevel logLevel, const LogLevel log
|
||||
FUNCTION_TEST_RETURN_VOID();
|
||||
}
|
||||
|
||||
/**********************************************************************************************************************************/
|
||||
#define LOG_SIGNAL_MESSAGE_PRE "terminated on signal "
|
||||
|
||||
FN_EXTERN void
|
||||
logSignal(const LogLevel logLevel, const char *const signalName)
|
||||
{
|
||||
FUNCTION_TEST_BEGIN();
|
||||
FUNCTION_TEST_PARAM(ENUM, logLevel);
|
||||
FUNCTION_TEST_PARAM(STRINGZ, signalName);
|
||||
FUNCTION_TEST_END();
|
||||
|
||||
ASSERT(signalName != NULL);
|
||||
STATIC_ASSERT_STMT(LOG_BUFFER_SIZE >= sizeof(LOG_SIGNAL_MESSAGE_PRE), "invalid log buffer size");
|
||||
|
||||
// Initialize log buffer and data with static signal message
|
||||
memcpy(logBuffer, LOG_SIGNAL_MESSAGE_PRE, sizeof(LOG_SIGNAL_MESSAGE_PRE) - 1);
|
||||
LogPreResult logData = {.bufferPos = sizeof(LOG_SIGNAL_MESSAGE_PRE) - 1, .logBufferStdErr = logBuffer, .indentSize = 4};
|
||||
|
||||
// Add signal name and ensure string is zero-terminated
|
||||
strncpy(logBuffer + logData.bufferPos, signalName, sizeof(logBuffer) - logData.bufferPos - 1);
|
||||
logData.bufferPos += strlen(signalName);
|
||||
logBuffer[sizeof(logBuffer) - 1] = 0;
|
||||
|
||||
logPost(&logData, logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX);
|
||||
|
||||
FUNCTION_TEST_RETURN_VOID();
|
||||
}
|
||||
|
||||
/**********************************************************************************************************************************/
|
||||
FN_EXTERN void
|
||||
logInternal(
|
||||
|
||||
@@ -40,6 +40,9 @@ FN_EXTERN bool logAny(LogLevel logLevel);
|
||||
FN_EXTERN LogLevel logLevelEnum(StringId logLevelId);
|
||||
FN_EXTERN const char *logLevelStr(LogLevel logLevel);
|
||||
|
||||
// Log exit on signal
|
||||
FN_EXTERN void logSignal(LogLevel logLevel, const char *signalName);
|
||||
|
||||
/***********************************************************************************************************************************
|
||||
Macros
|
||||
|
||||
|
||||
+1
-1
@@ -216,7 +216,7 @@ unit:
|
||||
|
||||
# ----------------------------------------------------------------------------------------------------------------------------
|
||||
- name: log
|
||||
total: 5
|
||||
total: 6
|
||||
feature: log
|
||||
harness:
|
||||
name: log
|
||||
|
||||
@@ -20,9 +20,9 @@ testRun(void)
|
||||
// *****************************************************************************************************************************
|
||||
if (testBegin("exitSignalName()"))
|
||||
{
|
||||
TEST_RESULT_Z(exitSignalName(signalTypeHup), "HUP", "SIGHUP name");
|
||||
TEST_RESULT_Z(exitSignalName(signalTypeInt), "INT", "SIGINT name");
|
||||
TEST_RESULT_Z(exitSignalName(signalTypeTerm), "TERM", "SIGTERM name");
|
||||
TEST_RESULT_Z(exitSignalName(signalTypeHup), "SIGHUP", "SIGHUP name");
|
||||
TEST_RESULT_Z(exitSignalName(signalTypeInt), "SIGINT", "SIGINT name");
|
||||
TEST_RESULT_Z(exitSignalName(signalTypeTerm), "SIGTERM", "SIGTERM name");
|
||||
TEST_ERROR(exitSignalName(signalTypeNone), AssertError, "no name for signal none");
|
||||
}
|
||||
|
||||
@@ -42,6 +42,18 @@ testRun(void)
|
||||
HRN_FORK_CHILD_END(); // {uncoverable - signal is raised in block}
|
||||
}
|
||||
HRN_FORK_END();
|
||||
|
||||
// -------------------------------------------------------------------------------------------------------------------------
|
||||
HRN_FORK_BEGIN()
|
||||
{
|
||||
HRN_FORK_CHILD_BEGIN(.expectedExitStatus = errorTypeCode(&TermError))
|
||||
{
|
||||
exitInit();
|
||||
exitOnSignal(signalTypeNone); // simulate signal received from child
|
||||
}
|
||||
HRN_FORK_CHILD_END(); // {uncoverable - signal is raised in block}
|
||||
}
|
||||
HRN_FORK_END();
|
||||
}
|
||||
|
||||
// *****************************************************************************************************************************
|
||||
@@ -131,16 +143,6 @@ testRun(void)
|
||||
"P00 INFO: archive-push:async command end: aborted with exception [025]");
|
||||
}
|
||||
TRY_END();
|
||||
|
||||
// -------------------------------------------------------------------------------------------------------------------------
|
||||
TEST_RESULT_INT(
|
||||
exitSafe(errorTypeCode(&TermError), false, signalTypeNone), errorTypeCode(&TermError), "exit on term with no signal");
|
||||
TEST_RESULT_LOG("P00 INFO: archive-push:async command end: terminated on signal from child process");
|
||||
|
||||
// -------------------------------------------------------------------------------------------------------------------------
|
||||
TEST_RESULT_INT(
|
||||
exitSafe(errorTypeCode(&TermError), false, signalTypeTerm), errorTypeCode(&TermError), "exit on term with SIGTERM");
|
||||
TEST_RESULT_LOG("P00 INFO: archive-push:async command end: terminated on signal [SIGTERM]");
|
||||
}
|
||||
|
||||
FUNCTION_HARNESS_RETURN_VOID();
|
||||
|
||||
@@ -328,5 +328,14 @@ testRun(void)
|
||||
"P99 INFO: [DRY-RUN] info message 2");
|
||||
}
|
||||
|
||||
// *****************************************************************************************************************************
|
||||
if (testBegin("logSignal()"))
|
||||
{
|
||||
TEST_RESULT_VOID(logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 0, 999, false), "init logging to debug");
|
||||
|
||||
TEST_RESULT_VOID(logSignal(logLevelDebug, "SIGNAL_NAME"), "log debug");
|
||||
TEST_RESULT_Z(logBuffer, "terminated on signal SIGNAL_NAME\n", "check log");
|
||||
}
|
||||
|
||||
FUNCTION_HARNESS_RETURN_VOID();
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user