1
0
mirror of https://github.com/pgbackrest/pgbackrest.git synced 2025-01-30 05:39:12 +02:00

Allow default process id to be specified in logInit().

The default process id was previously always 0 but there are cases where it is useful to be able to set the default.

Currently the only use case is for testing but the upcoming server code will also make use of it.
This commit is contained in:
David Steele 2020-04-07 14:23:31 -04:00
parent 2ec379fa40
commit ac3cfa4c9c
12 changed files with 79 additions and 38 deletions

View File

@ -37,6 +37,9 @@ DEBUG_UNIT_EXTERN bool logFileBanner = false;
// Is the timestamp printed in the log?
static bool logTimestamp = false;
// Default process id if none is specified
DEBUG_UNIT_EXTERN unsigned int logProcessId = 0;
// Size of the process id field
static int logProcessSize = 2;
@ -143,13 +146,14 @@ logAny(LogLevel logLevel)
void
logInit(
LogLevel logLevelStdOutParam, LogLevel logLevelStdErrParam, LogLevel logLevelFileParam, bool logTimestampParam,
unsigned int logProcessMax, bool dryRunParam)
unsigned int processId, unsigned int logProcessMax, bool dryRunParam)
{
FUNCTION_TEST_BEGIN();
FUNCTION_TEST_PARAM(ENUM, logLevelStdOutParam);
FUNCTION_TEST_PARAM(ENUM, logLevelStdErrParam);
FUNCTION_TEST_PARAM(ENUM, logLevelFileParam);
FUNCTION_TEST_PARAM(BOOL, logTimestampParam);
FUNCTION_TEST_PARAM(UINT, processId);
FUNCTION_TEST_PARAM(UINT, logProcessMax);
FUNCTION_TEST_PARAM(BOOL, dryRunParam);
FUNCTION_TEST_END();
@ -157,12 +161,14 @@ logInit(
ASSERT(logLevelStdOutParam <= LOG_LEVEL_MAX);
ASSERT(logLevelStdErrParam <= LOG_LEVEL_MAX);
ASSERT(logLevelFileParam <= LOG_LEVEL_MAX);
ASSERT(processId <= 999);
ASSERT(logProcessMax <= 999);
logLevelStdOut = logLevelStdOutParam;
logLevelStdErr = logLevelStdErrParam;
logLevelFile = logLevelFileParam;
logTimestamp = logTimestampParam;
logProcessId = processId;
logProcessSize = logProcessMax > 99 ? 3 : 2;
logDryRun = dryRunParam;
@ -238,7 +244,7 @@ logClose(void)
FUNCTION_TEST_VOID();
// Disable all logging
logInit(logLevelOff, logLevelOff, logLevelOff, false, 1, false);
logInit(logLevelOff, logLevelOff, logLevelOff, false, 0, 1, false);
// Close the log file if it is open
logFileClose();
@ -376,8 +382,8 @@ logPre(LogLevel logLevel, unsigned int processId, const char *fileName, const ch
// Add process and aligned log level
result.bufferPos += (size_t)snprintf(
logBuffer + result.bufferPos, sizeof(logBuffer) - result.bufferPos, "P%0*u %*s: ", logProcessSize, processId, 6,
logLevelStr(logLevel));
logBuffer + result.bufferPos, sizeof(logBuffer) - result.bufferPos, "P%0*u %*s: ", logProcessSize,
processId == (unsigned int)-1 ? logProcessId : processId, 6, logLevelStr(logLevel));
// When writing to stderr the timestamp, process, and log level alignment will be skipped
result.logBufferStdErr = logBuffer + result.bufferPos - strlen(logLevelStr(logLevel)) - 2;

View File

@ -4,6 +4,7 @@ Log Handler
#ifndef COMMON_LOG_H
#define COMMON_LOG_H
#include <limits.h>
#include <stdbool.h>
#include "common/logLevel.h"
@ -21,7 +22,7 @@ Functions
// Initialize the log system
void logInit(
LogLevel logLevelStdOutParam, LogLevel logLevelStdErrParam, LogLevel logLevelFileParam, bool logTimestampParam,
unsigned int logProcessMax, bool dryRun);
unsigned int processId, unsigned int logProcessMax, bool dryRun);
// Close the log system
void logClose(void);
@ -111,7 +112,7 @@ do
LOG_PID_FMT(logLevelTrace, processId, 0, __VA_ARGS__)
#define LOG(logLevel, code, message) \
LOG_PID(logLevel, 0, code, message)
LOG_PID(logLevel, UINT_MAX, code, message)
#define LOG_ASSERT(message) \
LOG(logLevelAssert, errorTypeCode(&AssertError), message)
@ -129,7 +130,7 @@ do
LOG(logLevelTrace, 0, message)
#define LOG_FMT(logLevel, code, ...) \
LOG_PID_FMT(logLevel, 0, code, __VA_ARGS__)
LOG_PID_FMT(logLevel, UINT_MAX, code, __VA_ARGS__)
#define LOG_ASSERT_FMT(...) \
LOG_FMT(logLevelAssert, errorTypeCode(&AssertError), __VA_ARGS__)

View File

@ -52,7 +52,7 @@ cfgLoadLogSetting(void)
logProcessMax = cfgOptionUInt(cfgOptProcessMax);
logInit(
logLevelConsole, logLevelStdErr, logLevelFile, logTimestamp, logProcessMax,
logLevelConsole, logLevelStdErr, logLevelFile, logTimestamp, 0, logProcessMax,
cfgOptionValid(cfgOptDryRun) && cfgOptionBool(cfgOptDryRun));
FUNCTION_LOG_RETURN_VOID();

View File

@ -613,7 +613,7 @@ configParse(unsigned int argListSize, const char *argList[], bool resetLogLevel)
// Enable logging (except for local and remote commands) so config file warnings will be output
if (cfgCommandRole() != cfgCmdRoleLocal && cfgCommandRole() != cfgCmdRoleRemote && resetLogLevel)
logInit(logLevelWarn, logLevelWarn, logLevelOff, false, 1, false);
logInit(logLevelWarn, logLevelWarn, logLevelOff, false, 0, 1, false);
// Only continue if command options need to be validated, i.e. a real command is running or we are getting help for a
// specific command and would like to display actual option values in the help.

View File

@ -40,6 +40,8 @@ There should not be any code outside the HARNESS_FORK_CHILD_BEGIN/END() and HARN
#include <common/fork.h>
#include <common/harnessLog.h>
/***********************************************************************************************************************************
Define the max number of child processes allowed
***********************************************************************************************************************************/
@ -141,6 +143,9 @@ Create a child process
{ \
unsigned int HARNESS_FORK_PROCESS_IDX() = HARNESS_FORK_PROCESS_TOTAL(); \
\
/* Change log process id to aid in debugging */ \
hrnLogProcessIdSet(HARNESS_FORK_PROCESS_IDX() + 1); \
\
if (pipeRequired) \
{ \
close(HARNESS_FORK_PARENT_READ_PROCESS(HARNESS_FORK_PROCESS_IDX())); \

View File

@ -23,6 +23,7 @@ Expose log internal data for unit testing/debugging
extern LogLevel logLevelFile;
extern int logHandleFile;
extern bool logFileBanner;
extern unsigned int logProcessId;
extern void logAnySet(void);
/***********************************************************************************************************************************
@ -72,7 +73,7 @@ harnessLogInit(void)
{
FUNCTION_HARNESS_VOID();
logInit(logLevelTestDefault, logLevelOff, logLevelInfo, false, 99, false);
logInit(logLevelTestDefault, logLevelOff, logLevelInfo, false, logProcessId, 99, false);
logFileBanner = true;
snprintf(logFile, sizeof(logFile), "%s/expect.log", testDataPath());
@ -88,7 +89,7 @@ harnessLogDryRunSet(bool dryRun)
{
logDryRunTest = dryRun;
logInit(logLevelTestDefault, logLevelOff, logLevelTest, false, 99, logDryRunTest);
logInit(logLevelTestDefault, logLevelOff, logLevelTest, false, logProcessId, 99, logDryRunTest);
}
/***********************************************************************************************************************************
@ -101,7 +102,7 @@ harnessLogLevelSet(LogLevel logLevel)
{
logLevelTest = logLevel;
logInit(logLevelTestDefault, logLevelOff, logLevelTest, false, 99, logDryRunTest);
logInit(logLevelTestDefault, logLevelOff, logLevelTest, false, logProcessId, 99, logDryRunTest);
}
/***********************************************************************************************************************************
@ -114,7 +115,7 @@ harnessLogLevelReset(void)
{
logLevelTest = logLevelInfo;
logInit(logLevelTestDefault, logLevelOff, logLevelTest, false, 99, logDryRunTest);
logInit(logLevelTestDefault, logLevelOff, logLevelTest, false, logProcessId, 99, logDryRunTest);
}
/***********************************************************************************************************************************
@ -128,6 +129,12 @@ harnessLogLevelDefaultSet(LogLevel logLevel)
logLevelTestDefault = logLevel;
}
/**********************************************************************************************************************************/
void hrnLogProcessIdSet(unsigned int processId)
{
logProcessId = processId;
}
/***********************************************************************************************************************************
Load log result from file into the log buffer
***********************************************************************************************************************************/

View File

@ -26,6 +26,13 @@ Getters/Setters
void harnessLogLevelReset(void);
void harnessLogLevelSet(LogLevel logLevel);
// Set the process id used for logging. Ignore the request if the logging module is not active yet.
#ifndef NO_LOG
void hrnLogProcessIdSet(unsigned int processId);
#else
#define hrnLogProcessIdSet(processId)
#endif
/***********************************************************************************************************************************
Internal Setters
***********************************************************************************************************************************/

View File

@ -627,7 +627,7 @@ testRun(void)
}
HARNESS_FORK_END();
harnessLogResult("P00 INFO: unable to find 000000010000000100000001 in the archive");
harnessLogResult("P01 INFO: unable to find 000000010000000100000001 in the archive");
// Check for missing WAL
// -------------------------------------------------------------------------------------------------------------------------
@ -644,7 +644,7 @@ testRun(void)
}
HARNESS_FORK_END();
harnessLogResult("P00 INFO: unable to find 000000010000000100000001 in the archive");
harnessLogResult("P01 INFO: unable to find 000000010000000100000001 in the archive");
TEST_RESULT_BOOL(
storageExistsP(storageSpool(), strNewFmt(STORAGE_SPOOL_ARCHIVE_IN "/%s.ok", strPtr(walSegment))), false,
@ -666,7 +666,7 @@ testRun(void)
}
HARNESS_FORK_END();
TEST_RESULT_VOID(harnessLogResult("P00 INFO: found 000000010000000100000001 in the archive"), "check log");
TEST_RESULT_VOID(harnessLogResult("P01 INFO: found 000000010000000100000001 in the archive"), "check log");
TEST_RESULT_BOOL(
storageExistsP(storageSpoolWrite(), strNewFmt(STORAGE_SPOOL_ARCHIVE_IN "/%s", strPtr(walSegment))), false,
@ -698,7 +698,7 @@ testRun(void)
}
HARNESS_FORK_END();
TEST_RESULT_VOID(harnessLogResult("P00 INFO: found 000000010000000100000001 in the archive"), "check log");
TEST_RESULT_VOID(harnessLogResult("P01 INFO: found 000000010000000100000001 in the archive"), "check log");
TEST_RESULT_BOOL(storageExistsP(storageTest, walFile), true, "check WAL segment was moved");
@ -718,7 +718,7 @@ testRun(void)
}
HARNESS_FORK_END();
harnessLogResult("P00 INFO: unable to find 000000010000000100000001 in the archive");
harnessLogResult("P01 INFO: unable to find 000000010000000100000001 in the archive");
// -------------------------------------------------------------------------------------------------------------------------
strLstAddZ(argList, BOGUS_STR);

View File

@ -14,6 +14,9 @@ testHttpServer(void)
{
if (fork() == 0)
{
// Change log process id to aid in debugging
hrnLogProcessIdSet(1);
harnessTlsServerInitDefault();
// Test no output from server

View File

@ -16,6 +16,9 @@ testTlsServerAltName(void)
{
if (fork() == 0)
{
// Change log process id to aid in debugging
hrnLogProcessIdSet(1);
harnessTlsServerInit(
harnessTlsTestPort(),
strPtr(strNewFmt("%s/" TEST_CERTIFICATE_PREFIX "-alt-name.crt", testRepoPath())),
@ -60,6 +63,9 @@ testTlsServer(void)
{
if (fork() == 0)
{
// Change log process id to aid in debugging
hrnLogProcessIdSet(1);
harnessTlsServerInitDefault();
// First protocol exchange

View File

@ -120,14 +120,14 @@ testRun(void)
TEST_RESULT_INT(logLevelStdErr, logLevelError, "stderr logging is error");
TEST_RESULT_INT(logLevelFile, logLevelOff, "file logging is off");
TEST_RESULT_VOID(logInit(logLevelInfo, logLevelWarn, logLevelError, true, 99, true), "init logging");
TEST_RESULT_VOID(logInit(logLevelInfo, logLevelWarn, logLevelError, true, 0, 99, true), "init logging");
TEST_RESULT_INT(logLevelStdOut, logLevelInfo, "console logging is info");
TEST_RESULT_INT(logLevelStdErr, logLevelWarn, "stderr logging is warn");
TEST_RESULT_INT(logLevelFile, logLevelError, "file logging is error");
TEST_RESULT_INT(logProcessSize, 2, "process field size is 2");
TEST_RESULT_BOOL(logDryRun, true, "dry run is true");
TEST_RESULT_VOID(logInit(logLevelInfo, logLevelWarn, logLevelError, true, 100, false), "init logging");
TEST_RESULT_VOID(logInit(logLevelInfo, logLevelWarn, logLevelError, true, 0, 100, false), "init logging");
TEST_RESULT_INT(logProcessSize, 3, "process field size is 3");
TEST_RESULT_BOOL(logDryRun, false, "dry run is false");
}
@ -168,12 +168,12 @@ testRun(void)
// *****************************************************************************************************************************
if (testBegin("logInternal() and logInternalFmt()"))
{
TEST_RESULT_VOID(logInit(logLevelOff, logLevelOff, logLevelOff, false, 1, false), "init logging to off");
TEST_RESULT_VOID(logInit(logLevelOff, logLevelOff, logLevelOff, false, 0, 1, false), "init logging to off");
TEST_RESULT_VOID(
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, false), "init logging to warn (timestamp on)");
TEST_RESULT_VOID(logInit(logLevelWarn, logLevelOff, logLevelOff, true, 0, 1, false), "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, 0, "file", "function", 0, "TEST"), "log timestamp");
@ -193,29 +193,31 @@ testRun(void)
snprintf(stderrFile, sizeof(stderrFile), "%s/stderr.log", testPath());
logHandleStdErr = testLogOpen(stderrFile, O_WRONLY | O_CREAT | O_TRUNC, 0640);
TEST_RESULT_VOID(logInit(logLevelWarn, logLevelOff, logLevelOff, false, 1, false), "init logging to warn (timestamp off)");
TEST_RESULT_VOID(
logInit(logLevelWarn, logLevelOff, logLevelOff, false, 44, 1, false), "init logging to warn (timestamp off)");
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternalFmt(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 0, "format %d", 99), "log warn");
TEST_RESULT_Z(logBuffer, "P00 WARN: format 99\n", " check log");
logInternalFmt(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, UINT_MAX, "file", "function", 0, "format %d", 99),
"log warn");
TEST_RESULT_Z(logBuffer, "P44 WARN: format 99\n", " check log");
// This won't be logged due to the range
TEST_RESULT_VOID(
logInternal(logLevelWarn, logLevelError, logLevelError, 0, "file", "function", 0, "NOT OUTPUT"), "out of range");
logInternal(logLevelWarn, logLevelError, logLevelError, UINT_MAX, "file", "function", 0, "NOT OUTPUT"), "out of range");
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 26, "message"), "log error");
TEST_RESULT_Z(logBuffer, "P00 ERROR: [026]: message\n", " check log");
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, UINT_MAX, "file", "function", 26, "message"), "log error");
TEST_RESULT_Z(logBuffer, "P44 ERROR: [026]: message\n", " check log");
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 26, "message1\nmessage2"),
logInternal(logLevelError, LOG_LEVEL_MIN, LOG_LEVEL_MAX, UINT_MAX, "file", "function", 26, "message1\nmessage2"),
"log error with multiple lines");
TEST_RESULT_Z(logBuffer, "P00 ERROR: [026]: message1\nmessage2\n", " check log");
TEST_RESULT_Z(logBuffer, "P44 ERROR: [026]: message1\nmessage2\n", " check log");
TEST_RESULT_VOID(logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 999, false), "init logging to debug");
TEST_RESULT_VOID(logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 0, 999, false), "init logging to debug");
// Log to file
char fileFile[1024];
@ -230,16 +232,17 @@ testRun(void)
// This won't be logged due to the range
TEST_RESULT_VOID(
logInternal(logLevelDebug, logLevelTrace, logLevelTrace, 0, "test.c", "test_func", 0, "NOT OUTPUT"), "out of range");
logInternal(logLevelDebug, logLevelTrace, logLevelTrace, UINT_MAX, "test.c", "test_func", 0, "NOT OUTPUT"),
"out of range");
logBuffer[0] = 0;
TEST_RESULT_VOID(
logInternal(logLevelTrace, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "test.c", "test_func", 0, "message"), "log debug");
logInternal(logLevelTrace, LOG_LEVEL_MIN, LOG_LEVEL_MAX, UINT_MAX, "test.c", "test_func", 0, "message"), "log debug");
TEST_RESULT_Z(logBuffer, "P000 TRACE: test::test_func: message\n", " check log");
// Reopen the log file
TEST_RESULT_VOID(
logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 99, true), "reduce process-id size and dry-run");
logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 0, 99, true), "reduce process-id size and dry-run");
TEST_RESULT_BOOL(logFileSet(fileFile), true, "open valid file");
logBuffer[0] = 0;
@ -255,7 +258,7 @@ testRun(void)
TEST_RESULT_INT(logHandleFile, -1, "log file is closed");
// Close logging again
TEST_RESULT_VOID(logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 99, false), "reduce log size");
TEST_RESULT_VOID(logInit(logLevelDebug, logLevelDebug, logLevelDebug, false, 0, 99, false), "reduce log size");
TEST_RESULT_BOOL(logFileSet(fileFile), true, "open valid file");
TEST_RESULT_BOOL(logHandleFile != -1, true, "log file is open");
@ -268,9 +271,9 @@ testRun(void)
// Check stdout
testLogResult(
stdoutFile,
"P00 WARN: format 99\n"
"P00 ERROR: [026]: message\n"
"P00 ERROR: [026]: message1\n"
"P44 WARN: format 99\n"
"P44 ERROR: [026]: message\n"
"P44 ERROR: [026]: message1\n"
" message2");
// Check stderr

View File

@ -87,6 +87,9 @@ testS3Server(void)
{
if (fork() == 0)
{
// Change log process id to aid in debugging
hrnLogProcessIdSet(1);
harnessTlsServerInitDefault();
harnessTlsServerAccept();