Add README examples for autoconfigured use-cases.

Primarily intended for use in libraries or other contexts where you want
to fall back to std/logging if the application is not using or hasn't
configured namespaced_logging.

By default the StdLoggingAppender only logs when no namespaced_logging
appenders are configured, but it can also be configured to always
forward log messages, even when namespaced_logging is configured.

README.md

@@ -136,6 +136,43 @@ proc configureLogging(localLogSvc: ThreadLocalLogService, verbose: bool) =
 # Changes automatically propagate to all threads
 ```
 
+### Autoconfigured Logging in Library Code, Falling Back to `std/logging`
+
+One of the primary uses-cases for the autoconfigured option is for use in
+libraries or other packaged code where the main application may not be using
+or even aware of namespaced\_logging, especially when paired with the
+[*StdLoggingAppender*][#StandingLoggingAppender], which can be configured to
+fallback to std/logging when no appenders have been configured for
+namespaced\_logging.
+
+```nim
+import namespaced_logging/autoconfigured
+
+# Add a StdLoggingAppender to forward logs to std/logging
+addLogAppender(initStdLoggingAppender(fallbackOnly = true))
+
+# will be forwarded to std/logging.debug
+debug("log from library code")
+
+addLogAppender(initConsoleLogAppender())
+
+# will no longer be forwarded to std/logging.debug
+debug("log from library code")
+```
+
+### Providing A Custom Configuration to Replace Autoconfigured Service
+
+```nim
+import namespace_logging
+
+var ls = initLogService()
+ls.addAppender(initConsoleLogAppender())
+
+useForAutoconfiguredLogging(ls)
+
+# from this point on any autoconfigured LogService or Loggers will use the
+# configuration defined by ls
+```
 ## Loggers and Appenders
 
 The logging system is composed of two main components: loggers and appenders.
@@ -225,6 +262,26 @@ by destination file, opens the file with mode `fmAppend`, writes the current
 batch of log messages, and then closes the file handle. Because of this, it has
 no problem if another process moves or truncates any of the target log files.
 
+### StdLoggingAppender
+
+Provides a fallback to [std/logging][std-logging]-based logging. This is
+primarily intended for use in libraries or other contexts where you want to
+fall back to std/logging if the application is not using or hasn't configured
+namespaced\_logging.
+
+By default the *StdLoggingAppender* only logs when no namespaced\_logging
+appenders are configured but it can also be configured to always forward log
+messages regardless of whether namespaced\_logging has other appenders by
+setting `fallbackOnly = false`.
+
+```nim
+func initStdLoggingAppender*(
+    fallbackOnly = true,
+    formatter = formatForwardedLog,
+    namespace = "",
+    threshold = lvlAll): StdLoggingAppender {.gcsafe.}
+```
+
 ### CustomLogAppender
 
 Provides an extension point for custom logging implementations.
@@ -488,6 +545,7 @@ logService.setErrorHandler(silentErrorHandler)
 ### Best Practices
 
 #### Provide Fallbacks
+
 ```nim
 proc robustErrorHandler(err: ref Exception, msg: string) {.gcsafe, nimcall.} =
   # Primary: Send to monitoring system

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

@@ -1,9 +1,10 @@
 import std/[algorithm, atomics, json, locks, options, os, paths, sequtils,
             strutils, tables, times]
 import timeutils
+import std/logging as stdlog
 
-from logging import Level
-export logging.Level
+from std/logging import Level
+export Level
 
 type
   GlobalLogServiceObj {.acyclic.} = object
@@ -21,6 +22,12 @@ type
     errorHandler: ErrorHandlerFunc
     errorHandlerLock: Lock
 
+    takeOverGls: Option[GlobalLogService]
+      # Used to direct ThreadLocalLogServices that they should switch to a new
+      # GlobalLogService (logging root). This is used primarily in the context of
+      # autoconfigured logging where we want to be able to reconfigure the GLS
+      # used for autologging, have existing ThreadLocalLogServices switch over
+      # to the newly provided GLS, and let the old GLS get garbage-collected
 
   GlobalLogService = ref GlobalLogServiceObj
 
@@ -41,7 +48,7 @@ type
   ThreadLocalLogService* = ref LogService
 
 
-  Logger* = object
+  Logger* = ref object
     scope*: string
     threadSvc: ThreadLocalLogService
 
@@ -123,6 +130,55 @@ type
     formatter*: LogMessageFormatter
     absPath*: Path
 
+  StdLoggingAppender* = ref object of LogAppender
+    ## Log appender that forwards log messages to the std/logging
+    ## implementation. This is primarily intended for libraries and other
+    ## situations where you expect that your code will be third-party to others
+    ## and want to respect applications which use std/logging for log handlers
+    ## and configuration.
+
+    fallbackOnly*: bool
+      ## when true, only forward to std/logging where there are no appenders
+      ## configured on the related LogService
+
+    formatter*: LogMessageFormatter
+
+const UninitializedConfigVersion = low(int)
+let JNULL = newJNull()
+
+
+proc initLogMessage*(
+    scope: string,
+    lvl: Level,
+    message: string,
+    error: Option[ref Exception] = none[ref Exception](),
+    additionalData: JsonNode = JNULL): LogMessage =
+
+  LogMessage(
+    scope: scope,
+    level: lvl,
+    error: error,
+    timestamp: now(),
+    message: message,
+    additionalData: additionalData)
+
+
+proc initLogMessage*(
+    scope: string,
+    lvl: Level,
+    msg: JsonNode,
+    error: Option[ref Exception] = none[ref Exception]()): LogMessage =
+
+  LogMessage(
+    scope: scope,
+    level: lvl,
+    error: error,
+    timestamp: now(),
+    message:
+      if msg.hasKey("message"): msg["message"].getStr
+      else: "",
+    additionalData: msg)
+
 
 method clone*(app: LogAppender): LogAppender {.base, gcsafe.} =
   raise newException(CatchableError, "missing concrete implementation")
@@ -197,6 +253,12 @@ proc ensureFreshness*(ls: var LogService) =
 
   if ls.configVersion == ls.global.configVersion.load(): return
 
+  if ls.global.takeOverGls.isSome:
+    let newGls = ls.global.takeOverGls.get
+    assert not newGls.isNil
+    assert newGls.initialized.load
+    ls.global = newGls
+
   withLock ls.global.lock:
     ls.configVersion = ls.global.configVersion.load
 
@@ -210,6 +272,28 @@ proc ensureFreshness*(ls: var LogService) =
 proc ensureFreshness*(ls: ThreadLocalLogService) = ensureFreshness(ls[])
 
 
+proc initGlobalLogService(
+    rootLevel = lvlAll,
+    errorHandler = defaultErrorHandlerFunc): GlobalLogService =
+  result = GlobalLogService()
+  result.configVersion.store(0)
+  initLock(result.lock)
+  initLock(result.errorHandlerLock)
+
+  result.appenders = @[]
+  result.thresholds = newTable[string, Level]()
+  result.rootLevel.store(rootLevel)
+  result.errorHandler = errorHandler
+
+  result.initialized.store(true)
+
+proc initLogService(gls: GlobalLogService): LogService =
+  var lsRef: ThreadLocalLogService = ThreadLocalLogService(
+    configVersion: UninitializedConfigVersion, global: gls)
+  ensureFreshness(lsRef)
+  result = lsRef[]
+
+
 proc initLogService*(
     rootLevel = lvlAll,
     errorHandler = defaultErrorHandlerFunc): LogService =
@@ -227,24 +311,12 @@ proc initLogService*(
   ## configure thresholds, and create loggers. The ref returned by this
   ## procedure should also be retained by the main thread so that garbage
   ## collection does not harvest the global state while it is still in use.
-  let global = GlobalLogService()
-  global.configVersion.store(0)
-  global.initialized.store(true)
-  initLock(global.lock)
-  initLock(global.errorHandlerLock)
-
-  global.appenders = @[]
-  global.thresholds = newTable[string, Level]()
-  global.rootLevel.store(rootLevel)
-  global.errorHandler = errorHandler
-
-  var lsRef: ThreadLocalLogService = ThreadLocalLogService(configVersion: -1, global: global)
-  ensureFreshness(lsRef)
-  result = lsRef[]
+  let global = initGlobalLogService(rootLevel, errorHandler)
+  result = initLogService(global)
 
 
 proc threadLocalRef*(ls: LogService): ThreadLocalLogService =
-  result = new(LogService)
+  new result
   result[] = ls
 
 
@@ -378,6 +450,19 @@ proc addAppender*(ls: ThreadLocalLogService, appender: LogAppender) {.gcsafe.} =
   addAppender(ls[], appender)
 
 
+proc clearAppenders*(ls: var LogService) {.gcsafe.} =
+  ## Remove all log appenders added to the global log service and refresh the
+  ## local thread state. The updated global state will trigger other threads to
+  ## refresh their state as well.
+  withLock ls.global.lock:
+    ls.global.appenders = @[]
+    ls.global.configVersion.atomicInc
+
+
+proc clearAppenders*(ls: ThreadLocalLogService) {.gcsafe.} =
+  clearAppenders(ls[])
+
+
 func getEffectiveThreshold(logger: Logger): Level {.gcsafe.} =
   ## Get the effective logging level threshold for a logger. This is the most
   ## specific level that is set for the logger or any of its parents. The root
@@ -399,89 +484,77 @@ func getEffectiveThreshold(logger: Logger): Level {.gcsafe.} =
     result = logger.threadSvc.thresholds[namespaces[0]]
 
 
-proc doLog(logger: Logger, msg: LogMessage) {.gcsafe.} =
-  ensureFreshness(logger.threadSvc)
+proc isEnabled*(l: Logger, lvl: Level): bool {.inline,gcsafe.} =
+  lvl >= l.getEffectiveThreshold
 
-  if msg.level < logger.getEffectiveThreshold: return
 
+proc sendToAppenders(logger: Logger, msg: LogMessage) {.gcsafe,inline.} =
   for app in logger.threadSvc.appenders:
     if logger.scope.startsWith(app.namespace) and msg.level >= app.threshold:
       app.appendLogMessage(logger.threadSvc, msg)
 
 
-proc log*(l: Logger, lvl: Level, msg: string) {.gcsafe.} =
-  l.doLog(LogMessage(
-    scope: l.scope,
-    level: lvl,
-    error: none[ref Exception](),
-    timestamp: now(),
-    message: msg,
-    additionalData: newJNull()))
+template log*(l: Logger, lm: LogMessage) =
+  ensureFreshness(l.threadSvc)
+
+  if lm.level >= l.getEffectiveThreshold:
+    sendToAppenders(l, lm)
+
+template log*(l: Logger, lvl: Level, msg: untyped) =
+  ensureFreshness(l.threadSvc)
+
+  if lvl >= l.getEffectiveThreshold:
+    sendToAppenders(l, initLogMessage(l.scope, lvl, msg))
 
 
-proc log*(
-    l: Logger,
+template log*[T: ref Exception](l: Logger, lvl: Level, err: T, msg: untyped) =
+  ensureFreshness(l.threadSvc)
+
+  if lvl >= l.getEffectiveThreshold:
+    sendToAppenders(
+      l,
+      initLogMessage(l.scope, lvl, msg, some(cast[ref Exception](err))))
+
+template log*(l: Option[Logger], lm: LogMessage) =
+  if l.isSome: log(l.get, lm)
+
+template log*(l: Option[Logger], lvl: Level, msg: untyped) =
+  if l.isSome: log(l.get, lvl, msg)
+
+template log*(
+    l: Option[Logger],
     lvl: Level,
     error: ref Exception,
-    msg: string ) {.gcsafe.} =
-  l.doLog(LogMessage(
-    scope: l.scope,
-    level: lvl,
-    error: some(error),
-    timestamp: now(),
-    message: msg,
-    additionalData: newJNull()))
-
-
-proc log*(l: Logger, lvl: Level, msg: JsonNode) {.gcsafe.} =
-  l.doLog(LogMessage(
-    scope: l.scope,
-    level: lvl,
-    error: none[ref Exception](),
-    timestamp: now(),
-    message:
-      if msg.hasKey("message"): msg["message"].getStr
-      else: "",
-    additionalData: msg))
-
-
-proc log*(l: Option[Logger], lvl: Level, msg: string) {.gcsafe.} =
-  if l.isSome: log(l.get, lvl, msg)
-
-proc log*(l: Option[Logger], lvl: Level, msg: JsonNode) {.gcsafe.} =
-  if l.isSome: log(l.get, lvl, msg)
-
-proc log*(l: Option[Logger], lvl: Level, error: ref Exception, msg: string) {.gcsafe.} =
+    msg: untyped) =
   if l.isSome: log(l.get, lvl, error, msg)
 
-template debug*[T](l: Logger, msg: T) = log(l, lvlDebug, msg)
-template info*[T](l: Logger, msg: T) = log(l, lvlInfo, msg)
-template notice*[T](l: Logger, msg: T) = log(l, lvlNotice, msg)
-template warn*[T](l: Logger, msg: T) = log(l, lvlWarn, msg)
+template debug*[L: Logger or Option[Logger], M](l: L, msg: M) =
+  log(l, lvlDebug, msg)
 
-template error*[T](l: Logger, msg: T) = log(l, lvlError, msg)
-template error*(l: Logger, error: ref Exception, msg: string) =
+template info*[L: Logger or Option[Logger], M](l: L, msg: M) =
+  log(l, lvlInfo, msg)
+
+template notice*[L: Logger or Option[Logger], M](l: L, msg: M) =
+  log(l, lvlNotice, msg)
+
+template warn*[L: Logger or Option[Logger], M](l: L, msg: M) =
+  log(l, lvlWarn, msg)
+
+template error*[L: Logger or Option[Logger], M](l: L, msg: M) =
+  log(l, lvlError, msg)
+
+template error*[L: Logger or Option[Logger], M](l: L, error: ref Exception, msg: M) =
   log(l, lvlError, error, msg)
 
-template fatal*[T](l: Logger, msg: T) = log(l, lvlFatal, msg)
-template fatal*(l: Logger, error: ref Exception, msg: string) =
+template fatal*[L: Logger or Option[Logger], M](l: L, msg: M) =
+  log(l, lvlFatal, msg)
+
+template fatal*[L: Logger or Option[Logger], M](l: L, error: ref Exception, msg: M) =
   log(l, lvlFatal, error, msg)
 
-template debug*[T](l: Option[Logger], msg: T) = log(l, lvlDebug, msg)
-template info*[T](l: Option[Logger], msg: T) = log(l, lvlInfo, msg)
-template notice*[T](l: Option[Logger], msg: T) = log(l, lvlNotice, msg)
-template warn*[T](l: Option[Logger], msg: T) = log(l, lvlWarn, msg)
-
-template error*[T](l: Option[Logger], msg: T) = log(l, lvlError, msg)
-template error*(l: Option[Logger], error: ref Exception, msg: string) =
-  log(l, lvlError, error, msg)
-
-template fatal*[T](l: Option[Logger], msg: T) = log(l, lvlFatal, msg)
-template fatal*(l: Option[Logger], error: ref Exception, msg: string) =
-  log(l, lvlFatal, error, msg)
 
 # -----------------------------------------------------------------------------
-# CustomerLogAppender Implementation
+# CustomLogAppender Implementation
 # -----------------------------------------------------------------------------
 
 func initCustomLogAppender*[T](
@@ -491,7 +564,7 @@ func initCustomLogAppender*[T](
     threshold = lvlAll): CustomLogAppender[T] {.gcsafe.} =
 
   if doLogMessage.isNil:
-    debugEcho "initCustomLogAppender: doLogMessage is nil"
+    raise newException(ValueError, "initCustomLogAppender: doLogMessage is nil")
 
   result = CustomLogAppender[T](
     namespace: namespace,
@@ -500,8 +573,8 @@ func initCustomLogAppender*[T](
     state: state)
 
 method clone*[T](cla: CustomLogAppender[T]): LogAppender {.gcsafe.} =
-  if cla.doLogMessage.isNil:
-    debugEcho "CustomLogAppender#clone: source doLogMessage is nil"
+  assert not cla.doLogMessage.isNil,
+    "CustomLogAppender#clone: source doLogMessage is nil"
 
   result = CustomLogAppender[T](
     namespace: cla.namespace,
@@ -516,7 +589,7 @@ method appendLogMessage[T](
     msg: LogMessage) {.gcsafe.} =
   try:
     if cla.doLogMessage.isNil:
-      debugEcho "doLogMessage is nil"
+      raise newException(ValueError, "CustomLogAppender.appendLogMessage: doLogMessage is nil")
     else: cla.doLogMessage(cla.state, msg)
   except Exception:
     ls.global.reportLoggingError(
@@ -774,15 +847,166 @@ method appendLogMessage(
       "unable to append to FileLogAppender")
 
 
+# -----------------------------------------------------------------------------
+# StdLoggingAppender Implementation
+# -----------------------------------------------------------------------------
 
-when isMainModule:
+func formatForwardedLog*(lm: LogMessage): string =
+  ## Default formatter for the StdLoggingAppender that prepends the logger
+  ## scope to the message before formatting the message via
+  ## *formatSimpleTextLog*
+  "[" & lm.scope & "] " & formatSimpleTextLog(lm)
+
+
+func initStdLoggingAppender*(
+    fallbackOnly = true,
+    formatter = formatForwardedLog,
+    namespace = "",
+    threshold = lvlAll): StdLoggingAppender {.gcsafe.} =
+
+  result = StdLoggingAppender(
+    namespace: namespace,
+    threshold: threshold,
+    fallbackOnly: fallbackOnly,
+    formatter: formatter)
+
+
+method clone*(sla: StdLoggingAppender): LogAppender {.gcsafe.} =
+  result = StdLoggingAppender(
+    namespace: sla.namespace,
+    threshold: sla.threshold,
+    fallbackOnly: sla.fallbackOnly,
+    formatter: sla.formatter)
+
+
+method appendLogMessage*(
+    sla: StdLoggingAppender,
+    ls: ThreadLocalLogService,
+    msg: LogMessage) {.gcsafe.} =
+
+  if sla.fallbackOnly and ls.appenders.len > 1: return
+
+  stdlog.log(msg.level, sla.formatter(msg))
+
+
+# -----------------------------------------------------------------------------
+# Autoconfiguration Implementation
+# -----------------------------------------------------------------------------
+
+var autoGls = GlobalLogService()
+  # we create the global reference so that it is maintained by the thread that
+  # first imported this module, but leave it uninitialized until
+  # initAutoconfiguredLogService is actually called (when
+  # namespaced_logging/autoconfigured is imported)
+
+var autoTlls {.threadvar.}: ThreadLocalLogService
+var autoLogger {.threadvar.}: Logger
+
+
+proc initAutoconfiguredLogService*() =
+  ## This exists primarily for namespaced_logging/autoconfigured to call as
+  ## part of its setup process. This function needs to live here and be
+  ## exported for the autoconfigured module's visibility as many of the internal
+  ## fields required to properly manage the autoconfigured LogService are not
+  ## exported, to avoid confusion and prevent misuse of the library (from a
+  ## thread-safety POV).
+
+  assert not autoGls.isNil
+
+  let oldGls = autoGls
+  autoGls = initGlobalLogService()
+
+  if oldGls.initialized.load:
+    # If we already have an auto-configured GLS, let's log to the existing GLS
+    # that we're replacing it.
+
+    withLock oldGls.lock:
+      if autoTlls.isNil:
+        # If we somehow have an auto-configured GLS but never instantiated a
+        # thread-local LogService, let's do so temporarily.
+        autoTlls = new(LogService)
+        autoTlls.global = oldGls
+        ensureFreshness(autoTlls)
+
+      warn(
+        getLogger(autoTlls, "namespaced_logging/autoconfigured"),
+        "initializing a new auto-configured logging service, replacing this one")
+
+      oldGls.takeOverGls = some(autoGls)
+      oldGls.configVersion.atomicInc
+
+  autoTlls = threadLocalRef(initLogService(autoGls))
+  autoLogger = autoTlls.getLogger("")
+
+
+proc getAutoconfiguredLogService*(): ThreadLocalLogService =
+  if autoTlls.isNil:
+    if not autoGls.initialized.load():
+      initAutoconfiguredLogService()
+      assert autoGls.initialized.load()
+
+    autoTlls = threadLocalRef(initLogService(autoGls))
+
+  return autoTlls
+
+
+proc getAutoconfiguredLogger*(): Logger =
+  if autoLogger.isNil:
+    autoLogger = getLogger(getAutoconfiguredLogService(), "")
+
+  return autoLogger
+
+
+proc useForAutoconfiguredLogging*(ls: LogService) =
+  # Reconfigure the autoconfigured logging behavior to use the given LogService
+  # configuration instead of the existing autoconfigured configuration. This is
+  # useful in applications that want to control the behavior of third-party
+  # libraries or code that use namespaced_logging/autoconfigured.
+  #
+  # Libraries and other non-application code are suggested to use
+  # namespaced_logging/autoconfigured. The autoconfigured log service has no
+  # appenders when it is initialized which means that applications which are
+  # unaware of namespaced_logging are unaffected and no logs are generated.
+
+  if ls.global == autoGls:
+    # As of Nim 2 `==` on `ref`s performs a referential equality check by
+    # default, and we don't overload `==`. Referential equality is what we're
+    # after here. If the reference in ls already points to the same place as
+    # autoGls, we have nothing to do
+    return
+
+  if autoGls.initialized.load:
+    # if there is an existing autoGls, let's leave instructions for loggers and
+    # LogService instances to move to the newly provided GLS before we change
+    # our autoGls reference.
+    withLock autoGls.lock:
+      autoGls.takeOverGls = some(ls.global)
+      autoGls.configVersion.atomicInc
+
+  autoGls = ls.global
+
+
+proc useForAutoconfiguredLogging*(tlls: ThreadLocalLogService) =
+  useForAutoconfiguredLogging(tlls[])
+
+
+proc resetAutoconfiguredLogging*() =
+  ## Reset the auto-configured logging service. In general it is suggested to
+  # define a new LogService, configure it, and pass it to
+  # *useForAutoconfiguredLogging* instead.  in a way that disconnects it
+  #from
+  autoGls = GlobalLogService()
+  initAutoconfiguredLogService()
 
-  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":
@@ -905,8 +1129,7 @@ when isMainModule:
     setup:
       let ls = threadLocalRef(initLogService())
       let loggedMsgs = initLoggedMessages()
-      let testAppender = initTestLogAppender(loggedMsgs)
-      ls.addAppender(testAppender)
+      ls.addAppender(initTestLogAppender(loggedMsgs))
 
     test "getLogger creates logger with correct scope":
       let logger = ls.getLogger("api/users")
@@ -916,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")
 
@@ -964,8 +1207,7 @@ when isMainModule:
     setup:
       let ls = threadLocalRef(initLogService())
       let loggedMsgs = initLoggedMessages()
-      let testAppender = initTestLogAppender(loggedMsgs)
-      ls.addAppender(testAppender)
+      ls.addAppender(initTestLogAppender(loggedMsgs))
 
     test "root level filtering":
       ls.setRootThreshold(lvlInfo)
@@ -1015,6 +1257,25 @@ when isMainModule:
         lm[0].scope == "api/users/detail"
         lm[0].level == lvlDebug
 
+    test "message construction is avoided if the message is not logged":
+
+      var expensiveCallCount = 0
+      proc expensiveCall(): int =
+        inc expensiveCallCount
+        return expensiveCallCount
+
+      ls.setThreshold("test", lvlInfo)
+      let logger = ls.getLogger("test")
+
+      logger.debug("Expensive call (" & $expensiveCall() & ")")
+      logger.info("Expensive call (" & $expensiveCall() & ")")
+
+      let lm = loggedMsgs.get()
+      check:
+        lm.len == 1
+        lm[0].message.contains("Expensive call (1)")
+        expensiveCallCount == 1
+
   suite "Appender Functionality":
     setup:
       let ls = threadLocalRef(initLogService())
@@ -1113,6 +1374,8 @@ when isMainModule:
         lines.len == 1
         "test message" in lines[0]
 
+      removeFile(pathStr)
+
     test "file appender clone":
       let original = initFileLogAppender("tempfile.log", namespace = "test")
       let cloned = clone(original)
@@ -1121,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

@@ -1,4 +1,4 @@
-import std/[json, options]
+import std/[json, options, strutils]
 from logging import Level
 import ../namespaced_logging
 
@@ -10,7 +10,7 @@ export
   LogMessage,
   ConsoleLogAppender,
   CustomLogAppender,
-  CustomLogAppenderFunction,
+  CustomLogAppenderFunc,
   FileLogAppender,
 
   # Procs/Funcs
@@ -18,81 +18,203 @@ export
   initConsoleLogAppender,
   initCustomLogAppender,
   initFileLogAppender,
-  formatJsonStructuredLog
-
-var globalLogServiceRef: ThreadLocalLogService = new(LogService)
-globalLogServiceRef[] = initLogService()
-
-var threadLocalLogServiceRef {.threadvar.}: ThreadLocalLogService
-var defaultLogger {.threadvar.}: Option[Logger]
-
-
-proc getThreadLocalLogServiceRef(): ThreadLocalLogService {.inline.} =
-  if threadLocalLogServiceRef.isNil:
-    threadLocalLogServiceRef = new(LogService)
-    threadLocalLogServiceRef[] = globalLogServiceRef[]
-
-  return threadLocalLogServiceRef
-
-proc getDefaultLogger(): Logger {.inline.} =
-
-  if defaultLogger.isNone:
-    defaultLogger = some(getThreadLocalLogServiceRef().getLogger(""))
-
-  return defaultLogger.get
-
-
-proc useForAutoconfiguredLogging*(ls: LogService) =
-  globalLogServiceRef[] = ls
+  formatJsonStructuredLog,
+  useForAutoconfiguredLogging
 
 
 proc setRootLoggingThreshold*(lvl: Level) =
-  setRootThreshold(getThreadLocalLogServiceRef(), lvl)
+  setRootThreshold(getAutoconfiguredLogService(), lvl)
 
 
 proc setLoggingThreshold*(scope: string, lvl: Level) =
-  setThreshold(getThreadLocalLogServiceRef(), scope, lvl)
+  setThreshold(getAutoconfiguredLogService(), scope, lvl)
 
 
 proc addLogAppender*(appender: LogAppender) =
-  addAppender(getThreadLocalLogServiceRef(), appender)
+  addAppender(getAutoconfiguredLogService(), appender)
+
+
+proc clearLogAppenders*() =
+  clearAppenders(getAutoconfiguredLogService())
 
 
 proc getLogger*(scope: string, lvl: Option[Level] = none[Level]()): Logger =
-  getLogger(getThreadLocalLogServiceRef(), scope, lvl)
+  getLogger(getAutoconfiguredLogService(), scope, lvl)
 
 
-proc log*(lvl: Level, msg: string) = getDefaultLogger().log(lvl, msg)
-proc log*(lvl: Level, msg: JsonNode) = getDefaultLogger().log(lvl, msg)
+template log*(lm: LogMessage) = log(getAutoconfiguredLogger(), lm)
 
-proc log*(lvl: Level, error: ref Exception, msg: string) =
-  getDefaultLogger().log(lvl, error, msg)
+template log*(lvl: Level, msg: untyped) = log(getAutoconfiguredLogger(), lvl, msg)
+
+template log*[T: ref Exception](lvl: Level, error: T, msg: untyped) =
+  log(getAutoconfiguredLogger(), lvl, error, msg)
 
 template debug*[T](msg: T) = log(lvlDebug, msg)
 template info*[T](msg: T) = log(lvlInfo, msg)
 template notice*[T](msg: T) = log(lvlNotice, msg)
 template warn*[T](msg: T) = log(lvlWarn, msg)
 template error*[T](msg: T) = log(lvlError, msg)
-template error*(error: ref Exception, msg: string) = log(lvlError, error, msg)
+template error*[T](error: ref Exception, msg: T) = log(lvlError, error, msg)
 template fatal*[T](msg: T) = log(lvlFatal, msg)
-template fatal*(error: ref Exception, msg: string) = log(lvlFatal, error, msg)
+template fatal*[T](error: ref Exception, msg: T) = log(lvlFatal, error, msg)
 
 when isMainModule:
   import std/unittest
   import ./testutil
 
-  suite "Autoconfigured Logging":
-    setup:
-      globalLogServiceRef[] = initLogService()
-      let loggedMessages = initLoggedMessages()
-      let testAppender = initTestLogAppender(loggedMessages)
+  suite "Automatic Global Setup":
 
-    test "simple no-config logging":
-      addLogAppender(testAppender)
+    setup:
+      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