Compare commits
15 Commits
Author | SHA1 | Date | |
---|---|---|---|
3178c50936 | |||
1b598fb445 | |||
101ac8d869 | |||
a4464c7275 | |||
49755fa2af | |||
b2d43d1c6d | |||
c22e7edd5d | |||
269cc81c82 | |||
1884e07378 | |||
2f761833bd | |||
c4074007b5 | |||
05f5c2548c | |||
9861a93ee4 | |||
4a8365ebef | |||
f80e5807db |
3
.gitignore
vendored
3
.gitignore
vendored
@ -1,3 +1,6 @@
|
||||
.*.sw?
|
||||
nimcache/
|
||||
tests/tests
|
||||
src/namespaced_logging.out
|
||||
src/namespaced_logging/autoconfigured
|
||||
.worktrees
|
||||
|
502
README.md
502
README.md
@ -1,36 +1,79 @@
|
||||
# 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 (*not yet implemented*)
|
||||
|
||||
## 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
|
||||
|
||||
### 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")
|
||||
```
|
||||
|
||||
### 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
|
||||
@ -43,140 +86,383 @@ 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.*
|
||||
|
||||
> [!CAUTION] 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.
|
||||
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.
|
||||
|
||||
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).
|
||||
The thread which initializes a *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.
|
||||
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
|
||||
|
@ -1,6 +1,6 @@
|
||||
# Package
|
||||
|
||||
version = "1.1.0"
|
||||
version = "2.0.2"
|
||||
author = "Jonathan Bernard"
|
||||
description = "Wrapper around std/logging to provide namespaced logging."
|
||||
license = "MIT"
|
||||
@ -13,3 +13,7 @@ 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"
|
||||
exec "src/namespaced_logging.out"
|
||||
|
File diff suppressed because it is too large
Load Diff
51
src/namespaced_logging/testutil.nim
Normal file
51
src/namespaced_logging/testutil.nim
Normal file
@ -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)
|
@ -1 +0,0 @@
|
||||
--path:"../src"
|
303
tests/tests.nim
303
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)
|
Reference in New Issue
Block a user