Add more unit tests.

namespaced_logging.nimble

@@ -13,3 +13,8 @@ requires @["nim >= 2.2.0", "zero_functional"]
 
 # from https://git.jdb-software.com/jdb/nim-packages
 requires "timeutils"
+
+task test, "Run unittests for the package.":
+  exec "nimble c src/namespaced_logging.nim src/namespaced_logging/autoconfigured.nim"
+  exec "src/namespaced_logging.out"
+  exec "src/namespaced_logging/autoconfigured"

src/namespaced_logging.nim

@@ -998,14 +998,15 @@ proc resetAutoconfiguredLogging*() =
   autoGls = GlobalLogService()
   initAutoconfiguredLogService()
 
-when isMainModule:
-
-  import std/[tempfiles, unittest]
-  import ./namespaced_logging/testutil
 # -----------------------------------------------------------------------------
 # Tests
 # -----------------------------------------------------------------------------
 
+when isMainModule:
+
+  import std/[files, tempfiles, unittest]
+  import ./namespaced_logging/testutil
+
   suite "GlobalLogService Initialization":
 
     test "initLogService creates valid service":
@@ -1128,8 +1129,7 @@ when isMainModule:
     setup:
       let ls = threadLocalRef(initLogService())
       let loggedMsgs = initLoggedMessages()
-      let testAppender = initTestLogAppender(loggedMsgs)
+      ls.addAppender(initTestLogAppender(loggedMsgs))
-      ls.addAppender(testAppender)
 
     test "getLogger creates logger with correct scope":
       let logger = ls.getLogger("api/users")
@@ -1139,6 +1139,26 @@ when isMainModule:
       let logger = ls.getLogger("api/users", some(lvlWarn))
       check ls.thresholds["api/users"] == lvlWarn
 
+    test "log methods work":
+      let logger = ls.getLogger("test")
+
+      logger.log(lvlDebug, "debug string msg")
+      logger.log(lvlInfo, %*{"message": "info json msg"})
+      logger.log(lvlNotice, "notice string msg")
+      logger.log(lvlError, newException(ValueError, "exception msg"), "error ex. msg")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 4
+        lm[0].level == lvlDebug
+        lm[0].message.contains("debug string msg")
+        lm[1].level == lvlInfo
+        lm[1].message.contains("info json msg")
+        lm[2].level == lvlNotice
+        lm[2].message.contains("notice string msg")
+        lm[3].level == lvlError
+        lm[3].message.contains("error ex. msg")
+
     test "logger convenience methods work":
       let logger = ls.getLogger("test")
 
@@ -1187,8 +1207,7 @@ when isMainModule:
     setup:
       let ls = threadLocalRef(initLogService())
       let loggedMsgs = initLoggedMessages()
-      let testAppender = initTestLogAppender(loggedMsgs)
+      ls.addAppender(initTestLogAppender(loggedMsgs))
-      ls.addAppender(testAppender)
 
     test "root level filtering":
       ls.setRootThreshold(lvlInfo)
@@ -1365,3 +1384,107 @@ when isMainModule:
       let clonedFile = FileLogAppender(cloned)
       check clonedFile.absPath == original.absPath
       check clonedFile.namespace == "test"
+
+  suite "StdLoggingAppender":
+
+    var fileLogger: FileLogger
+    var tempFile: File
+    var tempFilename: string
+
+    setup:
+      let ls = threadLocalRef(initLogService())
+      (tempFile, tempFilename) = createTempFile("stdlog_test", ".tmp.log")
+      fileLogger = newFileLogger(tempFile, flushThreshold = lvlAll)
+      addHandler(fileLogger)
+
+    teardown:
+      removeHandler(fileLogger)
+      try: close(tempFile)
+      except Exception: discard
+      removeFile(tempFilename)
+
+    test "forwards to std logging":
+      ls.addAppender(initStdLoggingAppender())
+      let logger = ls.getLogger("test")
+
+      logger.debug("message at debug")
+      logger.info("message at info")
+      logger.error("message at error")
+
+      tempFile.flushFile()
+      close(tempFile)
+
+      check open(tempFile, tempFilename, fmRead)
+      let lines = toSeq(lines(tempFile))
+      check:
+        lines.len == 3
+        lines[0] == "DEBUG [test] message at debug"
+        lines[1] == "INFO [test] message at info"
+        lines[2] == "ERROR [test] message at error"
+
+    test "fallbackOnly works when on":
+      ls.addAppender(initStdLoggingAppender())
+      let logger = ls.getLogger("test")
+
+      logger.debug("message at debug")
+      logger.info("message at info")
+      logger.error("message at error")
+
+      let loggedMsgs = initLoggedMessages()
+      ls.addAppender(initTestLogAppender(loggedMsgs))
+
+      logger.notice("message at notice")
+      logger.warn("message at warn")
+      logger.fatal("message at fatal")
+
+      tempFile.flushFile()
+      close(tempFile)
+
+      check open(tempFile, tempFilename, fmRead)
+      let lines = toSeq(lines(tempFile))
+      let lm = loggedMsgs.get()
+      check:
+        lines.len == 3
+        lines[0] == "DEBUG [test] message at debug"
+        lines[1] == "INFO [test] message at info"
+        lines[2] == "ERROR [test] message at error"
+
+        lm.len == 3
+        lm[0].message.contains("message at notice")
+        lm[1].message.contains("message at warn")
+        lm[2].message.contains("message at fatal")
+
+    test "fallbackOnly works when off":
+      ls.addAppender(initStdLoggingAppender(fallbackOnly = false))
+      let logger = ls.getLogger("test")
+
+      logger.debug("message at debug")
+      logger.info("message at info")
+      logger.error("message at error")
+
+      let loggedMsgs = initLoggedMessages()
+      ls.addAppender(initTestLogAppender(loggedMsgs))
+
+      logger.notice("message at notice")
+      logger.warn("message at warn")
+      logger.fatal("message at fatal")
+
+      tempFile.flushFile()
+      close(tempFile)
+
+      check open(tempFile, tempFilename, fmRead)
+      let lines = toSeq(lines(tempFile))
+      let lm = loggedMsgs.get()
+      check:
+        lines.len == 6
+        lines[0] == "DEBUG [test] message at debug"
+        lines[1] == "INFO [test] message at info"
+        lines[2] == "ERROR [test] message at error"
+        lines[3] == "NOTICE [test] message at notice"
+        lines[4] == "WARN [test] message at warn"
+        lines[5] == "FATAL [test] message at fatal"
+
+        lm.len == 3
+        lm[0].message.contains("message at notice")
+        lm[1].message.contains("message at warn")
+        lm[2].message.contains("message at fatal")

src/namespaced_logging/autoconfigured.nim

@@ -62,18 +62,159 @@ when isMainModule:
   import std/unittest
   import ./testutil
 
-  suite "Autoconfigured Logging":
+  suite "Automatic Global Setup":
-    setup:
-      globalLogServiceRef[] = initLogService()
-      let loggedMessages = initLoggedMessages()
-      let testAppender = initTestLogAppender(loggedMessages)
 
-    test "simple no-config logging":
+    setup:
-      addLogAppender(testAppender)
+      clearLogAppenders()
+      let loggedMsgs = initLoggedMessages()
+      addLogAppender(initTestLogAppender(loggedMsgs))
+      # note that we are not resetting the global log service reference as the
+      # module default behavior in setting up the global log service reference
+      # is what we want to test
+
+    test "simple logging works":
       info("test message")
 
-      let lm = loggedMessages.get()
+      let lm = loggedMsgs.get()
       check:
         lm.len == 1
         lm[0].level == lvlInfo
         lm[0].message == "test message"
+        lm[0].scope == ""
+
+  suite "Autoconfigured Logging":
+    setup:
+      resetAutoconfiguredLogging()
+      let loggedMsgs = initLoggedMessages()
+      addLogAppender(initTestLogAppender(loggedMsgs))
+
+    test "message construction is avoided if the message is not logged":
+      var expensiveCallCount = 0
+      proc expensiveCall(): int =
+        inc expensiveCallCount
+        return expensiveCallCount
+
+      setRootLoggingThreshold(lvlInfo)
+
+      debug("Expensive call (" & $expensiveCall() & ")")
+      info("Expensive call (" & $expensiveCall() & ")")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 1
+        lm[0].message.contains("Expensive call (1)")
+        expensiveCallCount == 1
+
+    test "thread local variables are cached":
+      # Get the service reference multiple times - should be same instance
+      let svc1 = getAutoconfiguredLogService()
+      let svc2 = getAutoconfiguredLogService()
+      check svc1 == svc2
+
+      # Default logger should also be cached
+      let logger1 = getAutoconfiguredLogger()
+      let logger2 = getAutoconfiguredLogger()
+      check logger1 == logger2
+
+    test "logging with exceptions works":
+      let testException = newException(ValueError, "test error")
+      error(testException, "Something went wrong")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 1
+        lm[0].level == lvlError
+        lm[0].error.isSome
+        lm[0].error.get.msg == "test error"
+
+    test "all convenience methods work":
+      debug("debug message")
+      info("info message")
+      notice("notice message")
+      warn("warn message")
+      error("error message")
+      fatal("fatal message")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 6
+        lm[0].level == lvlDebug
+        lm[1].level == lvlInfo
+        lm[2].level == lvlNotice
+        lm[3].level == lvlWarn
+        lm[4].level == lvlError
+        lm[5].level == lvlFatal
+
+    test "message construction is avoided if the message is not logged":
+      var expensiveCallCount = 0
+      proc expensiveCall(): int =
+        inc expensiveCallCount
+        return expensiveCallCount
+
+      setRootLoggingThreshold(lvlInfo)
+
+      debug("Expensive call (" & $expensiveCall() & ")")
+      info("Expensive call (" & $expensiveCall() & ")")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 1
+        lm[0].message.contains("Expensive call (1)")
+        expensiveCallCount == 1
+
+
+  suite "Global Service Management":
+    setup:
+      resetAutoconfiguredLogging()
+
+    test "useForAutoconfiguredLogging changes global service":
+
+      let origLogs = initLoggedMessages()
+      let newLogs = initLoggedMessages()
+
+      # autoconfiged first
+      addLogAppender(initTestLogAppender(origLogs))
+      let origLogger = getAutoconfiguredLogger()
+      debug("msg 1")
+
+      # Then we setup a custom service that will take over the autoconfig
+      var customLogService = initLogService(lvlWarn)
+      customLogService.addAppender(initTestLogAppender(newLogs))
+      useForAutoconfiguredLogging(customLogService)
+
+      # Subsequent calls to debug, info, etc. should use the new config
+      debug("msg 2 - should be filtered")
+      warn("msg 3 - should appear")
+
+      # Any Loggers that are still around should also get updates
+      origLogger.debug("msg 4 - should be filtered")
+      origLogger.error("msg 5 - should appear")
+
+      let lmOrig = origLogs.get()
+      let lmNew = newLogs.get()
+      check:
+        lmOrig.len == 1
+        lmOrig[0].message == "msg 1"
+        lmNew.len == 2
+        lmNew[0].message == "msg 3 - should appear"
+        lmNew[1].message == "msg 5 - should appear"
+
+    test "configuration changes affect autoconfigured logging":
+      let loggedMsgs = initLoggedMessages()
+      addLogAppender(initTestLogAppender(loggedMsgs))
+
+      # Initially all levels should work
+      debug("debug message")
+
+      # Change root threshold
+      setRootLoggingThreshold(lvlInfo)
+
+      # Debug should now be filtered
+      debug("should be filtered")
+      info("should appear")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 2  # First debug + info
+        lm[0].level == lvlDebug
+        lm[1].level == lvlInfo