Bump version.

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.

.gitignore

@@ -1,3 +1,5 @@
 .*.sw?
 nimcache/
 tests/tests
+src/namespaced_logging.out
+src/namespaced_logging/autoconfigured

README.md

@@ -1,38 +1,178 @@
 # Namespaced Logging for Nim
 
-`namespaced_logging` provides a logging framework similar to [log4j][] or
-[logback][] for Nim. It has three main motivating features:
+`namespaced_logging` is intended to be a high-performance, thread-safe logging
+framework similar to [std/logging][std-logging] with support for
+namespace-scoped logging similar to [log4j][] or [logback][] for Nim. It has
+four 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).
+- Native support for structured logging.
+- Simple, autoconfigured usage pattern reminiscent of the
+  [std/logging][std-logging] interface.
 
 ## Getting Started
 
-Install the package from nimble:
+Install the package via nimble:
 
 ```bash
-nimble install namespaced_logging
+# Not yet in official Nim packages. TODO once we've battle-tested it a little
+nimble install https://github.com/jdbernard/nim-namespaced-logging
 ```
 
-Then, in your application, you can use the logging system like so:
+## Usage Patterns
 
+### Simple, Autoconfigured Setup
+```nim
+import namespaced_logging/autoconfigured
+
+# Zero configuration of the LogService required, appender/logger configuration
+# is immediately available
+addLogAppender(initConsoleLogAppender())
+info("Application started")
+
+# Set global threshold
+setRootLoggingThreshold(lvlWarn)
+
+# Namespaced loggers, thresholds, and appenders supported
+addLogAppender(initFileLogAppender(
+  filePath = "/var/log/app_db.log",
+  formatter = formatJsonStructuredLog, # provided in namespaced_logging
+  namespace = "app/db",
+  threshold = lvlInfo))
+
+# in DB code
+let dbLogger = getLogger("app/db/queryplanner")
+dbLogger.debug("Beginning query plan...")
+
+# native support for structured logs (import std/json)
+dbLogger.debug(%*{
+  "method": "parseParams",
+  "message": "unrecognized param type",
+  "invalidType": $params[idx].type,
+  "metadata": %(params.meta)
+} )
+```
+
+### Manual Configuration
 ```nim
 import namespaced_logging
 
-# On the main thread
-let logService = initLogService()
-logService.addAppender(initConsoleAppender(LogLevel.INFO))
+# Manually creating a LogService. This is an independent logging root fully
+# isolated from subsequent LogServices initialized with initLogService
+var ls = initLogService()
 
-# On any thread, including the main thread
-let logger = logService.getLogger("app/service/example")
-logger.info("Log from the example service")
+# Configure logging
+ls.addAppender(initConsoleLogAppender())
+ls.addAppender(initFileLogAppender("app.log"))
+ls.setThreshold("api", lvlWarn)
 
-# 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")
+# Create loggers
+let localLogSvc = threadLocalRef(ls)
+let apiLogger = localLogSvc.getLogger("api")
+let dbLogger = localLogSvc.getLogger("db")
 ```
 
+### Autoconfigured Multithreaded Application
+```nim
+import namespaced_logging/autoconfigured
+import mummy, mummy/routers
+
+# Main thread setup
+addLogAppender(initConsoleLogAppender())
+
+proc createApiRouter*(apiCtx: ProbatemApiContext): Router =
+  # This will run on a separate thread, but the thread creation is managed by
+  # mummy, not us. Log functions still operate correctly and respect the
+  # configuration setup on the main thread
+  let logger = getLogger("api")
+  logger.trace(%*{ "method_entered": "createApiRouter" })
+
+  # API route setup...
+
+  logger.debug(%*{ "method": "createApiRouter", "routes": numRoutes })
+
+
+let server = newServer(createApiRouter(), workerThreads = 4)
+ctx.server.serve(Port(8080))
+info("Serving MyApp v1.0.0 on port 8080")
+
+setThreshold("api", lvlTrace) # will be picked up by loggers on worker threads
+```
+
+
+### Manual Multithreaded Application
+```nim
+import namespaced_logging
+
+# Main thread setup
+var logService = initLogService()
+logService.addAppender(initConsoleLogAppender())
+
+var localLogSvc = threadLocalRef(logService) # for use on main thread
+
+# Worker thread function
+proc worker(ls: LogService) {.thread.} =
+  let localLogSvc = threadLocalRef(ls)
+  let logger = localLogSvc.getLogger("worker")
+
+  # Runtime configuration changes
+  localLogSvc.setThreshold("worker", lvlDebug)
+  logger.debug("Worker configured")
+
+# Safe thread creation
+createThread(workerThread, worker, logService)
+```
+
+### Dynamic Configuration
+```nim
+# Configuration can change at runtime
+proc configureLogging(localLogSvc: ThreadLocalLogService, verbose: bool) =
+  if verbose:
+    localLogSvc.setRootThreshold(lvlDebug)
+    localLogSvc.addAppender(initFileLogAppender("debug.log"))
+  else:
+    localLogSvc.setRootThreshold(lvlInfo)
+
+# 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.
@@ -43,140 +183,392 @@ 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
+### Heirarchical Logging 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`.
+scope. A logger with the scope `app/service/example` is conceptually a child of
+the logger with the scope `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 scopes 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.
+the logger. An explicit logging level threshold can be set for any scope. Any
+scope that does not have an explicit inherits its threshold from ancestor
+loggers upwards in the scope naming 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.
+
+### LogMessageFormater
+
+Both the [ConsoleLogAppender](#ConsoleLogAppender) and
+[FileLogAppender](#FileLogAppender) can be given a *LogMessageFormatter* to
+determine how a log message is formatted before being written.
+
+```nim
+type LogMessageFormatter* = proc (msg: LogMessage): string {.gcsafe.}
+```
+
+## Available Appenders
+
+### ConsoleLogAppender
+
+Used for writing logs to stdout or stderr.
+
+```nim
+proc initConsoleLogAppender*(
+    formatter = formatSimpleTextLog,
+      ## formatJsonStructuredLog is another useful formatter provided
+      ## or you can write your own
+    useStderr = false,  ## stdout is used by default
+    namespace = "",     ## appender matches all scopes by default
+    threshold = lvlAll  ## and accepts all message levels by default
+  ): ConsoleLogAppender {.gcsafe.}
+```
+
+The first time a message is sent to any *ConsoleLogAppender*, we create a
+writer thread which writes messages to the specified output in the order they
+are received, flushing the file handle after each write to enforce an ordering.
+The ConsoleLogAppender implementation uses a channel to send messages to the
+writer thread.
+
+### FileLogAppender
+
+Used for writing logs to files.
+
+```nim
+proc initFileLogAppender*(
+    filePath: string,
+    formatter = formatSimpleTextLog,
+      ## formatJsonStructuredLog is another useful formatter provided
+      ## or you can write your own
+    namespace = "",
+    threshold = lvlAll
+  ): FileLogAppender {.gcsafe.}
+
+```
+
+Similar to the *ConsoleLogAppender* implementation, the first time a message is
+sent to any *FileLogAppender* we create a writer thread which writes messages
+to files associated with the *FileLogAppender* configured for the current
+*LogService*.
+
+`namespaced_logging` does not currently have built-in logic for file
+rotation, but it does play nice with external file rotation strategies. We do
+not hold open file handles. The *FileLogAppender* attempts to batch messages
+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.
+
+```nim
+func initCustomLogAppender*[T](
+    state: T,   # arbitrary state needed for the appender
+    doLogMessage: CustomLogAppenderFunc[T],
+      # custom log appender implementation
+    namespace = "",
+    threshold = lvlAll): CustomLogAppender[T] {.gcsafe.} =
+```
+
+The `state` field allows you to explicitly pass in any data that is required
+for the custom functionality.
+
+*TODO: rethink this. I chose this to avoid GC-safety issues copying closures
+across threads, but maybe I don't need this separate, explicit state field.*
+
+> [!WARNING] The `state` data type must support copy semantics on assignment.
+> It is possible to pass a `ref` to `state` and/or data structures that include
+> `ref`s, but **you must guarantee they remain valid**, either by allocating
+> shared memeory, or (preferably) keeping alive a reference to them that the GC
+> is aware of, either on the thread where they were initialized or by
+> explicitly telling the GC about the cross-thread reference *(TODO: how?)*.
+
+See [testutil][] and the unit tests in [namespaced\_logging][nsl-unit-tests]
+for an example.
 
 
 ## 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
+The loggers and appenders in this library are thread-safe and are intended to
+behave more intuitively in a multi-threaded environment than
+[std/logging][std-logging] while presenting a similar API. This is particularly
+true 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.
+As described in the [Getting Started](#getting-started) section, you can use
+the `namespaced_logging/autoconfigured` import to use a simplified interface
+that more closely matches the contract of [std/logging][std-logging]. In this
+case all thread and state management is done for you. The only limitation is
+that you cannot create multiple global *LogService* instances. In practice this
+is an uncommon need.
 
-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).
+If you do need or want the flexibility to manage the state yourself, import
+`namespaced_logging` directly. In this case, the thread which initialized
+*LogService* must also be the longest-living thread that uses that *LogService*
+instance. If the initializing thread terminates or the *LogService* object in
+that thread goes out of scope while other threads are still running and using
+the *LogService*, the global state may be harvested by the garbage collector,
+leading to use-after-free errors when other threads attempt to log (likely
+causing segfaults).
 
-**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.
+When managing the state yourself, the *LogService* object is the main entry
+point for the logging system and should be initialized on the main thread. The
+*LogService* contains a reference to the "source of truth" for logging
+configuration and is safe to be shared between all threads.
+
+Individual threads should use the *threadLocalRef* proc to obtain a
+*ThreadLocalLogService* reference that can be used to create *Logger* objects.
+*ThreadLocalLogService* objects cache the global *LogService* state locally to
+avoid expensive locks on the shared state. Instead an atomic configuration
+version number is maintained to allow the thread-local state to detect global
+configuration changes via an inexpensive [load][atomic-load] call and
+automatically synchronize only when necessary.
 
 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
+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.
+## Architectural Design
 
-## Custom Appender Implementations
+### Overview
 
-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`
+The namespaced logging library attempts to balance performance, safety, and
+usability in multithreaded environments. The design centers on two key types:
+*LogService* and *ThreadLocalLogService*.
 
+#### LogService (Value Type)
 ```nim
-method appendLogMessage*(appender: CustomLogAppender, msg: LogMessage): void {.base, gcsafe.}
+type LogService* = object
+  configVersion: int
+  global: GlobalLogService
+  appenders: seq[LogAppender]
+  thresholds: TableRef[string, Level]
 ```
 
-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.
+The *LogService* object is intended to support uses cases such as:
+- **Main thread initialization**: a mutable *LogService* supports all of the
+  configuration functions you would typically need when initializing logging
+  for an application on the main thread.
+- **Cross-thread communication**: Being an `object` type, *LogService* follows
+  value semantics and can be safely copied between threads.
+- **Service composition**: independently initialized *LogService* objects are
+  truly independent and multiple can be created and embedded in larger
+  application contexts.
 
-Because the *LogAppender* uses multi-methods for dynamic dispatch, the
-custom appender class must also be a `ref` type.
-
-### `initThreadCopy`
+> [!TIP]
+> The *LogService* object is the object that is intended to be shared across
+> threads.
 
+#### ThreadLocalLogService (Reference Type)
 ```nim
-method initThreadCopy*(app: LogAppender): LogAppender {.base, gcsafe.}
+type ThreadLocalLogService* = ref LogService
 ```
 
-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.
+*ThreadLocalLogService* is a reference to a thread-local copy of a *LogService*
+and can be obtained via *threadLocalRef*. We purposefully use reference
+semantics within the context of a thread so that *Logger* objects created
+within the same thread context share the same *ThreadLocalLogService*
+reference, avoiding the need to synchronize every *Logger* individually.
 
-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.
+*ThreadLocalLogService* is the object that users are expected to interact with
+during regular operation and support both the configuration functions of
+*LogService* and the creation of *Logger* objects.
 
-### Example Custom Appender
+> [!CAUTION]
+> *ThreadLocalLogService* objects should **never** be shared outside the
+> context of the thread in which they were initialized.
 
-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.
+#### GlobalLogService (Internal)
 
+Under the hood *LogService* holds a reference to a *GlobalLogService*, a
+heap-allocated object that serves as the single source of truth for logging
+configuration. This internal type is not exposed to library users but manages:
+
+- **Shared configuration state**: Appenders, thresholds, and root logging level
+- **Synchronization primitives**: Locks and atomic variables for thread
+  coordination
+- **Background I/O threads**: Dedicated writer threads for console and file
+  output
+- **Configuration versioning**: Atomic version numbers for efficient change
+  detection
+
+The `GlobalLogService` ensures that configuration changes are safely propagated
+across all threads while maintaining high performance for logging operations.
+
+### Thread Safety Model
+
+#### Safe Cross-Thread Pattern
 ```nim
-import db_connectors/db_postgres
-import namespaced_logging, waterpark, waterpark/db_postgres
+# Main thread setup
+let logService = initLogService()
+logService.addAppender(initConsoleLogAppender())
 
-type DbLogAppender = ref object of LogAppender
-  dbPool: PostgresPool
+# Safe: value semantics allow crossing thread boundaries
+proc workerThread(ls: LogService) {.thread.} =
+  # Convert to thread-local reference for efficient operations
+  let tlls = threadLocalRef(ls)
+  let logger = tlls.getLogger("worker")
+  logger.info("Worker thread started")
 
-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)
+createThread(worker, workerThread, logService)
 ```
 
+#### Unsafe Pattern (Avoided by Design)
+```nim
+# DON'T DO THIS - unsafe reference sharing
+# ThreadLocalLogService should not be shared across threads
+let tlls = threadLocalRef(initLogService())
+createThread(worker, someProc, tlls)  # ❌ Potential GC issues
+```
 
+### Configuration Synchronization
+
+#### Atomic Version Checking
+
+The library uses atomic version numbers to efficiently detect configuration
+changes:
+
+```nim
+proc ensureFreshness*(ls: var LogService) =
+  # Cheap atomic check first
+  if ls.configVersion == ls.global.configVersion.load():
+    return  # No changes, return immediately
+
+  # Only acquire lock and copy if versions differ
+  withLock ls.global.lock:
+    ls.configVersion = ls.global.configVersion.load
+    # Sync state...
+```
+
+Goals/Motivation:
+- Most logging operations skip expensive synchronization so the hot path is
+  fast.
+- Propogate changes automatically so all threads see configuration updates.
+- Minimize lock contention by only acquiring when configuration changes
+
+#### Thread-Local Caching
+
+Each thread maintains its own copy of the logging configuration in
+*ThreadLocalLogService*:
+
+- **Appenders**: Thread-local copies created via `clone()` method
+- **Thresholds**: Complete copy of namespace-to-level mappings
+- **Version tracking**: Local version number for change detection
+
+This caching strategy provides:
+- **High performance**: No locks needed for normal logging operations
+- **Consistency**: All threads eventually see the same configuration
+- **Isolation**: Thread-local state prevents cross-thread interference
+
+## Error Handling
+
+### Overview
+
+For errors that occur during logging operations, there is a callback-based
+error handling system designed to attempt to gracefully handle such failures.
+Since logging is typically a non-critical operation we prioritize application
+stability over guaranteed log delivery.
+
+### Error Handler
+
+The library uses a callback-based error handling pattern where applications can
+register custom error handlers to be notified when logging operations fail. The
+error handler receives:
+- `error`: The exception that caused the failure
+- `msg`: A descriptive message providing context about where the error occurred
+
+```nim
+type ErrorHandlerFunc* = proc(error: ref Exception, msg: string) {.gcsafe, nimcall.}
+```
+
+### Default Error Handler
+
+namespaced\_logging uses the `defaultErrorHandlerFunc` if a custom error
+handler has not been configured. The default handler:
+
+1. Attempts to write to stderr, assuming it is likely to be available and monitored
+2. Writes an error message and includes both the exception message and stack
+   trace (not available in release mode).
+3. Fails silently if it is unable to write to to stderr.
+
+### Configuration
+
+#### Setting Custom Error Handlers
+```nim
+# During initialization
+var logService = initLogService(errorHandler = myCustomErrorHandler)
+
+# Or at runtime on either the LogService...
+logService.setErrorHandler(myCustomErrorHandler)
+
+# ... or on a ThreadLocalLogService
+var localLogSvc = threadLocalRef(logService)
+localLogSvc.setErrorHandler(myCustomErrorHandler)
+```
+
+#### Disabling Error Reporting
+```nim
+proc silentErrorHandler(err: ref Exception, msg: string) {.gcsafe, nimcall.} =
+  discard # Do nothing
+
+logService.setErrorHandler(silentErrorHandler)
+```
+
+### Best Practices
+
+#### Provide Fallbacks
+
+```nim
+proc robustErrorHandler(err: ref Exception, msg: string) {.gcsafe, nimcall.} =
+  # Primary: Send to monitoring system
+  if not sendToMonitoring(err, msg):
+    # Secondary: Write to dedicated error log
+    if not writeToErrorLog(err, msg):
+      # Tertiary: Use stderr as last resort
+      try:
+        stderr.writeLine("LOGGING ERROR [" & msg & "]: " & err.msg)
+        stderr.flushFile()
+      except: discard
+```
+
+#### Keep Error Handlers Simple
+
+As much as possible, avoid complex operations that might themselves fail.
+Don't do heavy operations like database writes, complex network operations, or
+file system operations that might fail and cause cascading errors.
 
 [log4j]: https://logging.apache.org/log4j/2.x/
 [logback]: https://logback.qos.ch/
 [effective logging level]: https://logback.qos.ch/manual/architecture.html#effectiveLevel
+[atomic-load]: https://nim-lang.org/docs/atomics.html#load%2CAtomic%5BT%5D%2CMemoryOrder
+[std-logging]: https://nim-lang.org/docs/logging.html
+[testutil]: /blob/main/src/namespaced_logging/testutil.nim
+[nsl-unit-tests]: https://github.com/jdbernard/nim-namespaced-logging/blob/main/src/namespaced_logging.nim#L904

namespaced_logging.nimble

@@ -1,6 +1,6 @@
 # Package
 
-version       = "1.0.1"
+version       = "2.0.1"
 author        = "Jonathan Bernard"
 description   = "Wrapper around std/logging to provide namespaced logging."
 license       = "MIT"
@@ -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/autoconfigured.nim

@@ -0,0 +1,220 @@
+import std/[json, options, strutils]
+from logging import Level
+import ../namespaced_logging
+
+export
+  # Types
+  Level,
+  Logger,
+  LogAppender,
+  LogMessage,
+  ConsoleLogAppender,
+  CustomLogAppender,
+  CustomLogAppenderFunc,
+  FileLogAppender,
+
+  # Procs/Funcs
+  `%`,
+  initConsoleLogAppender,
+  initCustomLogAppender,
+  initFileLogAppender,
+  formatJsonStructuredLog,
+  useForAutoconfiguredLogging
+
+
+proc setRootLoggingThreshold*(lvl: Level) =
+  setRootThreshold(getAutoconfiguredLogService(), lvl)
+
+
+proc setLoggingThreshold*(scope: string, lvl: Level) =
+  setThreshold(getAutoconfiguredLogService(), scope, lvl)
+
+
+proc addLogAppender*(appender: LogAppender) =
+  addAppender(getAutoconfiguredLogService(), appender)
+
+
+proc clearLogAppenders*() =
+  clearAppenders(getAutoconfiguredLogService())
+
+
+proc getLogger*(scope: string, lvl: Option[Level] = none[Level]()): Logger =
+  getLogger(getAutoconfiguredLogService(), scope, lvl)
+
+
+template log*(lm: LogMessage) = log(getAutoconfiguredLogger(), lm)
+
+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*[T](error: ref Exception, msg: T) = log(lvlError, error, msg)
+template fatal*[T](msg: T) = log(lvlFatal, msg)
+template fatal*[T](error: ref Exception, msg: T) = log(lvlFatal, error, msg)
+
+when isMainModule:
+  import std/unittest
+  import ./testutil
+
+  suite "Automatic Global Setup":
+
+    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 = 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

src/namespaced_logging/testutil.nim

@@ -0,0 +1,51 @@
+import std/[locks, sequtils, syncio, os, times]
+from logging import Level
+from ../namespaced_logging import CustomLogAppender, initCustomLogAppender, LogMessage
+
+type
+  LoggedMessages* = ref object
+    messages*: seq[LogMessage]
+    lock: Lock
+
+proc initLoggedMessages*(): LoggedMessages =
+  result = LoggedMessages(messages: @[])
+  initLock(result.lock)
+
+
+proc add*(lm: LoggedMessages, msg: LogMessage) =
+  withLock lm.lock: lm.messages.add(msg)
+
+
+proc clear*(lm: LoggedMessages) =
+  withLock lm.lock: lm.messages = @[]
+
+
+proc get*(lm: LoggedMessages): seq[LogMessage] =
+  withLock lm.lock: return lm.messages.mapIt(it)
+
+
+proc testLogAppenderProc(state: LoggedMessages, msg: LogMessage) {.gcsafe, noconv.} =
+  state.add(msg)
+
+proc initTestLogAppender*(
+    lm: LoggedMessages,
+    namespace = "",
+    threshold = lvlAll): CustomLogAppender[LoggedMessages] =
+
+  initCustomLogAppender(
+    state = lm,
+    doLogMessage = testLogAppenderProc,
+    namespace = namespace,
+    threshold = threshold)
+
+
+proc waitForFileContent*(
+    path: string,
+    expectedLines: int,
+    timeoutMs: int = 1000): seq[string] =
+  let startTime = getTime()
+  while (getTime() - startTime).inMilliseconds < timeoutMs:
+    if fileExists(path):
+      result = readLines(path)
+      if result.len >= expectedLines: break
+    sleep(10)

tests/config.nims

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

tests/tests.nim

@@ -1,303 +0,0 @@
-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)