1
0
mirror of https://github.com/pgbackrest/pgbackrest.git synced 2025-01-18 04:58:51 +02:00

Allow process id in C logging

The default process id in C logging has always been zero.  This should have been updated when multi-processing was introduced in C, but it was missed.
This commit is contained in:
David Steele 2019-04-09 10:54:36 -04:00
parent 6099729e92
commit 4ace7edbd9
5 changed files with 61 additions and 30 deletions

View File

@ -98,7 +98,7 @@
</release-item>
<release-item>
<p>Allow three-digits process IDs in logging.</p>
<p>Logging improvements. Allow three-digits process IDs in logging. Allow process id in C logging.</p>
</release-item>
<release-item>

View File

@ -117,13 +117,13 @@ exitSafe(int result, bool error, SignalType signalType)
else
{
// Log just the error to non-debug levels
LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, logLevelDetail, errorCode(), errorMessage());
LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, logLevelDetail, 0, errorCode(), errorMessage());
// Log the stack trace debug levels
if (logWill(logLevelDebug))
{
LOG_INTERNAL(
logLevel, logLevelDebug, LOG_LEVEL_MAX, errorCode(), "%s\nSTACK TRACE:\n%s", errorMessage(),
logLevel, logLevelDebug, LOG_LEVEL_MAX, 0, errorCode(), "%s\nSTACK TRACE:\n%s", errorMessage(),
errorStackTrace());
}
}

View File

@ -347,8 +347,8 @@ General log function
***********************************************************************************************************************************/
void
logInternal(
LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, const char *fileName, const char *functionName, int code,
const char *format, ...)
LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, unsigned int processId, const char *fileName,
const char *functionName, int code, const char *format, ...)
{
FUNCTION_TEST_BEGIN();
FUNCTION_TEST_PARAM(ENUM, logLevel);
@ -386,7 +386,7 @@ logInternal(
// Add process and aligned log level
bufferPos += (size_t)snprintf(
logBuffer + bufferPos, sizeof(logBuffer) - bufferPos, "P%0*d %*s: ", logProcessSize, 0, 6, logLevelStr(logLevel));
logBuffer + bufferPos, sizeof(logBuffer) - bufferPos, "P%0*u %*s: ", logProcessSize, processId, 6, logLevelStr(logLevel));
// When writing to stderr the timestamp, process, and log level alignment will be skipped
char *logBufferStdErr = logBuffer + bufferPos - strlen(logLevelStr(logLevel)) - 2;

View File

@ -32,13 +32,19 @@ const char *logLevelStr(LogLevel logLevel);
/***********************************************************************************************************************************
Macros
Only call logInternal() if the message will be logged to one of the available outputs.
***********************************************************************************************************************************/
#define LOG_INTERNAL(logLevel, logRangeMin, logRangeMax, code, ...) \
logInternal(logLevel, logRangeMin, logRangeMax, __FILE__, __func__, code, __VA_ARGS__)
Only call logInternal() if the message will be logged to one of the available outputs. Also simplify each call site by supplying
commonly-used values.
Note that it's possible that that not all the macros below will appear in the code. They are included for completeness and future
usage.
***********************************************************************************************************************************/
#define LOG_INTERNAL(logLevel, logRangeMin, logRangeMax, processId, code, ...) \
logInternal(logLevel, logRangeMin, logRangeMax, processId, __FILE__, __func__, code, __VA_ARGS__)
#define LOG_PID(logLevel, processId, code, ...) \
LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX, processId, code, __VA_ARGS__)
#define LOG(logLevel, code, ...) \
LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX, code, __VA_ARGS__)
LOG_PID(logLevel, 0, code, __VA_ARGS__)
#define LOG_WILL(logLevel, code, ...) \
do \
@ -47,6 +53,13 @@ do
LOG(logLevel, code, __VA_ARGS__); \
} while(0)
#define LOG_WILL_PID(logLevel, processId, code, ...) \
do \
{ \
if (logWill(logLevel)) \
LOG_PID(logLevel, processId, code, __VA_ARGS__); \
} while(0)
#define LOG_ASSERT(...) \
LOG_WILL(logLevelAssert, errorTypeCode(&AssertError), __VA_ARGS__)
#define LOG_ERROR(code, ...) \
@ -62,11 +75,26 @@ do
#define LOG_TRACE(...) \
LOG_WILL(logLevelTrace, 0, __VA_ARGS__)
#define LOG_ASSERT_PID(processId, ...) \
LOG_WILL_PID(logLevelAssert, processId, errorTypeCode(&AssertError), __VA_ARGS__)
#define LOG_ERROR_PID(processId, code, ...) \
LOG_WILL_PID(logLevelError, processId, code, __VA_ARGS__)
#define LOG_WARN_PID(processId, ...) \
LOG_WILL_PID(logLevelWarn, processId, 0, __VA_ARGS__)
#define LOG_INFO_PID(processId, ...) \
LOG_WILL_PID(logLevelInfo, processId, 0, __VA_ARGS__)
#define LOG_DETAIL_PID(processId, ...) \
LOG_WILL_PID(logLevelDetail, processId, 0, __VA_ARGS__)
#define LOG_DEBUG_PID(processId, ...) \
LOG_WILL_PID(logLevelDebug, processId, 0, __VA_ARGS__)
#define LOG_TRACE_PID(processId, ...) \
LOG_WILL_PID(logLevelTrace, processId, 0, __VA_ARGS__)
/***********************************************************************************************************************************
Internal Functions
***********************************************************************************************************************************/
void logInternal(
LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, const char *fileName, const char *functionName,
int code, const char *format, ...);
LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, unsigned int processId, const char *fileName,
const char *functionName, int code, const char *format, ...);
#endif

View File

@ -179,12 +179,13 @@ testRun(void)
{
TEST_RESULT_VOID(logInit(logLevelOff, logLevelOff, logLevelOff, false, 1), "init logging to off");
TEST_RESULT_VOID(
logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "file", "function", 0, "format"),
logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 0, "format"),
"message not logged anywhere");
TEST_RESULT_VOID(logInit(logLevelWarn, logLevelOff, logLevelOff, true, 1), "init logging to warn (timestamp on)");
TEST_RESULT_VOID(logFileSet(BOGUS_STR), "ignore bogus filename because file logging is off");
TEST_RESULT_VOID(logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "file", "function", 0, "TEST"), "log timestamp");
TEST_RESULT_VOID(
logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 0, "TEST"), "log timestamp");
String *logTime = strNewN(logBuffer, 23);
TEST_RESULT_BOOL(
@ -205,20 +206,21 @@ testRun(void)
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "file", "function", 0, "format %d", 99), "log warn");
logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 0, "format %d", 99), "log warn");
TEST_RESULT_STR(logBuffer, "P00 WARN: format 99\n", " check log");
// This won't be logged due to the range
TEST_RESULT_VOID(
logInternal(logLevelWarn, logLevelError, logLevelError, "file", "function", 0, "NOT OUTPUT"), "out of range");
logInternal(logLevelWarn, logLevelError, logLevelError, 0, "file", "function", 0, "NOT OUTPUT"), "out of range");
logBuffer[0] = 0;
TEST_RESULT_VOID(logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "file", "function", 26, "message"), "log error");
TEST_RESULT_VOID(
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 26, "message"), "log error");
TEST_RESULT_STR(logBuffer, "P00 ERROR: [026]: message\n", " check log");
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "file", "function", 26, "message1\nmessage2"),
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 26, "message1\nmessage2"),
"log error with multiple lines");
TEST_RESULT_STR(logBuffer, "P00 ERROR: [026]: message1\nmessage2\n", " check log");
@ -231,16 +233,17 @@ testRun(void)
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelDebug, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "test.c", "test_func", 0, "message\nmessage2"), "log debug");
TEST_RESULT_STR(logBuffer, "P000 DEBUG: test::test_func: message\nmessage2\n", " check log");
logInternal(
logLevelDebug, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 999, "test.c", "test_func", 0, "message\nmessage2"), "log debug");
TEST_RESULT_STR(logBuffer, "P999 DEBUG: test::test_func: message\nmessage2\n", " check log");
// This won't be logged due to the range
TEST_RESULT_VOID(
logInternal(logLevelDebug, logLevelTrace, logLevelTrace, "test.c", "test_func", 0, "NOT OUTPUT"), "out of range");
logInternal(logLevelDebug, logLevelTrace, logLevelTrace, 0, "test.c", "test_func", 0, "NOT OUTPUT"), "out of range");
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelTrace, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "test.c", "test_func", 0, "message"), "log debug");
logInternal(logLevelTrace, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "test.c", "test_func", 0, "message"), "log debug");
TEST_RESULT_STR(logBuffer, "P000 TRACE: test::test_func: message\n", " check log");
// Reopen the log file
@ -249,11 +252,11 @@ testRun(void)
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelInfo, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "test.c", "test_func", 0, "info message"), "log info");
TEST_RESULT_STR(logBuffer, "P00 INFO: info message\n", " check log");
logInternal(logLevelInfo, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 1, "test.c", "test_func", 0, "info message"), "log info");
TEST_RESULT_STR(logBuffer, "P01 INFO: info message\n", " check log");
TEST_RESULT_VOID(
logInternal(logLevelInfo, LOG_LEVEL_MIN, LOG_LEVEL_MAX, "test.c", "test_func", 0, "info message 2"), "log info");
TEST_RESULT_STR(logBuffer, "P00 INFO: info message 2\n", " check log");
logInternal(logLevelInfo, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 99, "test.c", "test_func", 0, "info message 2"), "log info");
TEST_RESULT_STR(logBuffer, "P99 INFO: info message 2\n", " check log");
// Reopen invalid log file
TEST_RESULT_BOOL(logFileSet("/" BOGUS_STR), false, "attempt to open bogus file");
@ -292,12 +295,12 @@ testRun(void)
testLogResult(
fileFile,
"-------------------PROCESS START-------------------\n"
"P000 DEBUG: test::test_func: message\n"
"P999 DEBUG: test::test_func: message\n"
" message2\n"
"\n"
"-------------------PROCESS START-------------------\n"
"P00 INFO: info message\n"
"P00 INFO: info message 2");
"P01 INFO: info message\n"
"P99 INFO: info message 2");
}
FUNCTION_HARNESS_RESULT_VOID();