Major refactor to better support multi-threading.

See README for details.

.gitignore

@@ -1,2 +1,3 @@
 .*.sw?
 nimcache/
+tests/tests

README.md

@@ -0,0 +1,182 @@
+# Namespaced Logging for Nim
+
+`namespaced_logging` provides a logging framework similar to [log4j][] or
+[logback][] for Nim. It has three main motivating features:
+- Hierarchical, namespaced logging
+- Safe and straightforward to use in multi-threaded applications.
+- Native support for structured logging (old-style string logging is also
+  supported).
+
+## Getting Started
+
+Install the package from nimble:
+
+```bash
+nimble install namespaced_logging
+```
+
+Then, in your application, you can use the logging system like so:
+
+```nim
+import namespaced_logging
+
+# On the main thread
+let logService = initLogService()
+logService.addAppender(initConsoleAppender(LogLevel.INFO))
+
+# On any thread, including the main thread
+let logger = logService.getLogger("app/service/example")
+logger.info("Log from the example service")
+
+# Only get logs at the WARN or higher level from the database module
+let logger = logService.getLogger("app/database", threshold = some(Level.lvlWarn))
+logger.error("Database connection failed")
+```
+
+## Loggers and Appenders
+
+The logging system is composed of two main components: loggers and appenders.
+Loggers are used to create log events, which are then passed to the appenders.
+Appenders take log events and write them to some destination, such as the
+console, a file, or a network socket. Appenders also have a logging level
+threshold, which determines which log events are acted upon by the appender,
+and, optionally, a namespace filter, which determines from which loggers the
+appender accepts log events.
+
+### Heirarchical Logging and Namespaces
+
+Loggers are organized hierarchically, with the hierarchy defined by the logger
+name. A logger with the name `app/service/example` is a child of the logger
+with the name `app/service`. By default, appenders accept log events from all
+loggers, but this can be restricted by setting a namespace filter on the
+appender. An appender with a namespace set will accept log events from all
+loggers with names that start with the namespace. For example, an appender with
+the namespace `app` will accept log events from the loggers `app`,
+`app/service`, and `app/service/example`, but not from `api/service`.
+
+The other impact of the logger heirarchy is in the effective logging level of
+the logger. Any logger can have an explicit logging level set, but if it does
+not, the effective logging level is inherited from ancestor loggers upwards in
+the logger heirarchy. This pattern is explained in detail in the [logback
+documentation][effective logging level] and applies in the same manner to
+loggers in this library.
+
+
+## Notes on Use in Multi-Threaded Applications
+
+The loggers and appenders in this library are thread-safe and behaves more
+intuitively in a multi-threaded environment than `std/logging`, particularly in
+environments where the logging setup code may be separated from the
+thread-management code (in an HTTP server, for example).
+
+The *LogService* object is the main entry point for the logging system and
+should be initialized on the main thread. The *LogService* contains the "source
+of truth" for logging configuration and is shared between all threads.
+Internally all access to the *LogService* is protected by a mutex.
+
+Logging can be very noisy and if the *LogService* needed to be consulted for
+every log event, it could easily become a performance bottleneck. To avoid
+this, the *getLogger* procedure makes a thread-local copy of the logging system
+configuration (loggers defined and appenders attached).
+
+**Note** that this means that the thread-local cache of the logging system
+configuration can become stale if the logging system configuration is changed
+after the thread-local copy is made (if another appender is added, for
+example). This is a trade-off to avoid the performance penalty of consulting
+the *LogService* for every log event.
+
+This thread-local caching mechanism is the primary advantage of this logging
+system over `std/logging` in a multi-threaded environment as it means that
+the logging system itself is responsible for making sure appenders are
+configured for every thread where loggers are used, even if the thread
+initialization context is separated from the logging setup code.
+
+If you find yourself needing to change the logging configuration after the
+logging system has been initialized, the *reloadThreadState* procedure can be
+used to update the thread-local cache of the logging system configuration, but
+it must be called on the thread you wish to update.
+
+As a final note, the advice to initialize the *LogService* on the main thread
+is primarily to simplify the configuration of the logging service and avoid the
+need to manually reload caches on individual threads. A *LogService* reference
+is required to call *getLogger*, but it can be created on any thread.
+
+## Custom Appender Implementations
+
+Due to the thread-safety of the logging system, there are a few additional
+considerations when implementing custom appenders. The *LogAppender* abstract
+class is the base class for all appenders. To implement a custom appender, two
+methods must be implemented:
+
+### `appendLogMessage`
+
+```nim
+method appendLogMessage*(appender: CustomLogAppender, msg: LogMessage): void {.base, gcsafe.}
+```
+
+This is the primary appender implementation that takes a LogMessage and
+writes it to the appender's destination. As the signature suggests, the
+implementation must be GC-safe. As a multi-method, the *CustomLogAppender* type
+should be replaced by the actual name of your custom appender.
+
+Because the *LogAppender* uses multi-methods for dynamic dispatch, the
+custom appender class must also be a `ref` type.
+
+### `initThreadCopy`
+
+```nim
+method initThreadCopy*(app: LogAppender): LogAppender {.base, gcsafe.}
+```
+
+This method is used to create a thread-local copy of the appender. It is called
+by the *reloadThreadState* procedure to update the thread-local cache of the
+logging system configuration. The implementation will be passed the appender
+instance that was provided to the *addAppender* procedure and must return a
+thread-local copy of that appender.
+
+The `initThreadCopy` implementations for the built-in *ConsoleLogAppender* and
+*FileLogAppender* provide simple examples of how to implement this method by
+simply copying state into the local thread, but this method can also be used
+to perform any other thread-specific initialization that may be required for
+the appender implementation.
+
+### Example Custom Appender
+
+The following defines a simple custom appender that writes log messages to a
+database table. It uses the [waterpark][] connection pooling library to manage
+database connections as waterpark is also thread-safe and makes implementation
+straight-forward.
+
+```nim
+import db_connectors/db_postgres
+import namespaced_logging, waterpark, waterpark/db_postgres
+
+type DbLogAppender = ref object of LogAppender
+  dbPool: PostgresPool
+
+let dbPool: PostgresPool = newPostgresPool(10, "", "", "", connectionString)
+
+method initThreadCopy*(app: LogAppender): LogAppender =
+  result = DbLogAppender(dbPool: dbPool) # copy semantics as PostgresPool is an object
+
+method appendLogMessage*(appender: DbLogAppender, msg: LogMessage): void {gcsafe.} =
+  appender.withConnection conn:
+    conn.insert(
+      "INSERT INTO log_events " &
+      "  (level, scope, message, error, timestamp, custom_fields) " &
+      "VALUES " &
+      "  (?, ?, ?, ?, ?, ?)",
+      msg.level,
+      msg.scope,
+      msg.message,
+      if msg.error.isSome: msg.error.msg
+      else: "",
+      msg.timestamp,
+      msg.additionalData)
+```
+
+
+
+[log4j]: https://logging.apache.org/log4j/2.x/
+[logback]: https://logback.qos.ch/
+[effective logging level]: https://logback.qos.ch/manual/architecture.html#effectiveLevel

namespaced_logging.nimble

@@ -1,6 +1,6 @@
 # Package
 
-version       = "0.3.2"
+version       = "1.0.0"
 author        = "Jonathan Bernard"
 description   = "Wrapper around std/logging to provide namespaced logging."
 license       = "MIT"
@@ -9,4 +9,7 @@ srcDir        = "src"
 
 # Dependencies
 
-requires "nim >= 1.0.4"
+requires @["nim >= 2.2.0", "zero_functional"]
+
+# from https://git.jdb-software.com/jdb/nim-packages
+requires "timeutils"

src/namespaced_logging.nim

@@ -1,76 +1,306 @@
-import std/[logging, options, sequtils, strutils, tables]
+import std/[algorithm, json, locks, options, sequtils, strutils, tables, times]
+import timeutils, zero_functional
 
-export logging
+from logging import Level
+export logging.Level
 
 type
-  LoggingNamespace* = ref object
+  LogService* = ptr LogServiceObj
-    name: string
+    ## Shareable pointer to the shared log service object.
+
+  LogServiceObj = object
+    cfg*: LogServiceConfig
+    lock: Lock
+
+  LogServiceConfig* = object
+    loggers*: seq[LoggerConfig]
+    appenders: seq[LogAppender]
+    rootLevel*: Level
+
+  ThreadState = object
+    cfg: LogServiceConfig
+    loggers: TableRef[string, Logger]
+
+  LoggerConfig* = object of RootObj
+    name*: string
+    threshold*: Option[Level]
+
+  Logger* = object of LoggerConfig
+    svc: LogService
+
+  LogAppender* = ref object of RootObj
+    ## Base type for log appenders.
+    namespace*: string
+    threshold*: Level
+
+  LogMessage* = object
+    scope*: string
     level*: Level
-    msgPrefix*: string
+    error*: Option[ref Exception]
+    timestamp*: DateTime
+    message*: string
+    additionalData*: JsonNode
 
-var knownNamespacesInst {.threadvar.}: TableRef[string, LoggingNamespace]
+  ConsoleLogAppender* = ref object of LogAppender
+    ## Log appender that writes log messages to the console. See
+    ## *initConsoleLogAppender* for a convenient way to create instances of
+    ## this appender.
+    formatter*: proc (msg: LogMessage): string {.gcsafe.}
+      ## Formatter allows for custom formatting of log messages. The default
+      ## formatter uses `formatJsonStructuredLog` to format log messages as
+      ## JSON objects which are then stringified before being written to the
+      ## console.
+    useStderr*: bool
 
-template knownNamespaces(): TableRef[string, LoggingNamespace] =
+  #[
-  if knownNamespacesInst == nil:
+  # TODO: need to think throudh thread-safe IO for file logging
-    knownNamespacesInst = newTable[string, LoggingNamespace]()
+  FileLogAppender* = ref object of LogAppender
-  knownNamespacesInst
+    file*: File
+    formatter*: proc (msg: LogMessage): string {.gcsafe.}
+  ]#
 
-proc initLoggingNamespace(
+
+var threadState {.threadvar.}: ThreadState
+
+
+method initThreadCopy*(app: LogAppender): LogAppender {.base, gcsafe.} =
+  raise newException(CatchableError, "missing concrete implementation")
+
+
+method initThreadCopy*(cla: ConsoleLogAppender): LogAppender {.gcsafe.} =
+  result = ConsoleLogAppender(
+    namespace: cla.namespace,
+    threshold: cla.threshold,
+    formatter: cla.formatter,
+    useStderr: cla.useStdErr)
+
+
+#[
+method initThreadCopy*(fla: FileLogAppender): LogAppender {.gcsafe.} =
+  result = FileLogAppender(
+    namespace: fla.namespace,
+    threshold: fla.threshold,
+    formatter: fla.formatter,
+    file: fla.file)
+]#
+
+
+func initLogger(svc: LogService, cfg: LoggerConfig): Logger =
+  result = Logger(name: cfg.name, threshold: cfg.threshold, svc: svc)
+
+
+proc copyAppenders[T](s: seq[T]): seq[T] {.gcsafe.} =
+  for app in s:
+    result.add(initThreadCopy(app))
+
+
+proc reloadThreadState*(ls: LogService) {.gcsafe.} =
+  ## Refresh this thread's copy of the log service configuration. Note that
+  ## this currently loses any loggers defined on this thread since it was last
+  ## reloaded.
+  acquire(ls.lock)
+  # TODO: push loggers defined on this thread to the shared state?
+  threadState.cfg = ls.cfg
+  threadState.cfg.appenders = copyAppenders(ls.cfg.appenders)
+  release(ls.lock)
+
+  let loggers = threadState.cfg.loggers --> map(initLogger(ls, it))
+  threadState.loggers = newTable(loggers --> map((it.name, it)))
+
+
+proc getThreadState(ls: LogService): ThreadState =
+  if threadState.loggers.isNil: reloadThreadState(ls)
+  return threadState
+
+
+func fmtLevel(lvl: Level): string {.gcsafe.} =
+  case lvl
+  of lvlDebug: return "DEBUG"
+  of lvlInfo: return "INFO"
+  of lvlNotice: return "NOTICE"
+  of lvlWarn: return "WARN"
+  of lvlError: return "ERROR"
+  of lvlFatal: return "FATAL"
+  else: return "UNKNOWN"
+
+
+func `%`*(msg: LogMessage): JsonNode =
+  result = %*{
+    "scope": msg.scope,
+    "level": fmtLevel(msg.level),
+    "msg": msg.message,
+    "ts": msg.timestamp.formatIso8601
+  }
+
+  if msg.error.isSome:
+    result["err"] = %($msg.error.get.name & ": " & msg.error.get.msg)
+    result["stacktrace"] = %($msg.error.get.trace)
+
+  if msg.additionalData.kind == JObject:
+    for (k, v) in pairs(msg.additionalData):
+      if not result.hasKey(k): result[k] = v
+
+
+proc initLogService*(rootLevel = lvlAll): LogService =
+  result = cast[LogService](allocShared0(sizeof(LogServiceObj)))
+  result.cfg.rootLevel = rootLevel
+
+
+proc setRootLevel*(ls: LogService, lvl: Level) =
+  ls.cfg.rootLevel = lvl
+
+
+func formatJsonStructuredLog*(msg: LogMessage): string {.gcsafe.} = return $(%msg)
+
+
+func initConsoleLogAppender*(
+    namespace = "",
+    threshold = lvlInfo,
+    formatter = formatJsonStructuredLog,
+    useStderr = false): ConsoleLogAppender {.gcsafe.} =
+  result = ConsoleLogAppender(
+    namespace: namespace,
+    threshold: threshold,
+    formatter: formatter,
+    useStderr: useStdErr)
+
+
+method appendLogMessage*(appender: LogAppender, msg: LogMessage): void {.base, gcsafe.} =
+  raise newException(CatchableError, "missing concrete implementation")
+
+
+method appendLogMessage*(cla: ConsoleLogAppender, msg: LogMessage): void {.gcsafe.} =
+  if msg.level < cla.threshold: return
+
+  let strMsg = formatJsonStructuredLog(msg)
+  if cla.useStderr:
+    stderr.writeLine(strMsg)
+    stderr.flushFile()
+  else:
+    stdout.writeLine(strMsg)
+    stdout.flushFile()
+
+
+proc getLogger*(
+    ls: LogService,
     name: string,
-    level = lvlInfo,
+    threshold = none[Level]()): Logger {.gcsafe.} =
-    msgPrefix: string
-  ): LoggingNamespace {.raises: [].} =
 
-  result = LoggingNamespace(
+  let ts = getThreadState(ls)
-    name: name,
+  if not ts.loggers.contains(name):
-    level: level,
+    ts.loggers[name] = Logger(name: name, threshold: threshold, svc: ls)
-    msgPrefix: msgPrefix)
+  return ts.loggers[name]
 
-  knownNamespaces[name] = result
 
-proc getLoggerForNamespace*(
+proc getLogger*(
-    namespace: string,
+    ls: Option[LogService],
-    level = lvlInfo,
+    name: string,
-    msgPrefix: Option[string] = none[string]()
+    threshold = none[Level]()): Option[Logger] {.gcsafe.} =
-  ): LoggingNamespace {.raises: [].} =
-  ## Get a LogginNamesapce for the given namespace. The first time this is
-  ## called for a given name space a new logger will be created. In that case,
-  ## the optional `level` and `msgPrefix` will be used to configure the logger.
-  ## In all other cases, these paratmers are ignored and the existing namespace
-  ## instance is returned
 
-  if knownNamespaces.hasKey(namespace):
+  if ls.isNone: return none[Logger]()
-    try: return knownNamespaces[namespace]
+  else: return some(getLogger(ls.get, name, threshold))
-    except KeyError:
-      try: error "namespaced_logging: Impossible error. " &
-        "knownNamespaces contains " & namespace & " but raised a KeyError " &
-        "trying to access it."
-      except: discard
-  else:
-    if msgPrefix.isSome:
-      return initLoggingNamespace(namespace, level, msgPrefix.get)
-    else:
-      return initLoggingNamespace(namespace, level, namespace & ": ")
 
-proc setLevelForNamespace*(namespace: string, lvl: Level, recursive = false) {.raises: [] .} =
-  if recursive:
-    for k, v in knownNamespaces.pairs:
-      if k.startsWith(namespace):
-        v.level = lvl
-  else: getLoggerForNamespace(namespace).level = lvl
 
-proc name*(ns: LoggingNamespace): string = ns.name
+proc addAppender*(ls: LogService, appender: LogAppender) {.gcsafe.} =
-proc log*(ns: LoggingNamespace, level: Level, args: varargs[string, `$`]) {.raises: [] .} =
+  acquire(ls.lock)
-  try:
+  ls.cfg.appenders.add(appender)
-    if level >= ns.level:
+  release(ls.lock)
-      if not ns.msgPrefix.isEmptyOrWhitespace:
-        log(level, args.mapIt(ns.msgPrefix & it))
-      else: log(level, args)
-  except: discard
 
-proc debug*(ns: LoggingNamespace, args: varargs[string, `$`]) = log(ns, lvlDebug, args)
+
-proc info*(ns: LoggingNamespace, args: varargs[string, `$`]) = log(ns, lvlInfo, args)
+func `<`(a, b: LoggerConfig): bool = a.name < b.name
-proc notice*(ns: LoggingNamespace, args: varargs[string, `$`]) = log(ns, lvlNotice, args)
+
-proc warn*(ns: LoggingNamespace, args: varargs[string, `$`]) = log(ns, lvlWarn, args)
+
-proc error*(ns: LoggingNamespace, args: varargs[string, `$`]) = log(ns, lvlError, args)
+func getEffectiveLevel(ts: ThreadState, name: string): Level {.gcsafe.} =
-proc fatal*(ns: LoggingNamespace, args: varargs[string, `$`]) = log(ns, lvlFatal, args)
+  result = ts.cfg.rootLevel
+
+  var namespaces = toSeq(values(ts.loggers))
+  namespaces = sorted(
+    namespaces --> filter(name.startsWith(it.name)),
+    SortOrder.Descending)
+
+  for n in namespaces:
+    if n.threshold.isSome:
+      result = n.threshold.get
+
+proc doLog(logger: Logger, msg: LogMessage): void {.gcsafe.} =
+  let ts = getThreadState(logger.svc)
+  let threshold =
+    if logger.threshold.isSome: logger.threshold.get
+    else: getEffectiveLevel(ts, logger.name)
+
+  if msg.level < threshold: return
+
+  for app in ts.cfg.appenders:
+    if logger.name.startsWith(app.namespace):
+      appendLogMessage(app, msg)
+
+
+proc log*(l: Logger, lvl: Level, msg: string) {.gcsafe.} =
+  l.doLog(LogMessage(
+    scope: l.name,
+    level: lvl,
+    error: none[ref Exception](),
+    timestamp: now(),
+    message: msg,
+    additionalData: newJNull()))
+
+
+proc log*(
+    l: Logger,
+    lvl: Level,
+    error: ref Exception,
+    msg: string ) {.gcsafe.} =
+  l.doLog(LogMessage(
+    scope: l.name,
+    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.name,
+    level: lvl,
+    error: none[ref Exception](),
+    timestamp: now(),
+    message:
+      if msg.hasKey("msg"): msg["msg"].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.} =
+  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 error*[T](l: Logger, msg: T) = log(l, lvlError, msg)
+template error*(l: Logger, error: ref Exception, msg: string) =
+  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) =
+  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)

tests/config.nims

@@ -0,0 +1 @@
+--path:"../src"

tests/tests.nim

@@ -0,0 +1,303 @@
+import std/[json, locks, options, strutils, unittest]
+import namespaced_logging, zero_functional
+
+
+type
+  TestLogAppender = ref object of LogAppender
+    statePtr: ptr TestLogState
+
+  TestLogState = object
+    logs: seq[(string, LogMessage)]
+    lock: Lock
+
+var sharedTestLogState: ptr TestLogState
+
+proc initSharedTestLogState() =
+  sharedTestLogState = cast[ptr TestLogState](allocShared0(sizeof(TestLogState)))
+  sharedTestLogState.logs = @[]
+
+method appendLogMessage*(tla: TestLogAppender, msg: LogMessage): void {.gcsafe.} =
+  if msg.level < tla.threshold: return
+  acquire(sharedTestLogState.lock)
+  sharedTestLogState.logs.add((tla.namespace, msg))
+  release(sharedTestLogState.lock)
+
+method initThreadCopy*(tla: TestLogAppender): LogAppender {.gcsafe.} =
+  TestLogAppender(
+    namespace: tla.namespace,
+    threshold: tla.threshold,
+    statePtr: tla.statePtr)
+
+proc initTestLogAppender(namespace = "", threshold = lvlAll): TestLogAppender =
+  TestLogAppender(
+    namespace: namespace,
+    threshold: threshold,
+    statePtr: sharedTestLogState)
+
+initSharedTestLogState()
+
+suite "initialization":
+
+  test "can create LogService":
+    let logSvc = initLogService()
+    check:
+      not logSvc.isNil
+
+  test "reloadThreadState":
+    let logSvc = initLogService()
+    reloadThreadState(logSvc)
+
+
+  test "create Logger":
+    let logSvc = initLogService()
+    let logger = logSvc.getLogger("test")
+
+    check:
+      logger.threshold.isNone
+      logger.name == "test"
+
+  test "create Logger with threshold":
+    let logSvc = initLogService()
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test", some(lvlDebug))
+
+    check:
+      logger.threshold.isSome
+      logger.threshold.get == lvlDebug
+      logger.name == "test"
+
+  test "initConsoleLogAppender":
+    let cla = initConsoleLogAppender()
+
+suite "log methods":
+
+  test "log with ConsoleLogAppender":
+    let logSvc = initLogService()
+    let cla = initConsoleLogAppender(threshold = lvlDebug)
+    let tla = initTestLogAppender()
+    logSvc.addAppender(cla)
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test")
+    logger.info("Test log message.")
+
+    acquire(sharedTestLogState.lock)
+    check sharedTestLogState.logs.len == 1
+    let log = sharedTestLogState.logs[0][1]
+    check:
+      log.message == "Test log message."
+      log.level == lvlInfo
+      log.scope == "test"
+      log.error.isNone
+      log.additionalData.kind == JNull
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "log with error":
+    let logSvc = initLogService()
+    let tla = initTestLogAppender()
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test")
+    logger.error(newException(Exception, "Test error message."), "exception occurred")
+
+    acquire(sharedTestLogState.lock)
+    check sharedTestLogState.logs.len == 1
+    let log = sharedTestLogState.logs[0][1]
+    check:
+      log.message == "exception occurred"
+      log.level == lvlError
+      log.scope == "test"
+      log.error.isSome
+      log.error.get.name == "Exception"
+      log.error.get.msg == "Test error message."
+      log.additionalData.kind == JNull
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+suite "namespaces":
+
+  test "appenders at the root level accept all messages":
+    let logSvc = initLogService()
+    let tla = initTestLogAppender()
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let l1 = logSvc.getLogger("")
+    let l2 = logSvc.getLogger("test")
+    let l3 = logSvc.getLogger("test/sub")
+
+    l1.info("message from root")
+    l2.info("message from test")
+    l3.info("message from test/sub")
+
+    acquire(sharedTestLogState.lock)
+    let logs = sharedTestLogState.logs
+    check:
+      logs.len == 3
+      logs[0][1].message == "message from root"
+      logs[1][1].message == "message from test"
+      logs[2][1].message == "message from test/sub"
+
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "appenders accept messages at their namespace":
+    let logSvc = initLogService()
+    let tla = initTestLogAppender(namespace = "test")
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test")
+    logger.info("message from test")
+
+    acquire(sharedTestLogState.lock)
+    check:
+      sharedTestLogState.logs.len == 1
+      sharedTestLogState.logs[0][0] == "test"
+      sharedTestLogState.logs[0][1].message == "message from test"
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "appenders accept messages from scopes within their namespace":
+    let logSvc = initLogService()
+    let tlaRoot = initTestLogAppender(namespace = "")
+    let tlaTest = initTestLogAppender(namespace = "test")
+    logSvc.addAppender(tlaRoot)
+    logSvc.addAppender(tlaTest)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test/sub")
+    logger.info("message from test/sub")
+
+    acquire(sharedTestLogState.lock)
+    let logs = sharedTestLogState.logs
+    check:
+      logs.len == 2
+      logs[0][0] == ""
+      logs[0][1].message == "message from test/sub"
+      logs[1][0] == "test"
+      logs[1][1].message == "message from test/sub"
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "appenders do not accept messages outside their namespace":
+    let logSvc = initLogService()
+    let tlaRoot = initTestLogAppender(namespace = "")
+    let tlaTest = initTestLogAppender(namespace = "test")
+    logSvc.addAppender(tlaRoot)
+    logSvc.addAppender(tlaTest)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("other")
+    logger.info("message from other")
+
+    acquire(sharedTestLogState.lock)
+    let logs = sharedTestLogState.logs
+    check:
+      logs.len == 1
+      logs[0][0] == ""
+      logs[0][1].message == "message from other"
+
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+suite "thresholds":
+
+  test "logger gates messages by level":
+    let logSvc = initLogService()
+    let tla = initTestLogAppender()
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test", some(lvlInfo))
+    logger.debug("message at debug level")
+    logger.info("message at info level")
+    logger.warn("message at warn level")
+
+    acquire(sharedTestLogState.lock)
+    let logs = sharedTestLogState.logs
+    check:
+      logs.len == 2
+      logs[0][1].message == "message at info level"
+      logs[1][1].message == "message at warn level"
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "root threshold applies when logger has none":
+    let logSvc = initLogService(lvlWarn)
+    let tla = initTestLogAppender()
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("test")
+    logger.debug("message at debug level")
+    logger.info("message at info level")
+    logger.warn("message at warn level")
+
+    acquire(sharedTestLogState.lock)
+    let logs = sharedTestLogState.logs
+    check:
+      logs.len == 1
+      logs[0][1].message == "message at warn level"
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "logger inherits effective threshold from ancestors":
+    let logSvc = initLogService()
+    let tla = initTestLogAppender()
+    logSvc.addAppender(tla)
+    reloadThreadState(logSvc)
+
+    let l1 = logSvc.getLogger("test", some(lvlInfo))
+    let l2 = logSvc.getLogger("test/sub")
+    let l3 = logSvc.getLogger("test/sub/subsub")
+    let l4 = logSvc.getLogger("other")
+
+    l3.debug("message at debug level")
+    l3.info("message at info level")
+    l3.warn("message at warn level")
+    l4.debug("message at debug level")
+
+    acquire(sharedTestLogState.lock)
+    let l3Logs = sharedTestLogState.logs --> filter(it[1].scope == "test/sub/subsub")
+    let l4Logs = sharedTestLogState.logs --> filter(it[1].scope == "other")
+    check:
+      l3Logs.len == 2
+      l3Logs[0][1].message == "message at info level"
+      l3Logs[1][1].message == "message at warn level"
+      l4Logs.len == 1
+      l4Logs[0][1].message == "message at debug level"
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)
+
+  test "appender gates messages by level":
+    let logSvc = initLogService()
+    let tlaInfo = initTestLogAppender(namespace="a", threshold = lvlInfo)
+    let tlaDebug = initTestLogAppender(namespace="a/b", threshold = lvlDebug)
+    logSvc.addAppender(tlaInfo)
+    logSvc.addAppender(tlaDebug)
+    reloadThreadState(logSvc)
+
+    let logger = logSvc.getLogger("a/b")
+    logger.debug("message at debug level")
+    logger.info("message at info level")
+    logger.warn("message at warn level")
+
+    acquire(sharedTestLogState.lock)
+    let aLogs = sharedTestLogState.logs --> filter(it[0] == "a")
+    let bLogs = sharedTestLogState.logs --> filter(it[0] == "a/b")
+    check:
+      aLogs.len == 2
+      aLogs[0][1].message == "message at info level"
+      aLogs[1][1].message == "message at warn level"
+      bLogs.len == 3
+      bLogs[0][1].message == "message at debug level"
+      bLogs[1][1].message == "message at info level"
+      bLogs[2][1].message == "message at warn level"
+
+    sharedTestLogState.logs.setLen(0)
+    release(sharedTestLogState.lock)