nim-namespaced-logging/README.md

# Namespaced Logging for Nim

`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.
- Simple, autoconfigured usage pattern reminiscent of the
  [std/logging][std-logging] interface (*not yet implemented*)

## Getting Started

Install the package via nimble:

```bash
# Not yet in official Nim packages. TODO once we've battle-tested it a little
nimble install https://github.com/jdbernard/nim-namespaced-logging
```

## Usage Patterns

### Manual Configuration
```nim
import namespaced_logging

# Manually creating a LogService. This is an independent logging root fully
# isolated from subsequent LogServices initialized with initLogService
var ls = initLogService()

# Configure logging
ls.addAppender(initConsoleLogAppender())
ls.addAppender(initFileLogAppender("app.log"))
ls.setThreshold("api", lvlWarn)

# Create loggers
let localLogSvc = threadLocalRef(ls)
let apiLogger = localLogSvc.getLogger("api")
let dbLogger = localLogSvc.getLogger("db")
```

### 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
```

### Avoiding Expensive Log Preparation

Use `isEnabled` to guard expensive work performed before a logging call:

```nim
if logger.isEnabled(lvlDebug):
  let details = buildExpensiveDetails()
  logger.debug(details)
```

`isEnabled` checks the logger's effective threshold without refreshing its
configuration. It uses cached namespace thresholds and the shared root fallback
level. Namespace changes can remain unseen until the local service refreshes.
Normal logging calls and `getLogger` refresh the cache; callers can also use
`ensureFreshness(localLogSvc)` explicitly.

If all logging is guarded by `isEnabled`, a cached disabled level can keep
skipping those logging calls indefinitely. To pick up runtime namespace changes
in that situation, refresh the local service at suitable application boundaries,
such as the start of a request or work batch.

A true result does not guarantee delivery: the logging call refreshes
configuration and appenders apply their own filters. For a single expression,
`logger.debug(buildExpensiveDetails())` already delays evaluation until the
logger's threshold permits the message. A separate guard is useful when
preparation requires multiple statements.

## 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 Namespaces

Loggers are organized hierarchically, with the hierarchy defined by the logger
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. 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.

### LogFormatter

Messages created by the library carry UTC timestamps in `LogMessage.ts`, which
remains a `DateTime`. This changes the previous local-time behavior. Structured
JSON output represents these timestamps with a `Z` suffix. Explicit timestamps
in caller-constructed `LogMessage` values are preserved.

Console, file, and std/logging appenders accept a *LogFormatter*. Noncapturing
functions such as *formatSimpleTextLog* and *formatJsonStructuredLog* are
converted automatically:

```nim
let appender = initConsoleLogAppender(formatter = formatJsonStructuredLog)
```

For a formatter that captures state, pass value configuration and a
noncapturing factory to *initLogFormatter*. The factory creates a separate
closure in each thread on first use:

```nim
proc makeFormatter(prefix: string): StatefulLogFormatterFunc =
  var count = 0
  result = proc(msg: LogMessage): string {.gcsafe.} =
    inc count
    prefix & $count & ": " & msg.msg

let appender = initConsoleLogAppender(
  formatter = initLogFormatter("request ", makeFormatter))
```

The factory's input must contain value data, such as strings, sequences of
values, or *SharedLogState* handles. Ordinary `ref` values and closures are
rejected, including when nested inside other types. The returned closure may
capture independently created references and mutable state belonging to its
thread. It must not return a closure shared with another thread.

Each appender clone starts fresh formatter state; configuration refresh can
reate new clones. For counters or other data that must persist across
refreshes or be shared between threads, pass a *SharedLogState* handle as
factory input.  To invoke a formatter directly, use
`formatter.format(message)`.


## Available Appenders

### ConsoleLogAppender

Used for writing logs to stdout or stderr.

```nim
proc initConsoleLogAppender*(
    formatter: LogFormatter = nil,  # defaults to 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: LogFormatter = nil,  # defaults to 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
proc initStdLoggingAppender*(
    fallbackOnly = true,
    formatter: LogFormatter = nil,  # defaults to formatForwardedLog
    namespace = "",
    threshold = lvlAll): StdLoggingAppender {.gcsafe.}
```

### CustomLogAppender

Provides an extension point for custom logging implementation.

Use *initCustomLogAppender* for state that can be copied by value. Its callback
receives `state: var T` and a *LogMessage*. Each clone owns a separate state
value. Ordinary `ref` values, closures, and embedded locks or atomics are
rejected, including inside containers and objects.

For mutable state shared by all workers, put value data in a *SharedLogState*:

```nim
let count = initSharedLogState(0)

proc countMessage(state: var SharedLogState[int], msg: LogMessage) {.gcsafe, noconv.} =
  state.withState(proc(value: var int) = inc value)

var service = initLogService()
service.addAppender(initCustomLogAppender(count, countMessage))
# Pass service copies to workers as described below.
# count.snapshot() reads the current count safely.
```

Copies of the handle share the same data and keep it alive. *withState* runs
its callback synchronously with exclusive access; *snapshot* returns a value
copy made under the same lock. Neither operation allows unsynchronized access
to the stored payload. Do not retain a pointer to the callback's argument or
call back into the same handle from inside *withState*, since its lock is not
recursive.

The payload must contain value data without ordinary references, closures, or
embedded synchronization primitives. Strings and sequences of supported values
are accepted. Raw pointers and types with custom copy/destruction hooks remain
an explicit caller responsibility: their lifetime and synchronization must be
safe across threads. *SharedLogState* does not make a raw pointer's target
safe.

The [testutil][] collector demonstrates shared state using value snapshots.
*LoggedMessages.get()* returns `seq[RecordedLogMessage]`: timestamps are
*Time* values, additional JSON data is serialized text, and exceptions retain
name, message, and stacktrace text. Returned snapshots can be inspected and
modified independently without sharing the original message's references.

### FactoryCustomLogAppender

Provides an extension point for custom logging with state created separately
in each logging thread. Use this when state needs ordinary references or
closures owned by that thread.

Call *initFactoryCustomLogAppender(seed, factory, doLogMessage)* during logging
setup. The noncapturing factory receives a copyable value seed and creates
independently owned state on the first message handled by each clone, in the
thread doing the logging. The logging callback receives `state: var T` and a
*LogMessage*.

The seed follows the same ownership restrictions as *CustomLogAppender* state;
it may include *SharedLogState* handles. The state returned by the factory may
contain independently created references and closures. State lasts for that
clone's lifetime; configuration refresh may replace it. A factory that raises
is retried on the next message, and errors go to the configured error handler.
Do not retain managed references from an incoming *LogMessage* for use in
another thread.

## Notes on Use in Multi-Threaded Applications

This library is intended to support thread-safe logging in multi-threaded
applications, and hopefully to behave more intuitively in a multi-threaded
environment than [std/logging][std-logging] while presenting a similar API. A
key difference is that logging setup can happen separately from thread
creation, such as when an HTTP server manages its own worker threads.

The *LogService* object is the main entry point for the logging system and
should be initialized via *initLogService* during application setup, usually on
the main thread.  Pass a copy of that *LogService* to each worker that needs
logging. Such copies use the same logging configuration and will be updated
when there are changes (e.g. to appenders or logging thresholds). Calling
*initLogService* again creates a separate, independent configuration.

Within each thread, call *threadLocalRef* to obtain a *ThreadLocalLogService*,
then use its *getLogger* method to create loggers. Keep those local services and
loggers within the thread that created them. If the main thread also logs,
create a local service and loggers there too. Appenders configured during setup
are available to each thread without repeating that setup in every worker.

Once workers have their own copies of the *LogService*, the original service
can go out of scope and the thread that initialized it can finish. Logging
remains available while any service copy, local service, or logger using that
service remains alive. Join worker threads before exiting the application so
they have an opportunity to finish logging.

When background writers are enabled with `-d:multithreaded`, normal application
exit drains the console and file queues and waits for the writers to finish.
No explicit flush or delay is needed after joining the threads that log.

You can change logging configuration through a service copy or a local service
in any thread. Those changes are intended to take effect automatically on
subsequent logging calls in every thread using that service, without recreating
loggers or configuring each worker separately. `isEnabled` intentionally does
not refresh configuration; see [Avoiding Expensive Log Preparation](#avoiding-expensive-log-preparation).

> [!NOTE]
> Thread-safety work is still in progress. Custom state and captured
> formatters must follow the ownership rules above.
> Nim 2.2.10 produces sanitizer reports in its default allocator
> during some cross-thread allocation patterns. See
> [the regression tests](tests/README.md) for the remaining work.


## Architectural Design

### Overview

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
type LogService* = object
  shared: ptr SharedLogServiceState
```

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**: Copies of a *LogService* can be passed
  between threads while keeping the shared configuration alive. Configuration
  changes are intended to become visible to each associated
  *ThreadLocalLogService* automatically on subsequent logging calls.
- **Service composition**: independently initialized *LogService* objects are
  truly independent and multiple can be created and embedded in larger
  application contexts.

> [!TIP]
> The *LogService* object is the object that is intended to be shared across
> threads.

#### ThreadLocalLogService (Reference Type)
```nim
type ThreadLocalLogService* = ref object
  serviceHandle: LogService
  configVersion: int
  appenders: seq[LogAppender]
  thresholds: TableRef[string, Level]
```

*threadLocalRef* builds a fresh *ThreadLocalLogService* cache in the calling
thread, even when the configuration has not changed. We 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.

*ThreadLocalLogService* is no longer an alias for `ref LogService`. To obtain a
shared handle from a local service, use `local.service` instead of `local[]`:

```nim
let handle = localLogSvc.service
# Pass handle to a worker, which calls handle.threadLocalRef() itself.
```

Configuration methods remain available on both types. Shared handles contain no
cache; `handle.appenders()` clones the current shared configuration.
`ensureFreshness` applies only to *ThreadLocalLogService*, which maintains a
per-thread cache. Calls to `ensureFreshness(handle)` must be removed or changed
to refresh the relevant local service when migrating to version 3.0.0.

*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.

> [!CAUTION]
> *ThreadLocalLogService* objects should **never** be shared outside the
> context of the thread in which they were initialized.

#### SharedLogServiceState (Internal)

Under the hood *LogService* holds a pointer to a manually allocated shared
control block 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
- **Ownership**: Atomic retain/release and explicit destruction of configuration
- **Configuration versioning**: Atomic version numbers for efficient change
  detection

Console and file writers remain process-wide. The shared control block owns
appender prototypes; refresh borrows them under the configuration lock and
calls `clone()` to create local instances. Clones must not retain ordinary
managed references shared across threads. Built-in custom appenders copy
checked value state or shared-state handles. Factory appenders and formatters
copy value seeds and create their managed state lazily within the thread that
uses each clone.  The state of an already-used clone is never copied into
another clone.

### Thread Safety Model

#### Safe Cross-Thread Pattern
```nim
# Main thread setup
var logService = initLogService()
logService.addAppender(initConsoleLogAppender())

# Each copy retains the shared control block atomically.
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")

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: ThreadLocalLogService) =
  # Cheap atomic check first
  if ls.configVersion == ls.shared.configVersion.load():
    return  # No changes, return immediately

  # Only acquire lock and copy if versions differ
  withLock ls.shared.lock:
    let version = ls.shared.configVersion.load()
    # Build the complete replacement cache, then install it after success.
    # If building raises, preserve the previous cache and version for retry.
    ls.configVersion = version
```

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.

## Testing

Run `nimble test` for all unit, regression, and ThreadSanitizer ownership tests.
It runs every suite even when an earlier suite fails. For focused debugging,
use `nimble testUnit`, `nimble testRegression`, or `nimble testThreadSafety`.
The regression tests currently expose known defects and are expected to fail
until those defects are fixed. See [tests/README.md](tests/README.md) for commands,
requirements, and coverage limitations.

[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