pgbackrest.git / summary / log / commit / refs
commit 0c05df458287c77df1188a68bbd74e145ed0f059
Author: David Steele <david@pgmasters.net>
Date: Fri Nov 22 18:33:26 2019 +0000
Add _FMT() logging macro variants.
Using the same macros for formatted and unformatted logging had several disadvantages.
First, the compiler was unable to verify the format string against the parameters.
Second, legitimate % characters in messages were being interpreted as format characters with garbage output ensuing.
Add _FMT() variants and update all call sites to use the correct variant.
src/command/archive/get/get.c | 12 +--
src/command/archive/push/push.c | 10 +--
src/command/check/check.c | 4 +-
src/command/control/start.c | 2 +-
src/command/control/stop.c | 8 +-
src/command/expire/expire.c | 20 ++---
src/command/restore/restore.c | 67 ++++++++--------
src/command/stanza/create.c | 2 +-
src/command/stanza/upgrade.c | 2 +-
src/common/debug.h | 6 +-
src/common/exit.c | 4 +-
src/common/io/http/client.c | 2 +-
src/common/io/tls/client.c | 2 +-
src/common/log.c | 160 ++++++++++++++++++++++++++++++---------
src/common/log.h | 139 +++++++++++++++++++++++-----------
src/config/load.c | 8 +-
src/config/parse.c | 18 ++---
src/db/helper.c | 2 +-
src/info/infoBackup.c | 6 +-
src/storage/s3/storage.c | 2 +-
test/src/module/common/logTest.c | 4 +-
21 files changed, 311 insertions(+), 169 deletions(-)
diff --git a/src/command/archive/get/get.c b/src/command/archive/get/get.c
index 91e846eec..9e8e9d3dd 100644
--- a/src/command/archive/get/get.c
+++ b/src/command/archive/get/get.c
@@ -275,9 +275,9 @@ cmdArchiveGet(void)
// Log whether or not the file was found
if (result == 0)
- LOG_INFO("found %s in the archive", strPtr(walSegment));
+ LOG_INFO_FMT("found %s in the archive", strPtr(walSegment));
else
- LOG_INFO("unable to find %s in the archive", strPtr(walSegment));
+ LOG_INFO_FMT("unable to find %s in the archive", strPtr(walSegment));
}
MEM_CONTEXT_TEMP_END();
@@ -335,7 +335,7 @@ cmdArchiveGetAsync(void)
if (strLstSize(jobData.walSegmentList) < 1)
THROW(ParamInvalidError, "at least one wal segment is required");
- LOG_INFO(
+ LOG_INFO_FMT(
"get %u WAL file(s) from archive: %s%s",
strLstSize(jobData.walSegmentList), strPtr(strLstGet(jobData.walSegmentList, 0)),
strLstSize(jobData.walSegmentList) == 1 ?
@@ -367,19 +367,19 @@ cmdArchiveGetAsync(void)
// Get the archive file
if (varIntForce(protocolParallelJobResult(job)) == 0)
{
- LOG_DETAIL_PID(processId, "found %s in the archive", strPtr(walSegment));
+ LOG_DETAIL_PID_FMT(processId, "found %s in the archive", strPtr(walSegment));
}
// If it does not exist write an ok file to indicate that it was checked
else
{
- LOG_DETAIL_PID(processId, "unable to find %s in the archive", strPtr(walSegment));
+ LOG_DETAIL_PID_FMT(processId, "unable to find %s in the archive", strPtr(walSegment));
archiveAsyncStatusOkWrite(archiveModeGet, walSegment, NULL);
}
}
// Else the job errored
else
{
- LOG_WARN_PID(
+ LOG_WARN_PID_FMT(
processId,
"could not get %s from the archive (will be retried): [%d] %s", strPtr(walSegment),
protocolParallelJobErrorCode(job), strPtr(protocolParallelJobErrorMessage(job)));
diff --git a/src/command/archive/push/push.c b/src/command/archive/push/push.c
index 4e09c275e..30b53458a 100644
--- a/src/command/archive/push/push.c
+++ b/src/command/archive/push/push.c
@@ -340,7 +340,7 @@ cmdArchivePush(void)
}
// Log success
- LOG_INFO("pushed WAL file '%s' to the archive asynchronously", strPtr(archiveFile));
+ LOG_INFO_FMT("pushed WAL file '%s' to the archive asynchronously", strPtr(archiveFile));
}
else
{
@@ -371,7 +371,7 @@ cmdArchivePush(void)
LOG_WARN(strPtr(warning));
// Log success
- LOG_INFO("pushed WAL file '%s' to the archive", strPtr(archiveFile));
+ LOG_INFO_FMT("pushed WAL file '%s' to the archive", strPtr(archiveFile));
}
}
}
@@ -463,7 +463,7 @@ cmdArchivePushAsync(void)
if (strLstSize(jobData.walFileList) == 0)
THROW(AssertError, "no WAL files to process");
- LOG_INFO(
+ LOG_INFO_FMT(
"push %u WAL file(s) to archive: %s%s", strLstSize(jobData.walFileList), strPtr(strLstGet(jobData.walFileList, 0)),
strLstSize(jobData.walFileList) == 1 ?
"" : strPtr(strNewFmt("...%s", strPtr(strLstGet(jobData.walFileList, strLstSize(jobData.walFileList) - 1)))));
@@ -517,13 +517,13 @@ cmdArchivePushAsync(void)
// The job was successful
if (protocolParallelJobErrorCode(job) == 0)
{
- LOG_DETAIL_PID(processId, "pushed WAL file '%s' to the archive", strPtr(walFile));
+ LOG_DETAIL_PID_FMT(processId, "pushed WAL file '%s' to the archive", strPtr(walFile));
archiveAsyncStatusOkWrite(archiveModePush, walFile, varStr(protocolParallelJobResult(job)));
}
// Else the job errored
else
{
- LOG_WARN_PID(
+ LOG_WARN_PID_FMT(
processId,
"could not push WAL file '%s' to the archive (will be retried): [%d] %s", strPtr(walFile),
protocolParallelJobErrorCode(job), strPtr(protocolParallelJobErrorMessage(job)));
diff --git a/src/command/check/check.c b/src/command/check/check.c
index f258c71b9..851d8eda3 100644
--- a/src/command/check/check.c
+++ b/src/command/check/check.c
@@ -91,7 +91,7 @@ checkStandby(const DbGetResult dbGroup, unsigned int pgPathDefinedTotal)
// If backup from standby is true then warn when a standby not found
else if (cfgOptionBool(cfgOptBackupStandby))
{
- LOG_WARN("option '%s' is enabled but standby is not properly configured", cfgOptionName(cfgOptBackupStandby));
+ LOG_WARN_FMT("option '%s' is enabled but standby is not properly configured", cfgOptionName(cfgOptBackupStandby));
}
FUNCTION_LOG_RETURN_VOID();
@@ -137,7 +137,7 @@ checkPrimary(const DbGetResult dbGroup)
if (walSegmentFile != NULL)
{
- LOG_INFO(
+ LOG_INFO_FMT(
"WAL segment %s successfully archived to '%s'", strPtr(walSegment),
strPtr(storagePathP(storageRepo(), strNewFmt(STORAGE_REPO_ARCHIVE "/%s/%s", strPtr(archiveId),
strPtr(walSegmentFile)))));
diff --git a/src/command/control/start.c b/src/command/control/start.c
index 4162da054..20973e37a 100644
--- a/src/command/control/start.c
+++ b/src/command/control/start.c
@@ -27,7 +27,7 @@ cmdStart(void)
}
else
{
- LOG_WARN("stop file does not exist%s",
+ LOG_WARN_FMT("stop file does not exist%s",
(cfgOptionTest(cfgOptStanza) ? strPtr(strNewFmt(" for stanza %s", strPtr(cfgOptionStr(cfgOptStanza)))) : ""));
}
}
diff --git a/src/command/control/stop.c b/src/command/control/stop.c
index 1d79f4bee..c84e59925 100644
--- a/src/command/control/stop.c
+++ b/src/command/control/stop.c
@@ -61,7 +61,7 @@ cmdStop(void)
// If we cannot open the lock file for any reason then warn and continue to next file
if ((fileHandle = open(strPtr(lockFile), O_RDONLY, 0)) == -1)
{
- LOG_WARN( "unable to open lock file %s", strPtr(lockFile));
+ LOG_WARN_FMT( "unable to open lock file %s", strPtr(lockFile));
continue;
}
@@ -83,9 +83,9 @@ cmdStop(void)
if (processId != NULL && strSize(processId) > 0)
{
if (kill(cvtZToInt(strPtr(processId)), SIGTERM) != 0)
- LOG_WARN("unable to send term signal to process %s", strPtr(processId));
+ LOG_WARN_FMT("unable to send term signal to process %s", strPtr(processId));
else
- LOG_INFO("sent term signal to process %s", strPtr(processId));
+ LOG_INFO_FMT("sent term signal to process %s", strPtr(processId));
}
else
{
@@ -97,7 +97,7 @@ cmdStop(void)
}
else
{
- LOG_WARN(
+ LOG_WARN_FMT(
"stop file already exists for %s",
cfgOptionTest(cfgOptStanza) ? strPtr(strNewFmt("stanza %s", strPtr(cfgOptionStr(cfgOptStanza)))) : "all stanzas");
}
diff --git a/src/command/expire/expire.c b/src/command/expire/expire.c
index c07666210..b401e4436 100644
--- a/src/command/expire/expire.c
+++ b/src/command/expire/expire.c
@@ -131,7 +131,8 @@ expireDiffBackup(InfoBackup *infoBackup)
}
// If the message contains a comma, then prepend "set:"
- LOG_INFO("expire diff backup %s%s", (strChr(backupExpired, ',') != -1 ? "set: " : ""), strPtr(backupExpired));
+ LOG_INFO_FMT(
+ "expire diff backup %s%s", (strChr(backupExpired, ',') != -1 ? "set: " : ""), strPtr(backupExpired));
}
}
}
@@ -187,7 +188,8 @@ expireFullBackup(InfoBackup *infoBackup)
}
// If the message contains a comma, then prepend "set:"
- LOG_INFO("expire full backup %s%s", (strChr(backupExpired, ',') != -1 ? "set: " : ""), strPtr(backupExpired));
+ LOG_INFO_FMT(
+ "expire full backup %s%s", (strChr(backupExpired, ',') != -1 ? "set: " : ""), strPtr(backupExpired));
}
}
}
@@ -206,7 +208,7 @@ logExpire(ArchiveExpired *archiveExpire, String *archiveId)
if (archiveExpire->start != NULL)
{
// Force out any remaining message
- LOG_DETAIL(
+ LOG_DETAIL_FMT(
"remove archive: archiveId = %s, start = %s, stop = %s", strPtr(archiveId), strPtr(archiveExpire->start),
strPtr(archiveExpire->stop));
@@ -236,7 +238,7 @@ removeExpiredArchive(InfoBackup *infoBackup)
// cfgLoadUpdateOption based on certain rules.
if (archiveRetention == 0)
{
- LOG_INFO("option '%s' is not set - archive logs will not be expired", cfgOptionName(cfgOptRepoRetentionArchive));
+ LOG_INFO_FMT("option '%s' is not set - archive logs will not be expired", cfgOptionName(cfgOptRepoRetentionArchive));
}
else
{
@@ -358,7 +360,7 @@ removeExpiredArchive(InfoBackup *infoBackup)
String *fullPath = storagePathP(
storageRepo(), strNewFmt(STORAGE_REPO_ARCHIVE "/%s", strPtr(archiveId)));
storagePathRemoveP(storageRepoWrite(), fullPath, .recurse = true);
- LOG_INFO("remove archive path: %s", strPtr(fullPath));
+ LOG_INFO_FMT("remove archive path: %s", strPtr(fullPath));
}
// Continue to next directory
@@ -394,7 +396,7 @@ removeExpiredArchive(InfoBackup *infoBackup)
// forever.
else
{
- LOG_INFO(
+ LOG_INFO_FMT(
"full backup total < %u - using oldest full backup for %s archive retention", archiveRetention,
strPtr(archiveId));
strLstAdd(localBackupArchiveRetentionList, strLstGet(localBackupRetentionList, 0));
@@ -461,7 +463,7 @@ removeExpiredArchive(InfoBackup *infoBackup)
else
archiveExpireMax = strDup(archiveRange.start);
- LOG_DETAIL(
+ LOG_DETAIL_FMT(
"archive retention on backup %s, archiveId = %s, start = %s%s",
strPtr(backupData->backupLabel), strPtr(archiveId), strPtr(archiveRange.start),
archiveRange.stop != NULL ?
@@ -565,7 +567,7 @@ removeExpiredArchive(InfoBackup *infoBackup)
// Log if no archive was expired
if (archiveExpire.total == 0)
{
- LOG_DETAIL("no archive to remove, archiveId = %s", strPtr(archiveId));
+ LOG_DETAIL_FMT("no archive to remove, archiveId = %s", strPtr(archiveId));
}
// Log if there is more to log
else
@@ -606,7 +608,7 @@ removeExpiredBackup(InfoBackup *infoBackup)
{
if (!strLstExists(currentBackupList, strLstGet(backupList, backupIdx)))
{
- LOG_INFO("remove expired backup %s", strPtr(strLstGet(backupList, backupIdx)));
+ LOG_INFO_FMT("remove expired backup %s", strPtr(strLstGet(backupList, backupIdx)));
storagePathRemoveP(
storageRepoWrite(), strNewFmt(STORAGE_REPO_BACKUP "/%s", strPtr(strLstGet(backupList, backupIdx))),
diff --git a/src/command/restore/restore.c b/src/command/restore/restore.c
index be43199c2..fff7a4290 100644
--- a/src/command/restore/restore.c
+++ b/src/command/restore/restore.c
@@ -90,7 +90,7 @@ restorePathValidate(void)
if ((cfgOptionBool(cfgOptDelta) || cfgOptionBool(cfgOptForce)) &&
!storageExistsP(storagePg(), PG_FILE_PGVERSION_STR) && !storageExistsP(storagePg(), BACKUP_MANIFEST_FILE_STR))
{
- LOG_WARN(
+ LOG_WARN_FMT(
"--delta or --force specified but unable to find '" PG_FILE_PGVERSION "' or '" BACKUP_MANIFEST_FILE "' in '%s' to"
" confirm that this is a valid $PGDATA directory. --delta and --force have been disabled and if any files"
" exist in the destination directories the restore will be aborted.",
@@ -217,7 +217,7 @@ restoreManifestMap(Manifest *manifest)
if (!strEq(targetBase->path, pgPath))
{
- LOG_INFO("remap data directory to '%s'", strPtr(pgPath));
+ LOG_INFO_FMT("remap data directory to '%s'", strPtr(pgPath));
manifestTargetUpdate(manifest, targetBase->name, pgPath, NULL);
}
@@ -280,7 +280,7 @@ restoreManifestMap(Manifest *manifest)
// Remap tablespace if a mapping was found
if (tablespacePath != NULL)
{
- LOG_INFO("map tablespace '%s' to '%s'", strPtr(target->name), strPtr(tablespacePath));
+ LOG_INFO_FMT("map tablespace '%s' to '%s'", strPtr(target->name), strPtr(tablespacePath));
manifestTargetUpdate(manifest, target->name, tablespacePath, NULL);
manifestLinkUpdate(manifest, strNewFmt(MANIFEST_TARGET_PGDATA "/%s", strPtr(target->name)), tablespacePath);
@@ -328,7 +328,7 @@ restoreManifestMap(Manifest *manifest)
// Remap link if a mapping was found
if (linkPath != NULL)
{
- LOG_INFO("map link '%s' to '%s'", strPtr(link), strPtr(linkPath));
+ LOG_INFO_FMT("map link '%s' to '%s'", strPtr(link), strPtr(linkPath));
manifestLinkUpdate(manifest, target->name, linkPath);
// If the link is a file separate the file name from the path to update the target
@@ -358,10 +358,10 @@ restoreManifestMap(Manifest *manifest)
else if (!linkAll)
{
if (target->file != NULL)
- LOG_WARN("file link '%s' will be restored as a file at the same location", strPtr(link));
+ LOG_WARN_FMT("file link '%s' will be restored as a file at the same location", strPtr(link));
else
{
- LOG_WARN(
+ LOG_WARN_FMT(
"contents of directory link '%s' will be restored in a directory at the same location",
strPtr(link));
}
@@ -444,7 +444,7 @@ Check ownership of items in the manifest
const String *owner = strLstGet(type##List, ownerIdx); \
\
if (type##Name() == NULL || !strEq(type##Name(), owner)) \
- LOG_WARN("unknown " #type " '%s' in backup manifest mapped to current " #type, strPtr(owner)); \
+ LOG_WARN_FMT("unknown " #type " '%s' in backup manifest mapped to current " #type, strPtr(owner)); \
} \
} \
while (0)
@@ -488,10 +488,10 @@ restoreManifestOwner(Manifest *manifest)
if (userNull || groupNull)
{
if (userNull)
- LOG_WARN("unknown user in backup manifest mapped to '%s'", strPtr(pathInfo.user));
+ LOG_WARN_FMT("unknown user in backup manifest mapped to '%s'", strPtr(pathInfo.user));
if (groupNull)
- LOG_WARN("unknown group in backup manifest mapped to '%s'", strPtr(pathInfo.group));
+ LOG_WARN_FMT("unknown group in backup manifest mapped to '%s'", strPtr(pathInfo.group));
memContextSwitch(MEM_CONTEXT_OLD());
@@ -580,7 +580,7 @@ restoreCleanOwnership(
{
// If this is a newly created file/link/path then there's no need to log updated permissions
if (!new)
- LOG_DETAIL("update ownership for '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("update ownership for '%s'", strPtr(pgPath));
THROW_ON_SYS_ERROR_FMT(
lchown(strPtr(pgPath), expectedUserId, expectedGroupId) == -1, FileOwnerError, "unable to set ownership for '%s'",
@@ -606,7 +606,7 @@ restoreCleanMode(const String *pgPath, mode_t manifestMode, const StorageInfo *i
// Update mode if not as expected
if (manifestMode != info->mode)
{
- LOG_DETAIL("update mode for '%s' to %04o", strPtr(pgPath), manifestMode);
+ LOG_DETAIL_FMT("update mode for '%s' to %04o", strPtr(pgPath), manifestMode);
THROW_ON_SYS_ERROR_FMT(
chmod(strPtr(pgPath), manifestMode) == -1, FileOwnerError, "unable to set mode for '%s'", strPtr(pgPath));
@@ -676,7 +676,7 @@ restoreCleanInfoListCallback(void *data, const StorageInfo *info)
}
else
{
- LOG_DETAIL("remove invalid file '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("remove invalid file '%s'", strPtr(pgPath));
storageRemoveP(storageLocalWrite(), pgPath, .errorOnMissing = true);
}
@@ -691,7 +691,7 @@ restoreCleanInfoListCallback(void *data, const StorageInfo *info)
{
if (!strEq(manifestLink->destination, info->linkDestination))
{
- LOG_DETAIL("remove link '%s' because destination changed", strPtr(pgPath));
+ LOG_DETAIL_FMT("remove link '%s' because destination changed", strPtr(pgPath));
storageRemoveP(storageLocalWrite(), pgPath, .errorOnMissing = true);
}
else
@@ -699,7 +699,7 @@ restoreCleanInfoListCallback(void *data, const StorageInfo *info)
}
else
{
- LOG_DETAIL("remove invalid link '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("remove invalid link '%s'", strPtr(pgPath));
storageRemoveP(storageLocalWrite(), pgPath, .errorOnMissing = true);
}
@@ -733,7 +733,7 @@ restoreCleanInfoListCallback(void *data, const StorageInfo *info)
}
else
{
- LOG_DETAIL("remove invalid path '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("remove invalid path '%s'", strPtr(pgPath));
storagePathRemoveP(storageLocalWrite(), pgPath, .errorOnMissing = true, .recurse = true);
}
@@ -743,7 +743,7 @@ restoreCleanInfoListCallback(void *data, const StorageInfo *info)
// Special file types cannot exist in the manifest so just delete them
case storageTypeSpecial:
{
- LOG_DETAIL("remove special file '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("remove special file '%s'", strPtr(pgPath));
storageRemoveP(storageLocalWrite(), pgPath, .errorOnMissing = true);
break;
}
@@ -822,7 +822,7 @@ restoreCleanBuild(Manifest *manifest)
// Don't log check for the same path twice. There can be multiple links to files in the same path, but logging it more
// than once makes the logs noisy and looks like a bug.
if (!strLstExists(pathChecked, cleanData->targetPath))
- LOG_DETAIL("check '%s' exists", strPtr(cleanData->targetPath));
+ LOG_DETAIL_FMT("check '%s' exists", strPtr(cleanData->targetPath));
StorageInfo info = storageInfoP(storageLocal(), cleanData->targetPath, .ignoreMissing = true, .followLink = true);
strLstAdd(pathChecked, cleanData->targetPath);
@@ -879,7 +879,7 @@ restoreCleanBuild(Manifest *manifest)
if (manifestFileFindDefault(manifest, STRDEF(MANIFEST_TARGET_PGDATA "/" PG_FILE_TABLESPACEMAP), NULL) != NULL &&
manifestData(manifest)->pgVersion >= PG_VERSION_TABLESPACE_MAP)
{
- LOG_DETAIL("skip '" PG_FILE_TABLESPACEMAP "' -- tablespace links will be created based on mappings");
+ LOG_DETAIL_FMT("skip '" PG_FILE_TABLESPACEMAP "' -- tablespace links will be created based on mappings");
manifestFileRemove(manifest, STRDEF(MANIFEST_TARGET_PGDATA "/" PG_FILE_TABLESPACEMAP));
}
@@ -888,7 +888,7 @@ restoreCleanBuild(Manifest *manifest)
strEq(cfgOptionStr(cfgOptType), RECOVERY_TYPE_PRESERVE_STR) &&
manifestFileFindDefault(manifest, STRDEF(MANIFEST_TARGET_PGDATA "/" PG_FILE_POSTGRESQLAUTOCONF), NULL) != NULL)
{
- LOG_DETAIL("skip '" PG_FILE_POSTGRESQLAUTOCONF "' -- recovery type is preserve");
+ LOG_DETAIL_FMT("skip '" PG_FILE_POSTGRESQLAUTOCONF "' -- recovery type is preserve");
manifestFileRemove(manifest, STRDEF(MANIFEST_TARGET_PGDATA "/" PG_FILE_POSTGRESQLAUTOCONF));
}
@@ -898,7 +898,8 @@ restoreCleanBuild(Manifest *manifest)
// so the file does not return, zombie-like, in the case of a host crash.
if (storageExistsP(storagePg(), STRDEF(PG_PATH_GLOBAL "/" PG_FILE_PGCONTROL)))
{
- LOG_DETAIL("remove '" PG_PATH_GLOBAL "/" PG_FILE_PGCONTROL "' so cluster will not start if restore does not complete");
+ LOG_DETAIL_FMT(
+ "remove '" PG_PATH_GLOBAL "/" PG_FILE_PGCONTROL "' so cluster will not start if restore does not complete");
storageRemoveP(storagePgWrite(), STRDEF(PG_PATH_GLOBAL "/" PG_FILE_PGCONTROL));
storagePathSyncP(storagePgWrite(), PG_PATH_GLOBAL_STR);
}
@@ -916,7 +917,7 @@ restoreCleanBuild(Manifest *manifest)
// Only log when doing a delta restore because otherwise the targets should be empty. We'll still run the clean
// to fix permissions/ownership on the target paths.
if (delta)
- LOG_INFO("remove invalid files/links/paths from '%s'", strPtr(cleanData->targetPath));
+ LOG_INFO_FMT("remove invalid files/links/paths from '%s'", strPtr(cleanData->targetPath));
// Clean the target
storageInfoListP(
@@ -970,7 +971,7 @@ restoreCleanBuild(Manifest *manifest)
// Create the link if it is missing. If it exists it should already have the correct ownership and destination.
if (!linkInfo.exists)
{
- LOG_DETAIL("create symlink '%s' to '%s'", strPtr(pgPath), strPtr(link->destination));
+ LOG_DETAIL_FMT("create symlink '%s' to '%s'", strPtr(pgPath), strPtr(link->destination));
THROW_ON_SYS_ERROR_FMT(
symlink(strPtr(link->destination), strPtr(pgPath)) == -1, FileOpenError,
@@ -987,7 +988,7 @@ restoreCleanBuild(Manifest *manifest)
// Create the path if it is missing If it exists it should already have the correct ownership and mode.
if (!pathInfo.exists)
{
- LOG_DETAIL("create path '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("create path '%s'", strPtr(pgPath));
storagePathCreateP(storagePgWrite(), pgPath, .mode = path->mode, .noParentCreate = true, .errorOnExists = true);
restoreCleanOwnership(storagePathP(storagePg(), pgPath), path->user, path->group, userId(), groupId(), true);
@@ -1007,7 +1008,7 @@ restoreCleanBuild(Manifest *manifest)
// Create the link if it is missing. If it exists it should already have the correct ownership and destination.
if (!linkInfo.exists)
{
- LOG_DETAIL("create symlink '%s' to '%s'", strPtr(pgPath), strPtr(link->destination));
+ LOG_DETAIL_FMT("create symlink '%s' to '%s'", strPtr(pgPath), strPtr(link->destination));
THROW_ON_SYS_ERROR_FMT(
symlink(strPtr(link->destination), strPtr(pgPath)) == -1, FileOpenError,
@@ -1073,7 +1074,7 @@ restoreSelectiveExpression(Manifest *manifest)
THROW(FormatError, "no databases found for selective restore\nHINT: is this a valid cluster?");
// Log databases found
- LOG_DETAIL("databases found for selective restore (%s)", strPtr(strLstJoin(dbList, ", ")));
+ LOG_DETAIL_FMT("databases found for selective restore (%s)", strPtr(strLstJoin(dbList, ", ")));
// Remove included databases from the list
const StringList *includeList = strLstNewVarLst(cfgOptionLst(cfgOptDbInclude));
@@ -1141,7 +1142,7 @@ restoreSelectiveExpression(Manifest *manifest)
// If all user databases have been selected then nothing to do
if (expression == NULL)
{
- LOG_INFO("nothing to filter - all user databases have been selected");
+ LOG_INFO_FMT("nothing to filter - all user databases have been selected");
}
// Else return the expression
else
@@ -1340,7 +1341,7 @@ restoreRecoveryWriteConf(const Manifest *manifest, unsigned int pgVersion, const
// Only write recovery.conf if recovery type != none
if (!strEq(cfgOptionStr(cfgOptType), RECOVERY_TYPE_NONE_STR))
{
- LOG_INFO("write %s", strPtr(storagePathP(storagePg(), PG_FILE_RECOVERYCONF_STR)));
+ LOG_INFO_FMT("write %s", strPtr(storagePathP(storagePg(), PG_FILE_RECOVERYCONF_STR)));
// Use the data directory to set permissions and ownership for recovery file
const ManifestPath *dataPath = manifestPathFind(manifest, MANIFEST_TARGET_PGDATA_STR);
@@ -1446,7 +1447,7 @@ restoreRecoveryWriteAutoConf(unsigned int pgVersion, const String *restoreLabel)
strCatFmt(content, "%s", strPtr(restoreRecoveryConf(pgVersion, restoreLabel)));
}
- LOG_INFO(
+ LOG_INFO_FMT(
"write %s%s", autoConf == NULL ? "" : "updated ", strPtr(storagePathP(storagePg(), PG_FILE_POSTGRESQLAUTOCONF_STR)));
// Use the data directory to set permissions and ownership for recovery file
@@ -1503,7 +1504,7 @@ restoreRecoveryWrite(const Manifest *manifest)
if (!storageExistsP(storagePg(), recoveryFile))
{
- LOG_WARN(
+ LOG_WARN_FMT(
"recovery type is " RECOVERY_TYPE_PRESERVE " but recovery file does not exist at '%s'",
strPtr(storagePathP(storagePg(), recoveryFile)));
}
@@ -1899,7 +1900,7 @@ cmdRestore(void)
restoreManifestValidate(jobData.manifest, backupSet);
// Log the backup set to restore
- LOG_INFO("restore backup set %s", strPtr(backupSet));
+ LOG_INFO_FMT("restore backup set %s", strPtr(backupSet));
// Map manifest
restoreManifestMap(jobData.manifest);
@@ -1971,7 +1972,7 @@ cmdRestore(void)
strLstAdd(pathSynced, pgPath);
// Sync the path
- LOG_DETAIL("sync path '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("sync path '%s'", strPtr(pgPath));
storagePathSyncP(storageLocalWrite(), pgPath);
}
}
@@ -1992,7 +1993,7 @@ cmdRestore(void)
const String *pgPath = storagePathP(storagePg(), manifestPathPg(manifestName));
- LOG_DETAIL("sync path '%s'", strPtr(pgPath));
+ LOG_DETAIL_FMT("sync path '%s'", strPtr(pgPath));
storagePathSyncP(storagePgWrite(), pgPath);
}
@@ -2011,7 +2012,7 @@ cmdRestore(void)
LOG_WARN("backup does not contain '" PG_PATH_GLOBAL "/" PG_FILE_PGCONTROL "' -- cluster will not start");
// Sync global path
- LOG_DETAIL("sync path '%s'", strPtr(storagePathP(storagePg(), PG_PATH_GLOBAL_STR)));
+ LOG_DETAIL_FMT("sync path '%s'", strPtr(storagePathP(storagePg(), PG_PATH_GLOBAL_STR)));
storagePathSyncP(storagePgWrite(), PG_PATH_GLOBAL_STR);
}
MEM_CONTEXT_TEMP_END();
diff --git a/src/command/stanza/create.c b/src/command/stanza/create.c
index e8b0113d8..65efb689a 100644
--- a/src/command/stanza/create.c
+++ b/src/command/stanza/create.c
@@ -125,7 +125,7 @@ cmdStanzaCreate(void)
// If no files copied, then the stanza was already valid
if (sourceFile == NULL)
- LOG_INFO("stanza '%s' already exists and is valid", strPtr(cfgOptionStr(cfgOptStanza)));
+ LOG_INFO_FMT("stanza '%s' already exists and is valid", strPtr(cfgOptionStr(cfgOptStanza)));
}
// Else if both .info and corresponding .copy file are missing for one but not the other, then error
else
diff --git a/src/command/stanza/upgrade.c b/src/command/stanza/upgrade.c
index 8301c7b8f..1136f4dc3 100644
--- a/src/command/stanza/upgrade.c
+++ b/src/command/stanza/upgrade.c
@@ -94,7 +94,7 @@ cmdStanzaUpgrade(void)
}
if (!(infoArchiveUpgrade || infoBackupUpgrade))
- LOG_INFO("stanza '%s' is already up to date", strPtr(cfgOptionStr(cfgOptStanza)));
+ LOG_INFO_FMT("stanza '%s' is already up to date", strPtr(cfgOptionStr(cfgOptStanza)));
}
MEM_CONTEXT_TEMP_END();
diff --git a/src/common/debug.h b/src/common/debug.h
index fc44e244d..d8589f8bb 100644
--- a/src/common/debug.h
+++ b/src/common/debug.h
@@ -44,7 +44,7 @@ level is set to debug or trace.
#define FUNCTION_LOG_END_BASE() \
stackTraceTestStart(); \
- LOG(FUNCTION_LOG_LEVEL(), 0, "(%s)", stackTraceParam()); \
+ LOG_FMT(FUNCTION_LOG_LEVEL(), 0, "(%s)", stackTraceParam()); \
}
#else
#define FUNCTION_LOG_BEGIN_BASE(logLevel) \
@@ -55,7 +55,7 @@ level is set to debug or trace.
stackTraceParamLog();
#define FUNCTION_LOG_END_BASE() \
- LOG(FUNCTION_LOG_LEVEL(), 0, "(%s)", stackTraceParam()); \
+ LOG_FMT(FUNCTION_LOG_LEVEL(), 0, "(%s)", stackTraceParam()); \
}
#endif
@@ -236,7 +236,7 @@ Macros to return function results (or void)
char buffer[STACK_TRACE_PARAM_MAX]; \
\
FUNCTION_LOG_##typeMacroPrefix##_FORMAT(FUNCTION_LOG_RETURN_result, buffer, sizeof(buffer)); \
- LOG(FUNCTION_LOG_LEVEL(), 0, "=> %s", buffer); \
+ LOG_FMT(FUNCTION_LOG_LEVEL(), 0, "=> %s", buffer); \
} \
\
return FUNCTION_LOG_RETURN_result; \
diff --git a/src/common/exit.c b/src/common/exit.c
index 9016b3b3a..161f36b80 100644
--- a/src/common/exit.c
+++ b/src/common/exit.c
@@ -115,7 +115,7 @@ exitSafe(int result, bool error, SignalType signalType)
// Assert errors always output a stack trace
if (logLevel == logLevelAssert)
- LOG(logLevel, errorCode(), "%s\nSTACK TRACE:\n%s", errorMessage(), errorStackTrace());
+ LOG_FMT(logLevel, errorCode(), "%s\nSTACK TRACE:\n%s", errorMessage(), errorStackTrace());
else
{
// Log just the error to non-debug levels
@@ -124,7 +124,7 @@ exitSafe(int result, bool error, SignalType signalType)
// Log the stack trace debug levels
if (logAny(logLevelDebug))
{
- LOG_INTERNAL(
+ LOG_INTERNAL_FMT(
logLevel, logLevelDebug, LOG_LEVEL_MAX, 0, errorCode(), "%s\nSTACK TRACE:\n%s", errorMessage(),
errorStackTrace());
}
diff --git a/src/common/io/http/client.c b/src/common/io/http/client.c
index a9415698a..cda39fb56 100644
--- a/src/common/io/http/client.c
+++ b/src/common/io/http/client.c
@@ -435,7 +435,7 @@ httpClientRequest(
// Retry if wait time has not expired
if (wait != NULL && waitMore(wait))
{
- LOG_DEBUG("retry %s: %s", errorTypeName(errorType()), errorMessage());
+ LOG_DEBUG_FMT("retry %s: %s", errorTypeName(errorType()), errorMessage());
retry = true;
httpClientStatLocal.retry++;
diff --git a/src/common/io/tls/client.c b/src/common/io/tls/client.c
index 1f136fd9f..2102d7b87 100644
--- a/src/common/io/tls/client.c
+++ b/src/common/io/tls/client.c
@@ -651,7 +651,7 @@ tlsClientOpen(TlsClient *this)
// Retry if wait time has not expired
if (wait != NULL && waitMore(wait))
{
- LOG_DEBUG("retry %s: %s", errorTypeName(errorType()), errorMessage());
+ LOG_DEBUG_FMT("retry %s: %s", errorTypeName(errorType()), errorMessage());
retry = true;
tlsClientStatLocal.retry++;
diff --git a/src/common/log.c b/src/common/log.c
index cc3de5797..fb4ecca93 100644
--- a/src/common/log.c
+++ b/src/common/log.c
@@ -216,7 +216,8 @@ logFileSet(const char *logFile)
if (logHandleFile == -1)
{
int errNo = errno;
- LOG_WARN("unable to open log file '%s': %s\nNOTE: process will continue without log file.", logFile, strerror(errNo));
+ LOG_WARN_FMT(
+ "unable to open log file '%s': %s\nNOTE: process will continue without log file.", logFile, strerror(errNo));
result = false;
}
@@ -334,35 +335,35 @@ logWriteIndent(int handle, const char *message, size_t indentSize, const char *e
}
/***********************************************************************************************************************************
-General log function
+Generate the log header and anything else that needs to happen before the message is output
***********************************************************************************************************************************/
-void
-logInternal(
- LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, unsigned int processId, const char *fileName,
- const char *functionName, int code, const char *format, ...)
+typedef struct LogPreResult
+{
+ size_t bufferPos;
+ char *logBufferStdErr;
+ size_t indentSize;
+} LogPreResult;
+
+static LogPreResult
+logPre(LogLevel logLevel, unsigned int processId, const char *fileName, const char *functionName, int code)
{
FUNCTION_TEST_BEGIN();
FUNCTION_TEST_PARAM(ENUM, logLevel);
- FUNCTION_TEST_PARAM(ENUM, logRangeMin);
- FUNCTION_TEST_PARAM(ENUM, logRangeMax);
+ FUNCTION_TEST_PARAM(UINT, processId);
FUNCTION_TEST_PARAM(STRINGZ, fileName);
FUNCTION_TEST_PARAM(STRINGZ, functionName);
FUNCTION_TEST_PARAM(INT, code);
- FUNCTION_TEST_PARAM(STRINGZ, format);
FUNCTION_TEST_END();
ASSERT_LOG_LEVEL(logLevel);
- ASSERT_LOG_LEVEL(logRangeMin);
- ASSERT_LOG_LEVEL(logRangeMax);
- ASSERT(logRangeMin <= logRangeMax);
ASSERT(fileName != NULL);
ASSERT(functionName != NULL);
ASSERT(
(code == 0 && logLevel > logLevelError) || (logLevel == logLevelError && code != errorTypeCode(&AssertError)) ||
(logLevel == logLevelAssert && code == errorTypeCode(&AssertError)));
- ASSERT(format != NULL);
- size_t bufferPos = 0; // Current position in the buffer
+ // Initialize buffer position
+ LogPreResult result = {.bufferPos = 0};
// Add time
if (logTimestamp)
@@ -370,24 +371,26 @@ logInternal(
TimeMSec logTimeMSec = timeMSec();
time_t logTimeSec = (time_t)(logTimeMSec / MSEC_PER_SEC);
- bufferPos += strftime(logBuffer + bufferPos, sizeof(logBuffer) - bufferPos, "%Y-%m-%d %H:%M:%S", localtime(&logTimeSec));
- bufferPos += (size_t)snprintf(
- logBuffer + bufferPos, sizeof(logBuffer) - bufferPos, ".%03d ", (int)(logTimeMSec % 1000));
+ result.bufferPos += strftime(
+ logBuffer + result.bufferPos, sizeof(logBuffer) - result.bufferPos, "%Y-%m-%d %H:%M:%S", localtime(&logTimeSec));
+ result.bufferPos += (size_t)snprintf(
+ logBuffer + result.bufferPos, sizeof(logBuffer) - result.bufferPos, ".%03d ", (int)(logTimeMSec % 1000));
}
// Add process and aligned log level
- bufferPos += (size_t)snprintf(
- logBuffer + bufferPos, sizeof(logBuffer) - bufferPos, "P%0*u %*s: ", logProcessSize, processId, 6, logLevelStr(logLevel));
+ result.bufferPos += (size_t)snprintf(
+ logBuffer + result.bufferPos, sizeof(logBuffer) - result.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;
+ result.logBufferStdErr = logBuffer + result.bufferPos - strlen(logLevelStr(logLevel)) - 2;
// Set the indent size -- this will need to be adjusted for stderr
- size_t indentSize = bufferPos;
+ result.indentSize = result.bufferPos;
// Add error code
if (code != 0)
- bufferPos += (size_t)snprintf(logBuffer + bufferPos, sizeof(logBuffer) - bufferPos, "[%03d]: ", code);
+ result.bufferPos += (size_t)snprintf(logBuffer + result.bufferPos, sizeof(logBuffer) - result.bufferPos, "[%03d]: ", code);
// Add debug info
if (logLevel >= logLevelDebug)
@@ -395,33 +398,54 @@ logInternal(
// Adding padding for debug and trace levels
for (unsigned int paddingIdx = 0; paddingIdx < ((logLevel - logLevelDebug + 1) * 4); paddingIdx++)
{
- logBuffer[bufferPos++] = ' ';
- indentSize++;
+ logBuffer[result.bufferPos++] = ' ';
+ result.indentSize++;
}
- bufferPos += (size_t)snprintf(
- logBuffer + bufferPos, LOG_BUFFER_SIZE - bufferPos, "%.*s::%s: ", (int)strlen(fileName) - 2, fileName,
+ result.bufferPos += (size_t)snprintf(
+ logBuffer + result.bufferPos, LOG_BUFFER_SIZE - result.bufferPos, "%.*s::%s: ", (int)strlen(fileName) - 2, fileName,
functionName);
}
- // Format message -- this will need to be indented later
- va_list argumentList;
- va_start(argumentList, format);
- bufferPos += (size_t)vsnprintf(logBuffer + bufferPos, LOG_BUFFER_SIZE - bufferPos, format, argumentList);
- va_end(argumentList);
+ FUNCTION_TEST_RETURN(result);
+}
+
+/***********************************************************************************************************************************
+Finalize formatting and log after the message has been added to the buffer
+***********************************************************************************************************************************/
+static void
+logPost(LogPreResult *logData, LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax)
+{
+ FUNCTION_TEST_BEGIN();
+ FUNCTION_TEST_PARAM(SIZE, logData->bufferPos);
+ FUNCTION_TEST_PARAM(STRINGZ, logData->logBufferStdErr);
+ FUNCTION_TEST_PARAM(SIZE, logData->indentSize);
+ FUNCTION_TEST_PARAM(ENUM, logLevel);
+ FUNCTION_TEST_PARAM(ENUM, logRangeMin);
+ FUNCTION_TEST_PARAM(ENUM, logRangeMax);
+ FUNCTION_TEST_END();
+
+ ASSERT_LOG_LEVEL(logLevel);
+ ASSERT_LOG_LEVEL(logRangeMin);
+ ASSERT_LOG_LEVEL(logRangeMax);
+ ASSERT(logRangeMin <= logRangeMax);
// Add linefeed
- logBuffer[bufferPos++] = '\n';
- logBuffer[bufferPos] = 0;
+ logBuffer[logData->bufferPos++] = '\n';
+ logBuffer[logData->bufferPos] = 0;
// Determine where to log the message based on log-level-stderr
if (logLevel <= logLevelStdErr)
{
if (logRange(logLevelStdErr, logRangeMin, logRangeMax))
- logWriteIndent(logHandleStdErr, logBufferStdErr, indentSize - (size_t)(logBufferStdErr - logBuffer), "log to stderr");
+ {
+ logWriteIndent(
+ logHandleStdErr, logData->logBufferStdErr, logData->indentSize - (size_t)(logData->logBufferStdErr - logBuffer),
+ "log to stderr");
+ }
}
else if (logLevel <= logLevelStdOut && logRange(logLevelStdOut, logRangeMin, logRangeMax))
- logWriteIndent(logHandleStdOut, logBuffer, indentSize, "log to stdout");
+ logWriteIndent(logHandleStdOut, logBuffer, logData->indentSize, "log to stdout");
// Log to file
if (logLevel <= logLevelFile && logHandleFile != -1 && logRange(logLevelFile, logRangeMin, logRangeMax))
@@ -442,8 +466,72 @@ logInternal(
logFileBanner = true;
}
- logWriteIndent(logHandleFile, logBuffer, indentSize, "log to file");
+ logWriteIndent(logHandleFile, logBuffer, logData->indentSize, "log to file");
}
FUNCTION_TEST_RETURN_VOID();
}
+
+/**********************************************************************************************************************************/
+void
+logInternal(
+ LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, unsigned int processId, const char *fileName,
+ const char *functionName, int code, const char *message)
+{
+ FUNCTION_TEST_BEGIN();
+ FUNCTION_TEST_PARAM(ENUM, logLevel);
+ FUNCTION_TEST_PARAM(ENUM, logRangeMin);
+ FUNCTION_TEST_PARAM(ENUM, logRangeMax);
+ FUNCTION_TEST_PARAM(UINT, processId);
+ FUNCTION_TEST_PARAM(STRINGZ, fileName);
+ FUNCTION_TEST_PARAM(STRINGZ, functionName);
+ FUNCTION_TEST_PARAM(INT, code);
+ FUNCTION_TEST_PARAM(STRINGZ, message);
+ FUNCTION_TEST_END();
+
+ ASSERT(message != NULL);
+
+ LogPreResult logData = logPre(logLevel, processId, fileName, functionName, code);
+
+ // Copy message into buffer and update buffer position
+ strncpy(logBuffer + logData.bufferPos, message, sizeof(logBuffer) - logData.bufferPos);
+ logBuffer[sizeof(logBuffer) - 1] = 0;
+ logData.bufferPos += strlen(logBuffer + logData.bufferPos);
+
+ logPost(&logData, logLevel, logRangeMin, logRangeMax);
+
+ FUNCTION_TEST_RETURN_VOID();
+}
+
+/**********************************************************************************************************************************/
+void
+logInternalFmt(
+ 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);
+ FUNCTION_TEST_PARAM(ENUM, logRangeMin);
+ FUNCTION_TEST_PARAM(ENUM, logRangeMax);
+ FUNCTION_TEST_PARAM(UINT, processId);
+ FUNCTION_TEST_PARAM(STRINGZ, fileName);
+ FUNCTION_TEST_PARAM(STRINGZ, functionName);
+ FUNCTION_TEST_PARAM(INT, code);
+ FUNCTION_TEST_PARAM(STRINGZ, format);
+ FUNCTION_TEST_END();
+
+ ASSERT(format != NULL);
+
+ LogPreResult logData = logPre(logLevel, processId, fileName, functionName, code);
+
+ // Format message into buffer and update buffer position
+ va_list argumentList;
+ va_start(argumentList, format);
+ logData.bufferPos += (size_t)vsnprintf(
+ logBuffer + logData.bufferPos, LOG_BUFFER_SIZE - logData.bufferPos, format, argumentList);
+ va_end(argumentList);
+
+ logPost(&logData, logLevel, logRangeMin, logRangeMax);
+
+ FUNCTION_TEST_RETURN_VOID();
+}
diff --git a/src/common/log.h b/src/common/log.h
index ae224f7a6..230ed1278 100644
--- a/src/common/log.h
+++ b/src/common/log.h
@@ -32,14 +32,14 @@ const char *logLevelStr(LogLevel logLevel);
/***********************************************************************************************************************************
Macros
-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.
+Macros only call logInternal()/logInternalFmt() if the message will be logged to one of the available outputs. The 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.
+Note that it's possible that that not all the macros below will appear in the code. In particular the ERROR and ASSERT macros
+should not be used directly. They are included for completeness and future usage.
***********************************************************************************************************************************/
// Define a macro to test logAny() that can be removed when performing coverage testing. Checking logAny() saves a function call
-// for logging calls that won't be output anywhere, but since the macro then contains a branch it causes coverage problems.
+// for logging calls that won't be output anywhere, but since the macro contains a branch it causes coverage problems.
#ifdef DEBUG_COVERAGE
#define IF_LOG_ANY(logLevel)
#else
@@ -47,56 +47,107 @@ usage.
if (logAny(logLevel))
#endif
-#define LOG_INTERNAL(logLevel, logRangeMin, logRangeMax, processId, code, ...) \
+#define LOG_INTERNAL(logLevel, logRangeMin, logRangeMax, processId, code, message) \
do \
{ \
IF_LOG_ANY(logLevel) \
{ \
- logInternal(logLevel, logRangeMin, logRangeMax, processId, __FILE__, __func__, code, __VA_ARGS__); \
+ logInternal(logLevel, logRangeMin, logRangeMax, processId, __FILE__, __func__, code, message); \
} \
} while (0)
-#define LOG_PID(logLevel, processId, code, ...) \
- LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX, processId, code, __VA_ARGS__)
-
-#define LOG_ASSERT_PID(processId, ...) \
- LOG_PID(logLevelAssert, processId, errorTypeCode(&AssertError), __VA_ARGS__)
-#define LOG_ERROR_PID(processId, code, ...) \
- LOG_PID(logLevelError, processId, code, __VA_ARGS__)
-#define LOG_WARN_PID(processId, ...) \
- LOG_PID(logLevelWarn, processId, 0, __VA_ARGS__)
-#define LOG_INFO_PID(processId, ...) \
- LOG_PID(logLevelInfo, processId, 0, __VA_ARGS__)
-#define LOG_DETAIL_PID(processId, ...) \
- LOG_PID(logLevelDetail, processId, 0, __VA_ARGS__)
-#define LOG_DEBUG_PID(processId, ...) \
- LOG_PID(logLevelDebug, processId, 0, __VA_ARGS__)
-#define LOG_TRACE_PID(processId, ...) \
- LOG_PID(logLevelTrace, processId, 0, __VA_ARGS__)
-
-#define LOG(logLevel, code, ...) \
- LOG_PID(logLevel, 0, code, __VA_ARGS__)
-
-#define LOG_ASSERT(...) \
- LOG(logLevelAssert, errorTypeCode(&AssertError), __VA_ARGS__)
-#define LOG_ERROR(code, ...) \
- LOG(logLevelError, code, __VA_ARGS__)
-#define LOG_WARN(...) \
- LOG(logLevelWarn, 0, __VA_ARGS__)
-#define LOG_INFO(...) \
- LOG(logLevelInfo, 0, __VA_ARGS__)
-#define LOG_DETAIL(...) \
- LOG(logLevelDetail, 0, __VA_ARGS__)
-#define LOG_DEBUG(...) \
- LOG(logLevelDebug, 0, __VA_ARGS__)
-#define LOG_TRACE(...) \
- LOG(logLevelTrace, 0, __VA_ARGS__)
+#define LOG_INTERNAL_FMT(logLevel, logRangeMin, logRangeMax, processId, code, ...) \
+do \
+{ \
+ IF_LOG_ANY(logLevel) \
+ { \
+ logInternalFmt(logLevel, logRangeMin, logRangeMax, processId, __FILE__, __func__, code, __VA_ARGS__); \
+ } \
+} while (0)
+
+#define LOG_PID(logLevel, processId, code, message) \
+ LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX, processId, code, message)
+
+#define LOG_ASSERT_PID(processId, message) \
+ LOG_PID(logLevelAssert, processId, errorTypeCode(&AssertError), message)
+#define LOG_ERROR_PID(processId, code, message) \
+ LOG_PID(logLevelError, processId, code, message)
+#define LOG_WARN_PID(processId, message) \
+ LOG_PID(logLevelWarn, processId, 0, message)
+#define LOG_INFO_PID(processId, message) \
+ LOG_PID(logLevelInfo, processId, 0, message)
+#define LOG_DETAIL_PID(processId, message) \
+ LOG_PID(logLevelDetail, processId, 0, message)
+#define LOG_DEBUG_PID(processId, message) \
+ LOG_PID(logLevelDebug, processId, 0, message)
+#define LOG_TRACE_PID(processId, message) \
+ LOG_PID(logLevelTrace, processId, 0, message)
+
+#define LOG_PID_FMT(logLevel, processId, code, ...) \
+ LOG_INTERNAL_FMT(logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX, processId, code, __VA_ARGS__)
+
+#define LOG_ASSERT_PID_FMT(processId, ...) \
+ LOG_PID_FMT(logLevelAssert, processId, errorTypeCode(&AssertError), __VA_ARGS__)
+#define LOG_ERROR_PID_FMT(processId, code, ...) \
+ LOG_PID_FMT(logLevelError, processId, code, __VA_ARGS__)
+#define LOG_WARN_PID_FMT(processId, ...) \
+ LOG_PID_FMT(logLevelWarn, processId, 0, __VA_ARGS__)
+#define LOG_INFO_PID_FMT(processId, ...) \
+ LOG_PID_FMT(logLevelInfo, processId, 0, __VA_ARGS__)
+#define LOG_DETAIL_PID_FMT(processId, ...) \
+ LOG_PID_FMT(logLevelDetail, processId, 0, __VA_ARGS__)
+#define LOG_DEBUG_PID_FMT(processId, ...) \
+ LOG_PID_FMT(logLevelDebug, processId, 0, __VA_ARGS__)
+#define LOG_TRACE_PID_FMT(processId, ...) \
+ LOG_PID_FMT(logLevelTrace, processId, 0, __VA_ARGS__)
+
+#define LOG(logLevel, code, message) \
+ LOG_PID(logLevel, 0, code, message)
+
+#define LOG_ASSERT(message) \
+ LOG(logLevelAssert, errorTypeCode(&AssertError), message)
+#define LOG_ERROR(code, message) \
+ LOG(logLevelError, code, message)
+#define LOG_WARN(message) \
+ LOG(logLevelWarn, 0, message)
+#define LOG_INFO(message) \
+ LOG(logLevelInfo, 0, message)
+#define LOG_DETAIL(message) \
+ LOG(logLevelDetail, 0, message)
+#define LOG_DEBUG(message) \
+ LOG(logLevelDebug, 0, message)
+#define LOG_TRACE(message) \
+ LOG(logLevelTrace, 0, message)
+
+#define LOG_FMT(logLevel, code, ...) \
+ LOG_PID_FMT(logLevel, 0, code, __VA_ARGS__)
+
+#define LOG_ASSERT_FMT(...) \
+ LOG_FMT(logLevelAssert, errorTypeCode(&AssertError), __VA_ARGS__)
+#define LOG_ERROR_FMT(code, ...) \
+ LOG_FMT(logLevelError, code, __VA_ARGS__)
+#define LOG_WARN_FMT(...) \
+ LOG_FMT(logLevelWarn, 0, __VA_ARGS__)
+#define LOG_INFO_FMT(...) \
+ LOG_FMT(logLevelInfo, 0, __VA_ARGS__)
+#define LOG_DETAIL_FMT(...) \
+ LOG_FMT(logLevelDetail, 0, __VA_ARGS__)
+#define LOG_DEBUG_FMT(...) \
+ LOG_FMT(logLevelDebug, 0, __VA_ARGS__)
+#define LOG_TRACE_FMT(...) \
+ LOG_FMT(logLevelTrace, 0, __VA_ARGS__)
/***********************************************************************************************************************************
-Internal Functions
+Internal Functions (in virtually all cases the macros above should be used in preference to these functions)
***********************************************************************************************************************************/
+// Log function
void logInternal(
LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, unsigned int processId, const char *fileName,
- const char *functionName, int code, const char *format, ...);
+ const char *functionName, int code, const char *message);
+
+// Log function with formatting
+void logInternalFmt(
+ LogLevel logLevel, LogLevel logRangeMin, LogLevel logRangeMax, unsigned int processId, const char *fileName,
+ const char *functionName, int code, const char *format, ...) __attribute__((format(printf, 8, 9)));
#endif
diff --git a/src/config/load.c b/src/config/load.c
index 48cc341ea..b9756e504 100644
--- a/src/config/load.c
+++ b/src/config/load.c
@@ -143,7 +143,7 @@ cfgLoadUpdateOption(void)
// If the repo-type is defined, then see if corresponding retention-full is set
if (cfgOptionTest(cfgOptRepoType + optionIdx) && !cfgOptionTest(cfgOptRepoRetentionFull + optionIdx))
{
- LOG_WARN(
+ LOG_WARN_FMT(
"option %s is not set, the repository may run out of space"
"\nHINT: to retain full backups indefinitely (without warning), set option '%s' to the maximum.",
cfgOptionName(cfgOptRepoRetentionFull + optionIdx),
@@ -187,7 +187,7 @@ cfgLoadUpdateOption(void)
}
else
{
- LOG_WARN("%s neither option '%s' nor option '%s' is set", strPtr(msgArchiveOff),
+ LOG_WARN_FMT("%s neither option '%s' nor option '%s' is set", strPtr(msgArchiveOff),
cfgOptionName(cfgOptRepoRetentionArchive + optionIdx),
cfgOptionName(cfgOptRepoRetentionDiff + optionIdx));
}
@@ -196,7 +196,7 @@ cfgLoadUpdateOption(void)
{
CHECK(strEqZ(archiveRetentionType, CFGOPTVAL_TMP_REPO_RETENTION_ARCHIVE_TYPE_INCR));
- LOG_WARN("%s option '%s' is not set", strPtr(msgArchiveOff),
+ LOG_WARN_FMT("%s option '%s' is not set", strPtr(msgArchiveOff),
cfgOptionName(cfgOptRepoRetentionArchive + optionIdx));
}
}
@@ -208,7 +208,7 @@ cfgLoadUpdateOption(void)
if ((strEqZ(archiveRetentionType, CFGOPTVAL_TMP_REPO_RETENTION_ARCHIVE_TYPE_DIFF)) &&
(!cfgOptionTest(cfgOptRepoRetentionDiff + optionIdx)))
{
- LOG_WARN("option '%s' is not set for '%s=%s'\n"
+ LOG_WARN_FMT("option '%s' is not set for '%s=%s'\n"
"HINT: to retain differential backups indefinitely (without warning), set option '%s' to the maximum.",
cfgOptionName(cfgOptRepoRetentionDiff + optionIdx),
cfgOptionName(cfgOptRepoRetentionArchiveType + optionIdx),
diff --git a/src/config/parse.c b/src/config/parse.c
index 8476bfde0..649987589 100644
--- a/src/config/parse.c
+++ b/src/config/parse.c
@@ -646,19 +646,19 @@ configParse(unsigned int argListSize, const char *argList[], bool resetLogLevel)
// Warn if the option not found
if (optionList[optionIdx].name == NULL)
{
- LOG_WARN("environment contains invalid option '%s'", strPtr(key));
+ LOG_WARN_FMT("environment contains invalid option '%s'", strPtr(key));
continue;
}
// Warn if negate option found in env
else if (optionList[optionIdx].val & PARSE_NEGATE_FLAG)
{
- LOG_WARN("environment contains invalid negate option '%s'", strPtr(key));
+ LOG_WARN_FMT("environment contains invalid negate option '%s'", strPtr(key));
continue;
}
// Warn if reset option found in env
else if (optionList[optionIdx].val & PARSE_RESET_FLAG)
{
- LOG_WARN("environment contains invalid reset option '%s'", strPtr(key));
+ LOG_WARN_FMT("environment contains invalid reset option '%s'", strPtr(key));
continue;
}
@@ -749,19 +749,19 @@ configParse(unsigned int argListSize, const char *argList[], bool resetLogLevel)
// Warn if the option not found
if (optionList[optionIdx].name == NULL)
{
- LOG_WARN("configuration file contains invalid option '%s'", strPtr(key));
+ LOG_WARN_FMT("configuration file contains invalid option '%s'", strPtr(key));
continue;
}
// Warn if negate option found in config
else if (optionList[optionIdx].val & PARSE_NEGATE_FLAG)
{
- LOG_WARN("configuration file contains negate option '%s'", strPtr(key));
+ LOG_WARN_FMT("configuration file contains negate option '%s'", strPtr(key));
continue;
}
// Warn if reset option found in config
else if (optionList[optionIdx].val & PARSE_RESET_FLAG)
{
- LOG_WARN("configuration file contains reset option '%s'", strPtr(key));
+ LOG_WARN_FMT("configuration file contains reset option '%s'", strPtr(key));
continue;
}
@@ -771,7 +771,7 @@ configParse(unsigned int argListSize, const char *argList[], bool resetLogLevel)
/// Warn if this option should be command-line only
if (cfgDefOptionSection(optionDefId) == cfgDefSectionCommandLine)
{
- LOG_WARN("configuration file contains command-line only option '%s'", strPtr(key));
+ LOG_WARN_FMT("configuration file contains command-line only option '%s'", strPtr(key));
continue;
}
@@ -794,7 +794,7 @@ configParse(unsigned int argListSize, const char *argList[], bool resetLogLevel)
// Warn if it is in a command section
if (sectionIdx % 2 == 0)
{
- LOG_WARN(
+ LOG_WARN_FMT(
"configuration file contains option '%s' invalid for section '%s'", strPtr(key),
strPtr(section));
continue;
@@ -807,7 +807,7 @@ configParse(unsigned int argListSize, const char *argList[], bool resetLogLevel)
if (cfgDefOptionSection(optionDefId) == cfgDefSectionStanza &&
strBeginsWithZ(section, CFGDEF_SECTION_GLOBAL))
{
- LOG_WARN(
+ LOG_WARN_FMT(
"configuration file contains stanza-only option '%s' in global section '%s'", strPtr(key),
strPtr(section));
continue;
diff --git a/src/db/helper.c b/src/db/helper.c
index 44afd6e03..056f3555f 100644
--- a/src/db/helper.c
+++ b/src/db/helper.c
@@ -89,7 +89,7 @@ dbGet(bool primaryOnly, bool primaryRequired)
}
CATCH_ANY()
{
- LOG_WARN("unable to check pg-%u: [%s] %s", pgIdx + 1, errorTypeName(errorType()), errorMessage());
+ LOG_WARN_FMT("unable to check pg-%u: [%s] %s", pgIdx + 1, errorTypeName(errorType()), errorMessage());
db = NULL;
}
TRY_END();
diff --git a/src/info/infoBackup.c b/src/info/infoBackup.c
index 593cda6c3..93045d454 100644
--- a/src/info/infoBackup.c
+++ b/src/info/infoBackup.c
@@ -673,7 +673,7 @@ infoBackupLoadFileReconstruct(const Storage *storage, const String *fileName, Ci
if (manData->pgId == pgHistory.id && manData->pgSystemId == pgHistory.systemId &&
manData->pgVersion == pgHistory.version)
{
- LOG_WARN("backup '%s' found in repository added to " INFO_BACKUP_FILE, strPtr(backupLabel));
+ LOG_WARN_FMT("backup '%s' found in repository added to " INFO_BACKUP_FILE, strPtr(backupLabel));
infoBackupDataAdd(infoBackup, manifest);
found = true;
break;
@@ -681,7 +681,7 @@ infoBackupLoadFileReconstruct(const Storage *storage, const String *fileName, Ci
}
if (!found)
- LOG_WARN("invalid backup '%s' cannot be added to current backups", strPtr(manData->backupLabel));
+ LOG_WARN_FMT("invalid backup '%s' cannot be added to current backups", strPtr(manData->backupLabel));
}
}
}
@@ -697,7 +697,7 @@ infoBackupLoadFileReconstruct(const Storage *storage, const String *fileName, Ci
// Remove backup from the current list in the infoBackup object
if (!storageExistsP(storage, manifestFileName))
{
- LOG_WARN("backup '%s' missing manifest removed from " INFO_BACKUP_FILE, strPtr(backupLabel));
+ LOG_WARN_FMT("backup '%s' missing manifest removed from " INFO_BACKUP_FILE, strPtr(backupLabel));
infoBackupDataDelete(infoBackup, backupLabel);
}
}
diff --git a/src/storage/s3/storage.c b/src/storage/s3/storage.c
index 446bb6452..4eb925732 100644
--- a/src/storage/s3/storage.c
+++ b/src/storage/s3/storage.c
@@ -306,7 +306,7 @@ storageS3Request(
if (strEq(errorCode, S3_ERROR_REQUEST_TIME_TOO_SKEWED_STR))
{
- LOG_DEBUG(
+ LOG_DEBUG_FMT(
"retry %s: %s", strPtr(errorCode),
strPtr(xmlNodeContent(xmlNodeChild(error, S3_XML_TAG_MESSAGE_STR, true))));
diff --git a/test/src/module/common/logTest.c b/test/src/module/common/logTest.c
index d8ab24d4d..ebfec8147 100644
--- a/test/src/module/common/logTest.c
+++ b/test/src/module/common/logTest.c
@@ -164,7 +164,7 @@ testRun(void)
}
// *****************************************************************************************************************************
- if (testBegin("logInternal()"))
+ if (testBegin("logInternal() and logInternalFmt()"))
{
TEST_RESULT_VOID(logInit(logLevelOff, logLevelOff, logLevelOff, false, 1), "init logging to off");
TEST_RESULT_VOID(
@@ -195,7 +195,7 @@ testRun(void)
logBuffer[0] = 0;
TEST_RESULT_VOID(
- logInternal(logLevelWarn, LOG_LEVEL_MIN, LOG_LEVEL_MAX, 0, "file", "function", 0, "format %d", 99), "log warn");
+ logInternalFmt(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
[parent: 99edcca55b3b]