Add log replacements to help test non-deterministic log output.

Some log output (e.g. time) is hard to test because the values can change between tests.

Add expressions to replace substrings in the log with predictable values to simplify testing.

This is similar to the log replacement facility available for Perl expect log testing.

test/src/common/harnessLog.c

@@ -8,6 +8,9 @@ Log Test Harness
 #include <string.h>
 
 #include "common/log.h"
+#include "common/memContext.h"
+#include "common/regExp.h"
+#include "common/type/stringList.h"
 
 #include "common/harnessDebug.h"
 #include "common/harnessTest.h"
@@ -150,6 +153,169 @@ harnessLogLoad(const char *logFile)
     FUNCTION_HARNESS_RESULT_VOID();
 }
 
+/**********************************************************************************************************************************/
+static struct
+{
+    MemContext *memContext;                                         // Mem context for log harness
+    List *replaceList;                                              // List of replacements
+} harnessLog;
+
+typedef struct HarnessLogReplace
+{
+    const String *expression;
+    RegExp *regExp;
+    const String *expressionSub;
+    RegExp *regExpSub;
+    const String *replacement;
+    StringList *matchList;
+    bool version;
+} HarnessLogReplace;
+
+void
+hrnLogReplaceAdd(const char *expression, const char *expressionSub, const char *replacement, bool version)
+{
+    FUNCTION_HARNESS_BEGIN();
+        FUNCTION_HARNESS_PARAM(STRINGZ, expression);
+        FUNCTION_HARNESS_PARAM(STRINGZ, expressionSub);
+        FUNCTION_HARNESS_PARAM(STRINGZ, replacement);
+        FUNCTION_HARNESS_PARAM(BOOL, version);
+    FUNCTION_HARNESS_END();
+
+    FUNCTION_HARNESS_ASSERT(expression != NULL);
+    FUNCTION_HARNESS_ASSERT(replacement != NULL);
+
+    if (harnessLog.memContext == NULL)
+    {
+        MEM_CONTEXT_BEGIN(memContextTop())
+        {
+            harnessLog.memContext = memContextNew("harnessLog");
+        }
+        MEM_CONTEXT_END();
+    }
+
+    if (harnessLog.replaceList == NULL)
+    {
+        MEM_CONTEXT_BEGIN(harnessLog.memContext)
+        {
+            harnessLog.replaceList = lstNew(sizeof(HarnessLogReplace));
+        }
+        MEM_CONTEXT_END();
+    }
+
+    MEM_CONTEXT_BEGIN(lstMemContext(harnessLog.replaceList))
+    {
+        HarnessLogReplace logReplace =
+        {
+            .expression = strNew(expression),
+            .regExp = regExpNew(STRDEF(expression)),
+            .expressionSub = expressionSub == NULL ? NULL : strNew(expressionSub),
+            .regExpSub = expressionSub == NULL ? NULL : regExpNew(STRDEF(expressionSub)),
+            .replacement = strNew(replacement),
+            .matchList = strLstNew(),
+            .version = version,
+        };
+
+        lstAdd(harnessLog.replaceList, &logReplace);
+    }
+    MEM_CONTEXT_END();
+
+    FUNCTION_HARNESS_RESULT_VOID();
+}
+
+/**********************************************************************************************************************************/
+void
+hrnLogReplaceClear(void)
+{
+    FUNCTION_HARNESS_VOID();
+
+    if (harnessLog.replaceList != NULL)
+        lstClear(harnessLog.replaceList);
+
+    FUNCTION_HARNESS_RESULT_VOID();
+}
+
+/***********************************************************************************************************************************
+Perform log replacements
+***********************************************************************************************************************************/
+static void
+hrnLogReplace(void)
+{
+    FUNCTION_HARNESS_VOID();
+
+    // Proceed only if replacements have been defined
+    if (harnessLog.replaceList != NULL)
+    {
+        MEM_CONTEXT_TEMP_BEGIN()
+        {
+            // Loop through all replacements
+            for (unsigned int replaceIdx = 0; replaceIdx < lstSize(harnessLog.replaceList); replaceIdx++)
+            {
+                HarnessLogReplace *logReplace = lstGet(harnessLog.replaceList, replaceIdx);
+
+                // Check for matches
+                while (regExpMatch(logReplace->regExp, STRDEF(harnessLogBuffer)))
+                {
+                    // Get the match
+                    String *match = regExpMatchStr(logReplace->regExp);
+
+                    // Find beginning of match
+                    char *begin = harnessLogBuffer + (regExpMatchPtr(logReplace->regExp) - harnessLogBuffer);
+
+                    // If there is a sub expression then evaluate it
+                    if (logReplace->regExpSub != NULL)
+                    {
+                        // The sub expression must match
+                        if (!regExpMatch(logReplace->regExpSub, match))
+                        {
+                            THROW_FMT(
+                                AssertError, "unable to find sub expression '%s' in '%s' extracted with expresion '%s'",
+                                strPtr(logReplace->expressionSub), strPtr(match), strPtr(logReplace->expression));
+                        }
+
+                        // Find beginning of match
+                        begin += regExpMatchPtr(logReplace->regExpSub) - strPtr(match);
+
+                        // Get the match
+                        match = regExpMatchStr(logReplace->regExpSub);
+                    }
+
+                    // Build replacement string.  If versioned then append the version number.
+                    String *replace = strNewFmt("[%s", strPtr(logReplace->replacement));
+
+                    if (logReplace->version)
+                    {
+                        unsigned int index = lstFindIdx((List *)logReplace->matchList, &match);
+
+                        if (index == LIST_NOT_FOUND)
+                        {
+                            index = strLstSize(logReplace->matchList);
+                            strLstAdd(logReplace->matchList, match);
+                        }
+
+                        strCatFmt(replace, "-%u", index + 1);
+                    }
+
+                    strCat(replace, "]");
+
+                    // Find end of match and calculate size difference from replacement
+                    char *end = begin + strSize(match);
+                    int diff = (int)strSize(replace) - (int)strSize(match);
+
+                    // Make sure we won't overflow the buffer
+                    CHECK((size_t)((int)strlen(harnessLogBuffer) + diff) < sizeof(harnessLogBuffer) - 1);
+
+                    // Move data from end of string enough to make room for the replacement and copy replacement
+                    memmove(end + diff, end, strlen(end) + 1);
+                    memcpy(begin, strPtr(replace), strSize(replace));
+                }
+            }
+        }
+        MEM_CONTEXT_TEMP_END();
+    }
+
+    FUNCTION_HARNESS_RESULT_VOID();
+}
+
 /***********************************************************************************************************************************
 Compare log to a static string
 
@@ -165,6 +331,7 @@ harnessLogResult(const char *expected)
     FUNCTION_HARNESS_END();
 
     harnessLogLoad(logFile);
+    hrnLogReplace();
 
     expected = hrnReplaceKey(expected);
 
@@ -236,6 +403,7 @@ harnessLogFinal(void)
     FUNCTION_HARNESS_VOID();
 
     harnessLogLoad(logFile);
+    hrnLogReplace();
 
     if (strcmp(harnessLogBuffer, "") != 0)
         THROW_FMT(AssertError, "\n\nexpected log to be empty but actual log was:\n\n%s\n\n", harnessLogBuffer);

test/src/common/harnessLog.h

@@ -4,11 +4,19 @@ Log Test Harness
 #ifndef TEST_COMMON_HARNESSLOG_H
 #define TEST_COMMON_HARNESSLOG_H
 
+#include <stdbool.h>
+
 #include "common/logLevel.h"
 
 /***********************************************************************************************************************************
 Functions
 ***********************************************************************************************************************************/
+// Add log replacement
+void hrnLogReplaceAdd(const char *expression, const char *expressionSub, const char *replacement, bool version);
+
+// Clear (remove) all log replacements
+void hrnLogReplaceClear(void);
+
 void harnessLogResult(const char *expected);
 void harnessLogResultRegExp(const char *expression);
 

test/src/common/harnessTest.c

@@ -171,6 +171,9 @@ testBegin(const char *name)
                 fflush(stderr);
                 exit(255);
             }
+
+            // Clear any log replacements
+            hrnLogReplaceClear();
         }
 #endif
         // No longer the first test

test/src/module/command/commandTest.c

@@ -127,9 +127,10 @@ testRun(void)
         httpClientNew(strNew("BOGUS"), 443, 1000, true, NULL, NULL);
 
         TEST_RESULT_VOID(cmdEnd(0, NULL), "command end with success");
-        harnessLogResultRegExp(
+        hrnLogReplaceAdd("\\([0-9]+ms\\)", "[0-9]+", "TIME", false);
+        TEST_RESULT_LOG(
             "P00   INFO: http statistics: objects 1, sessions 0, requests 0, retries 0, closes 0\n"
-            "P00   INFO\\: archive-get command end: completed successfully \\([0-9]+ms\\)");
+            "P00   INFO: archive-get command end: completed successfully ([TIME]ms)");
     }
 
     FUNCTION_HARNESS_RESULT_VOID();

test/src/module/db/dbTest.c

@@ -270,10 +270,12 @@ testRun(void)
         });
 
         TEST_ASSIGN(result, dbGet(false, true, false), "get primary and standy");
-        harnessLogResultRegExp(
+
-            "P00   WARN: unable to check pg-4: \\[DbConnectError\\] unable to connect to 'dbname='postgres' port=5433': error\n"
+        hrnLogReplaceAdd("No such file or directory.*$", NULL, "NO SUCH FILE OR DIRECTORY", false);
-            "P00   WARN: unable to check pg-5: \\[DbConnectError\\] raised from remote-0 protocol on 'localhost':"
+        TEST_RESULT_LOG(
-                " unable to connect to 'dbname='postgres' port=5432': could not connect to server: No such file or directory.*");
+            "P00   WARN: unable to check pg-4: [DbConnectError] unable to connect to 'dbname='postgres' port=5433': error\n"
+            "P00   WARN: unable to check pg-5: [DbConnectError] raised from remote-0 protocol on 'localhost':"
+                " unable to connect to 'dbname='postgres' port=5432': could not connect to server: [NO SUCH FILE OR DIRECTORY]");
 
         TEST_RESULT_INT(result.primaryId, 8, "    check primary id");
         TEST_RESULT_BOOL(result.primary != NULL, true, "    check primary");