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_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_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_PID(logLevel, processId, code, message) \ + LOG_INTERNAL(logLevel, LOG_LEVEL_MIN, LOG_LEVEL_MAX, processId, code, message) -#define LOG(logLevel, code, ...) \ - LOG_PID(logLevel, 0, code, __VA_ARGS__) +#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_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_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