1 Commits

Author SHA1 Message Date
3e7f3d4c1e Add version to nimble. 2025-07-07 21:49:35 -05:00
3 changed files with 109 additions and 449 deletions

554
README.md
View File

@@ -1,139 +1,36 @@
# Namespaced Logging for Nim # Namespaced Logging for Nim
`namespaced_logging` is intended to be a high-performance, thread-safe logging `namespaced_logging` provides a logging framework similar to [log4j][] or
framework similar to [std/logging][std-logging] with support for [logback][] for Nim. It has three main motivating features:
namespace-scoped logging similar to [log4j][] or [logback][] for Nim. It has
four main motivating features:
- Hierarchical, namespaced logging - Hierarchical, namespaced logging
- Safe and straightforward to use in multi-threaded applications. - Safe and straightforward to use in multi-threaded applications.
- Native support for structured logging. - Native support for structured logging (old-style string logging is also
- Simple, autoconfigured usage pattern reminiscent of the supported).
[std/logging][std-logging] interface.
## Getting Started ## Getting Started
Install the package via nimble: Install the package from nimble:
```bash ```bash
# Not yet in official Nim packages. TODO once we've battle-tested it a little nimble install namespaced_logging
nimble install https://github.com/jdbernard/nim-namespaced-logging
``` ```
## Usage Patterns Then, in your application, you can use the logging system like so:
### 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 ```nim
import namespaced_logging import namespaced_logging
# Manually creating a LogService. This is an independent logging root fully # On the main thread
# isolated from subsequent LogServices initialized let logService = initLogService()
var ls = initLogService() logService.addAppender(initConsoleAppender(LogLevel.INFO))
# Configure logging # On any thread, including the main thread
ls.addAppender(initConsoleLogAppender()) let logger = logService.getLogger("app/service/example")
ls.addAppender(initFileLogAppender("app.log")) logger.info("Log from the example service")
ls.setThreshold("api", lvlWarn)
# Create loggers # Only get logs at the WARN or higher level from the database module
let localLogSvc = threadLocalRef(ls) let logger = logService.getLogger("app/database", threshold = some(Level.lvlWarn))
let apiLogger = localLogSvc.getLogger("api") logger.error("Database connection failed")
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
``` ```
## Loggers and Appenders ## Loggers and Appenders
@@ -146,377 +43,140 @@ threshold, which determines which log events are acted upon by the appender,
and, optionally, a namespace filter, which determines from which loggers the and, optionally, a namespace filter, which determines from which loggers the
appender accepts log events. appender accepts log events.
### Heirarchical Logging Namespaces ### Heirarchical Logging and Namespaces
Loggers are organized hierarchically, with the hierarchy defined by the logger 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 name. A logger with the name `app/service/example` is a child of the logger
the logger with the scope `app/service`. By default, appenders accept log with the name `app/service`. By default, appenders accept log events from all
events from all loggers, but this can be restricted by setting a namespace loggers, but this can be restricted by setting a namespace filter on the
filter on the appender. An appender with a namespace set will accept log events appender. An appender with a namespace set will accept log events from all
from all loggers with scopes that start with the namespace. For example, an loggers with names that start with the namespace. For example, an appender with
appender with the namespace `app` will accept log events from the loggers the namespace `app` will accept log events from the loggers `app`,
`app`, `app/service`, and `app/service/example`, but not from `api/service`. `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 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 the logger. Any logger can have an explicit logging level set, but if it does
scope that does not have an explicit inherits its threshold from ancestor not, the effective logging level is inherited from ancestor loggers upwards in
loggers upwards in the scope naming heirarchy. This pattern is explained in the logger heirarchy. This pattern is explained in detail in the [logback
detail in the [logback documentation][effective logging level] and applies in documentation][effective logging level] and applies in the same manner to
the same manner to loggers in this library. 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 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.
### 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.*
> [!IMPORTANT] 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 ## Notes on Use in Multi-Threaded Applications
The loggers and appenders in this library are thread-safe and are intended to The loggers and appenders in this library are thread-safe and behaves more
behave more intuitively in a multi-threaded environment than intuitively in a multi-threaded environment than `std/logging`, particularly in
[std/logging][std-logging] while presenting a similar API. This is particularly environments where the logging setup code may be separated from the
true in environments where the logging setup code may be separated from the
thread-management code (in an HTTP server, for example). thread-management code (in an HTTP server, for example).
As described in the [Getting Started](#getting-started) section, you can use The *LogService* object is the main entry point for the logging system and
the `namespaced_logging/autoconfigured` import to use a simplified interface should be initialized on the main thread. The *LogService* contains the "source
that more closely matches the contract of [std/logging][std-logging]. In this of truth" for logging configuration and is shared between all threads.
case all thread and state management is done for you. The only limitation is Internally all access to the *LogService* is protected by a mutex.
that you cannot create multiple global *LogService* instances. In practice this
is an uncommon need.
If you do need or want the flexibility to manage the state yourself, import Logging can be very noisy and if the *LogService* needed to be consulted for
`namespaced_logging` directly. In this case, the thread which initialized every log event, it could easily become a performance bottleneck. To avoid
*LogService* must also be the longest-living thread that uses that *LogService* this, the *getLogger* procedure makes a thread-local copy of the logging system
instance. If the initializing thread terminates or the *LogService* object in configuration (loggers defined and appenders attached).
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).
When managing the state yourself, the *LogService* object is the main entry **Note** that this means that the thread-local cache of the logging system
point for the logging system and should be initialized on the main thread. The configuration can become stale if the logging system configuration is changed
*LogService* contains a reference to the "source of truth" for logging after the thread-local copy is made (if another appender is added, for
configuration and is safe to be shared between all threads. example). This is a trade-off to avoid the performance penalty of consulting
the *LogService* for every log event.
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 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 the logging system itself is responsible for making sure appenders are
configured for every thread where loggers are used, even if the thread configured for every thread where loggers are used, even if the thread
initialization context is separated from the logging setup code. 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.
## Architectural Design 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.
### Overview ## Custom Appender Implementations
The namespaced logging library is built around a thread-safe architecture that Due to the thread-safety of the logging system, there are a few additional
attempts to balance performance, safety, and usability in multithreaded considerations when implementing custom appenders. The *LogAppender* abstract
environments. The design centers on two key types (*LogService* and class is the base class for all appenders. To implement a custom appender, two
*ThreadLocalLogService*) that work together to provide both thread-safe methods must be implemented:
configuration management and efficient logging operations.
### Core Architecture Components ### `appendLogMessage`
#### GlobalLogService (Internal)
At the heart of the system is the `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.
#### LogService vs ThreadLocalLogService
The library exposes two distinct types for different usage patterns:
##### LogService (Value Type)
```nim
type LogService* = object
configVersion: int
global: GlobalLogService
appenders: seq[LogAppender]
thresholds: TableRef[string, Level]
```
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.
> [!TIP]
> The *LogService* object is the object that is intended to be shared across
> threads.
##### ThreadLocalLogService (Reference Type)
```nim
type ThreadLocalLogService* = ref LogService
```
The *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 *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.
### Thread Safety Model
#### Safe Cross-Thread Pattern
```nim
# Main thread setup
let logService = initLogService()
logService.addAppender(initConsoleLogAppender())
# 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")
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 ```nim
proc ensureFreshness*(ls: var LogService) = method appendLogMessage*(appender: CustomLogAppender, msg: LogMessage): void {.base, gcsafe.}
# 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...
``` ```
This design ensures that: This is the primary appender implementation that takes a LogMessage and
- **Hot path is fast**: Most logging operations skip expensive synchronization writes it to the appender's destination. As the signature suggests, the
- **Changes propagate automatically**: All threads see configuration updates implementation must be GC-safe. As a multi-method, the *CustomLogAppender* type
- **Minimal lock contention**: Locks only acquired when configuration changes should be replaced by the actual name of your custom appender.
#### Thread-Local Caching Because the *LogAppender* uses multi-methods for dynamic dispatch, the
custom appender class must also be a `ref` type.
Each thread maintains its own copy of the logging configuration: ### `initThreadCopy`
- **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 ```nim
type ErrorHandlerFunc* = proc(error: ref Exception, msg: string) {.gcsafe, nimcall.} method initThreadCopy*(app: LogAppender): LogAppender {.base, gcsafe.}
``` ```
### Default Error Handler 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.
namespaced\_logging uses the `defaultErrorHandlerFunc` if a custom error The `initThreadCopy` implementations for the built-in *ConsoleLogAppender* and
handler has not been configured. The default handler: *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.
1. Attempts to write to stderr, assuming it is likely to be available and monitored ### Example Custom Appender
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 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.
#### Setting Custom Error Handlers
```nim ```nim
# During initialization import db_connectors/db_postgres
var logService = initLogService(errorHandler = myCustomErrorHandler) import namespaced_logging, waterpark, waterpark/db_postgres
# Or at runtime on either the LogService... type DbLogAppender = ref object of LogAppender
logService.setErrorHandler(myCustomErrorHandler) dbPool: PostgresPool
# ... or on a ThreadLocalLogService let dbPool: PostgresPool = newPostgresPool(10, "", "", "", connectionString)
var localLogSvc = threadLocalRef(logService)
localLogSvc.setErrorHandler(myCustomErrorHandler) 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)
``` ```
#### 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/ [log4j]: https://logging.apache.org/log4j/2.x/
[logback]: https://logback.qos.ch/ [logback]: https://logback.qos.ch/
[effective logging level]: https://logback.qos.ch/manual/architecture.html#effectiveLevel [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

View File

@@ -1,6 +1,6 @@
# Package # Package
version = "1.1.0" version = "2.0.0"
author = "Jonathan Bernard" author = "Jonathan Bernard"
description = "Wrapper around std/logging to provide namespaced logging." description = "Wrapper around std/logging to provide namespaced logging."
license = "MIT" license = "MIT"

View File

@@ -440,7 +440,7 @@ proc log*(l: Logger, lvl: Level, msg: JsonNode) {.gcsafe.} =
error: none[ref Exception](), error: none[ref Exception](),
timestamp: now(), timestamp: now(),
message: message:
if msg.hasKey("message"): msg["message"].getStr if msg.hasKey("msg"): msg["msg"].getStr
else: "", else: "",
additionalData: msg)) additionalData: msg))