Compare commits
2 Commits
Author | SHA1 | Date | |
---|---|---|---|
3178c50936 | |||
1b598fb445 |
1
.gitignore
vendored
1
.gitignore
vendored
@ -3,3 +3,4 @@ nimcache/
|
|||||||
tests/tests
|
tests/tests
|
||||||
src/namespaced_logging.out
|
src/namespaced_logging.out
|
||||||
src/namespaced_logging/autoconfigured
|
src/namespaced_logging/autoconfigured
|
||||||
|
.worktrees
|
||||||
|
130
README.md
130
README.md
@ -8,7 +8,7 @@ four main motivating features:
|
|||||||
- 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.
|
||||||
- Simple, autoconfigured usage pattern reminiscent of the
|
- Simple, autoconfigured usage pattern reminiscent of the
|
||||||
[std/logging][std-logging] interface.
|
[std/logging][std-logging] interface (*not yet implemented*)
|
||||||
|
|
||||||
## Getting Started
|
## Getting Started
|
||||||
|
|
||||||
@ -21,38 +21,6 @@ nimble install https://github.com/jdbernard/nim-namespaced-logging
|
|||||||
|
|
||||||
## Usage Patterns
|
## 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
|
### Manual Configuration
|
||||||
```nim
|
```nim
|
||||||
import namespaced_logging
|
import namespaced_logging
|
||||||
@ -72,34 +40,6 @@ let apiLogger = localLogSvc.getLogger("api")
|
|||||||
let dbLogger = localLogSvc.getLogger("db")
|
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
|
### Manual Multithreaded Application
|
||||||
```nim
|
```nim
|
||||||
import namespaced_logging
|
import namespaced_logging
|
||||||
@ -136,43 +76,6 @@ proc configureLogging(localLogSvc: ThreadLocalLogService, verbose: bool) =
|
|||||||
# Changes automatically propagate to all threads
|
# 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
|
## Loggers and Appenders
|
||||||
|
|
||||||
The logging system is composed of two main components: loggers and appenders.
|
The logging system is composed of two main components: loggers and appenders.
|
||||||
@ -301,7 +204,7 @@ for the custom functionality.
|
|||||||
*TODO: rethink this. I chose this to avoid GC-safety issues copying closures
|
*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.*
|
across threads, but maybe I don't need this separate, explicit state field.*
|
||||||
|
|
||||||
> [!WARNING] The `state` data type must support copy semantics on assignment.
|
> [!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
|
> 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
|
> `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
|
> shared memeory, or (preferably) keeping alive a reference to them that the GC
|
||||||
@ -320,26 +223,17 @@ behave more intuitively in a multi-threaded environment than
|
|||||||
true in 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 a reference
|
||||||
that more closely matches the contract of [std/logging][std-logging]. In this
|
to the "source of truth" for logging configuration and is safe to be shared
|
||||||
case all thread and state management is done for you. The only limitation is
|
between all threads.
|
||||||
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
|
The thread which initializes a *LogService* must also be the longest-living
|
||||||
`namespaced_logging` directly. In this case, the thread which initialized
|
thread that uses that *LogService* instance. If the initializing thread
|
||||||
*LogService* must also be the longest-living thread that uses that *LogService*
|
terminates or the *LogService* object in that thread goes out of scope while
|
||||||
instance. If the initializing thread terminates or the *LogService* object in
|
other threads are still running and using the *LogService*, the global state
|
||||||
that thread goes out of scope while other threads are still running and using
|
may be harvested by the garbage collector, leading to use-after-free errors
|
||||||
the *LogService*, the global state may be harvested by the garbage collector,
|
when other threads attempt to log (likely causing segfaults).
|
||||||
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
|
|
||||||
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
|
Individual threads should use the *threadLocalRef* proc to obtain a
|
||||||
*ThreadLocalLogService* reference that can be used to create *Logger* objects.
|
*ThreadLocalLogService* reference that can be used to create *Logger* objects.
|
||||||
|
@ -1,6 +1,6 @@
|
|||||||
# Package
|
# Package
|
||||||
|
|
||||||
version = "2.0.1"
|
version = "2.0.2"
|
||||||
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"
|
||||||
@ -15,6 +15,5 @@ requires @["nim >= 2.2.0", "zero_functional"]
|
|||||||
requires "timeutils"
|
requires "timeutils"
|
||||||
|
|
||||||
task test, "Run unittests for the package.":
|
task test, "Run unittests for the package.":
|
||||||
exec "nimble c src/namespaced_logging.nim src/namespaced_logging/autoconfigured.nim"
|
exec "nimble c src/namespaced_logging.nim"
|
||||||
exec "src/namespaced_logging.out"
|
exec "src/namespaced_logging.out"
|
||||||
exec "src/namespaced_logging/autoconfigured"
|
|
||||||
|
@ -1,5 +1,5 @@
|
|||||||
import std/[algorithm, atomics, json, locks, options, os, paths, sequtils,
|
import std/[algorithm, atomics, exitprocs, json, locks, options, os, paths,
|
||||||
strutils, tables, times]
|
sequtils, strutils, tables, times]
|
||||||
import timeutils
|
import timeutils
|
||||||
import std/logging as stdlog
|
import std/logging as stdlog
|
||||||
|
|
||||||
@ -16,19 +16,9 @@ type
|
|||||||
thresholds: TableRef[string, Level]
|
thresholds: TableRef[string, Level]
|
||||||
rootLevel: Atomic[Level]
|
rootLevel: Atomic[Level]
|
||||||
|
|
||||||
console: ThreadedConsoleLoggingState
|
|
||||||
file: ThreadedFileLoggingState
|
|
||||||
|
|
||||||
errorHandler: ErrorHandlerFunc
|
errorHandler: ErrorHandlerFunc
|
||||||
errorHandlerLock: Lock
|
errorHandlerLock: Lock
|
||||||
|
|
||||||
takeOverGls: Option[GlobalLogService]
|
|
||||||
# Used to direct ThreadLocalLogServices that they should switch to a new
|
|
||||||
# GlobalLogService (logging root). This is used primarily in the context of
|
|
||||||
# autoconfigured logging where we want to be able to reconfigure the GLS
|
|
||||||
# used for autologging, have existing ThreadLocalLogServices switch over
|
|
||||||
# to the newly provided GLS, and let the old GLS get garbage-collected
|
|
||||||
|
|
||||||
GlobalLogService = ref GlobalLogServiceObj
|
GlobalLogService = ref GlobalLogServiceObj
|
||||||
|
|
||||||
|
|
||||||
@ -94,18 +84,11 @@ type
|
|||||||
absPath: Path
|
absPath: Path
|
||||||
|
|
||||||
|
|
||||||
ThreadedConsoleLoggingState = object
|
LogWriterThreadState[M] = object
|
||||||
initialized: Atomic[bool]
|
initialized: Atomic[bool]
|
||||||
shutdown: Atomic[bool]
|
shutdown: Atomic[bool]
|
||||||
chan: Channel[ConsoleMessage]
|
chan: Channel[M]
|
||||||
writerThread: Thread[GlobalLogService]
|
writerThread: Thread[void]
|
||||||
|
|
||||||
|
|
||||||
ThreadedFileLoggingState = object
|
|
||||||
initialized: Atomic[bool]
|
|
||||||
shutdown: Atomic[bool]
|
|
||||||
chan: Channel[FileMessage]
|
|
||||||
writerThread: Thread[GlobalLogService]
|
|
||||||
|
|
||||||
|
|
||||||
ConsoleLogAppender* = ref object of LogAppender
|
ConsoleLogAppender* = ref object of LogAppender
|
||||||
@ -146,6 +129,12 @@ type
|
|||||||
const UninitializedConfigVersion = low(int)
|
const UninitializedConfigVersion = low(int)
|
||||||
let JNULL = newJNull()
|
let JNULL = newJNull()
|
||||||
|
|
||||||
|
var consoleLogging {.global.}: LogWriterThreadState[ConsoleMessage]
|
||||||
|
var fileLogging {.global.}: LogWriterThreadState[FileMessage]
|
||||||
|
var loggingThreadInitLock {.global.}: Lock
|
||||||
|
|
||||||
|
initLock(loggingThreadInitLock)
|
||||||
|
|
||||||
|
|
||||||
proc initLogMessage*(
|
proc initLogMessage*(
|
||||||
scope: string,
|
scope: string,
|
||||||
@ -200,40 +189,39 @@ proc defaultErrorHandlerFunc*(
|
|||||||
stderr.flushFile()
|
stderr.flushFile()
|
||||||
except Exception: discard # we tried...
|
except Exception: discard # we tried...
|
||||||
|
|
||||||
proc shutdownThreadedConsoleLogging(gls: var GlobalLogServiceObj) =
|
proc shutdownThreadedConsoleLogging() =
|
||||||
if not gls.console.initialized.load(): return
|
if not consoleLogging.initialized.load(): return
|
||||||
|
|
||||||
gls.console.shutdown.store(true) # signal shutdown
|
withLock loggingThreadInitLock:
|
||||||
|
consoleLogging.shutdown.store(true) # signal shutdown
|
||||||
|
|
||||||
# Send sentinel values to wake up the writer thread
|
# Send sentinel values to wake up the writer thread
|
||||||
try: gls.console.chan.send(ConsoleMessage(message: "", useStderr: false))
|
try: consoleLogging.chan.send(ConsoleMessage(message: "", useStderr: false))
|
||||||
except Exception: discard
|
except Exception: discard
|
||||||
|
|
||||||
joinThread(gls.console.writerThread)
|
joinThread(consoleLogging.writerThread)
|
||||||
gls.console.chan.close()
|
consoleLogging.chan.close()
|
||||||
gls.console.initialized.store(false)
|
consoleLogging.initialized.store(false)
|
||||||
|
|
||||||
|
|
||||||
proc shutdownThreadedFileLogging(gls: var GlobalLogServiceObj) =
|
proc shutdownThreadedFileLogging() =
|
||||||
if not gls.file.initialized.load(): return
|
if not fileLogging.initialized.load(): return
|
||||||
|
|
||||||
gls.file.shutdown.store(true) # signal shutdown
|
fileLogging.shutdown.store(true) # signal shutdown
|
||||||
|
|
||||||
try: gls.file.chan.send(FileMessage(message: "", absPath: Path("/")))
|
withLock loggingThreadInitLock:
|
||||||
except Exception: discard
|
try: fileLogging.chan.send(FileMessage(message: "", absPath: Path("/")))
|
||||||
|
except Exception: discard
|
||||||
|
|
||||||
joinThread(gls.file.writerThread)
|
joinThread(fileLogging.writerThread)
|
||||||
gls.file.chan.close()
|
fileLogging.chan.close()
|
||||||
gls.file.initialized.store(false)
|
fileLogging.initialized.store(false)
|
||||||
|
|
||||||
|
|
||||||
proc `=destroy`*(gls: var GlobalLogServiceObj) =
|
proc `=destroy`*(gls: var GlobalLogServiceObj) =
|
||||||
# only one thread should cleanup
|
# only one thread should cleanup
|
||||||
if not gls.initialized.exchange(false): return
|
if not gls.initialized.exchange(false): return
|
||||||
|
|
||||||
gls.shutdownThreadedConsoleLogging()
|
|
||||||
gls.shutdownThreadedFileLogging()
|
|
||||||
|
|
||||||
try: deinitLock(gls.lock)
|
try: deinitLock(gls.lock)
|
||||||
except Exception: discard
|
except Exception: discard
|
||||||
|
|
||||||
@ -253,12 +241,6 @@ proc ensureFreshness*(ls: var LogService) =
|
|||||||
|
|
||||||
if ls.configVersion == ls.global.configVersion.load(): return
|
if ls.configVersion == ls.global.configVersion.load(): return
|
||||||
|
|
||||||
if ls.global.takeOverGls.isSome:
|
|
||||||
let newGls = ls.global.takeOverGls.get
|
|
||||||
assert not newGls.isNil
|
|
||||||
assert newGls.initialized.load
|
|
||||||
ls.global = newGls
|
|
||||||
|
|
||||||
withLock ls.global.lock:
|
withLock ls.global.lock:
|
||||||
ls.configVersion = ls.global.configVersion.load
|
ls.configVersion = ls.global.configVersion.load
|
||||||
|
|
||||||
@ -434,6 +416,15 @@ proc getLogger*(
|
|||||||
result = Logger(scope: scope, threadSvc: ls)
|
result = Logger(scope: scope, threadSvc: ls)
|
||||||
|
|
||||||
|
|
||||||
|
proc getLogger*(
|
||||||
|
ls: Option[ThreadLocalLogService],
|
||||||
|
scope: string,
|
||||||
|
lvl: Option[Level] = none[Level]()): Option[Logger] {.gcsafe.} =
|
||||||
|
return
|
||||||
|
if ls.isSome: some(getLogger(ls.get, scope, lvl))
|
||||||
|
else: none[Logger]()
|
||||||
|
|
||||||
|
|
||||||
proc addAppender*(ls: var LogService, appender: LogAppender) {.gcsafe.} =
|
proc addAppender*(ls: var LogService, appender: LogAppender) {.gcsafe.} =
|
||||||
## Add a log appender to the global log service and refresh the local thread
|
## Add a log appender to the global log service and refresh the local thread
|
||||||
## state. The updated global state will trigger other threads to refresh
|
## state. The updated global state will trigger other threads to refresh
|
||||||
@ -553,6 +544,102 @@ template fatal*[L: Logger or Option[Logger], M](l: L, error: ref Exception, msg:
|
|||||||
log(l, lvlFatal, error, msg)
|
log(l, lvlFatal, error, msg)
|
||||||
|
|
||||||
|
|
||||||
|
# -----------------------------------------------------------------------------
|
||||||
|
# Writer Thread Implementations
|
||||||
|
# -----------------------------------------------------------------------------
|
||||||
|
|
||||||
|
proc consoleWriterLoop() {.thread.} =
|
||||||
|
while not consoleLogging.shutdown.load():
|
||||||
|
var didSomething = false
|
||||||
|
|
||||||
|
let (hasData, msg) = consoleLogging.chan.tryRecv()
|
||||||
|
if hasData and msg.message.len > 0: # Skip empty sentinel messages
|
||||||
|
try:
|
||||||
|
let output =
|
||||||
|
if msg.useStderr: stderr
|
||||||
|
else: stdout
|
||||||
|
output.write(msg.message)
|
||||||
|
output.flushFile()
|
||||||
|
didSomething = true
|
||||||
|
except IOError:
|
||||||
|
discard
|
||||||
|
|
||||||
|
# Small delay if no work to prevent busy waiting
|
||||||
|
if not didSomething: sleep(100)
|
||||||
|
|
||||||
|
|
||||||
|
proc fileWriterLoop() {.thread.} =
|
||||||
|
const bufLen = 128
|
||||||
|
var msgsByPath = newTable[Path, seq[FileMessage]]()
|
||||||
|
|
||||||
|
while not fileLogging.shutdown.load():
|
||||||
|
var didSomething = false
|
||||||
|
|
||||||
|
var msgBuf: array[bufLen, FileMessage]
|
||||||
|
var recvIdx = 0
|
||||||
|
var writeIdx = 0
|
||||||
|
var dataAvailable = true
|
||||||
|
|
||||||
|
while dataAvailable and recvIdx < bufLen:
|
||||||
|
# Fill our message buffer if we can
|
||||||
|
(dataAvailable, msgBuf[recvIdx]) = fileLogging.chan.tryRecv()
|
||||||
|
if dataAvailable: inc recvIdx
|
||||||
|
|
||||||
|
# Organize messages by destination file
|
||||||
|
msgsByPath.clear()
|
||||||
|
while writeIdx < recvIdx:
|
||||||
|
let msg = msgBuf[writeIdx]
|
||||||
|
inc writeIdx
|
||||||
|
|
||||||
|
if msg.message.len > 0: # skip empty sentinel messages
|
||||||
|
if not msgsByPath.contains(msg.absPath): msgsByPath[msg.absPath] = @[]
|
||||||
|
msgsByPath[msg.absPath].add(msg)
|
||||||
|
didSomething = true
|
||||||
|
|
||||||
|
# Write all messages in file order to optimize file open/flush/close
|
||||||
|
for path, msgs in pairs(msgsByPath):
|
||||||
|
var f: File
|
||||||
|
|
||||||
|
if not open(f, $path, fmAppend):
|
||||||
|
# TODO: can we do better than silently failing here?
|
||||||
|
continue
|
||||||
|
|
||||||
|
for m in msgs:
|
||||||
|
try: writeLine(f, m.message)
|
||||||
|
except Exception: discard
|
||||||
|
flushFile(f)
|
||||||
|
close(f)
|
||||||
|
|
||||||
|
# Wait a bit if we had no work to prevent busy waiting
|
||||||
|
if not didSomething: sleep(100)
|
||||||
|
|
||||||
|
|
||||||
|
proc initThreadedConsoleLogging() =
|
||||||
|
if consoleLogging.initialized.load: return
|
||||||
|
|
||||||
|
withLock loggingThreadInitLock:
|
||||||
|
if consoleLogging.initialized.load: return
|
||||||
|
consoleLogging.chan.open()
|
||||||
|
consoleLogging.shutdown.store(false)
|
||||||
|
|
||||||
|
# Create writer thread with reference to the service
|
||||||
|
createThread(consoleLogging.writerThread, consoleWriterLoop)
|
||||||
|
consoleLogging.initialized.store(true)
|
||||||
|
|
||||||
|
|
||||||
|
proc initThreadedFileLogging() =
|
||||||
|
if fileLogging.initialized.load: return
|
||||||
|
|
||||||
|
withLock loggingThreadInitLock:
|
||||||
|
if fileLogging.initialized.load: return
|
||||||
|
fileLogging.chan.open()
|
||||||
|
fileLogging.shutdown.store(false)
|
||||||
|
|
||||||
|
# Create writer thread with reference to the service
|
||||||
|
createThread(fileLogging.writerThread, fileWriterLoop)
|
||||||
|
fileLogging.initialized.store(true)
|
||||||
|
|
||||||
|
|
||||||
# -----------------------------------------------------------------------------
|
# -----------------------------------------------------------------------------
|
||||||
# CustomLogAppender Implementation
|
# CustomLogAppender Implementation
|
||||||
# -----------------------------------------------------------------------------
|
# -----------------------------------------------------------------------------
|
||||||
@ -613,41 +700,6 @@ proc initConsoleLogAppender*(
|
|||||||
useStderr: useStderr)
|
useStderr: useStderr)
|
||||||
|
|
||||||
|
|
||||||
proc consoleWriterLoop(gls: GlobalLogService) {.thread.} =
|
|
||||||
while not gls.console.shutdown.load():
|
|
||||||
var didSomething = false
|
|
||||||
|
|
||||||
let (hasData, msg) = gls.console.chan.tryRecv()
|
|
||||||
if hasData and msg.message.len > 0: # Skip empty sentinel messages
|
|
||||||
try:
|
|
||||||
let output =
|
|
||||||
if msg.useStderr: stderr
|
|
||||||
else: stdout
|
|
||||||
output.write(msg.message)
|
|
||||||
output.flushFile()
|
|
||||||
didSomething = true
|
|
||||||
except IOError:
|
|
||||||
discard
|
|
||||||
|
|
||||||
# Small delay if no work to prevent busy waiting
|
|
||||||
if not didSomething: sleep(100)
|
|
||||||
|
|
||||||
|
|
||||||
proc initThreadedConsoleLogging(gls: GlobalLogService) =
|
|
||||||
if gls.console.initialized.load() or # don't double-init
|
|
||||||
not gls.initialized.load(): # don't init if the gls is shutting down
|
|
||||||
return
|
|
||||||
|
|
||||||
withLock gls.lock:
|
|
||||||
if gls.console.initialized.load(): return
|
|
||||||
gls.console.chan.open()
|
|
||||||
gls.console.shutdown.store(false)
|
|
||||||
|
|
||||||
# Create writer thread with reference to the service
|
|
||||||
createThread(gls.console.writerThread, consoleWriterLoop, gls)
|
|
||||||
gls.console.initialized.store(true)
|
|
||||||
|
|
||||||
|
|
||||||
method clone*(cla: ConsoleLogAppender): LogAppender {.gcsafe.} =
|
method clone*(cla: ConsoleLogAppender): LogAppender {.gcsafe.} =
|
||||||
result = ConsoleLogAppender(
|
result = ConsoleLogAppender(
|
||||||
namespace: cla.namespace,
|
namespace: cla.namespace,
|
||||||
@ -661,11 +713,11 @@ proc appendLogMessageMultiThreaded(
|
|||||||
ls: ref LogService,
|
ls: ref LogService,
|
||||||
msg: LogMessage) {.gcsafe.} =
|
msg: LogMessage) {.gcsafe.} =
|
||||||
|
|
||||||
if not ls.global.console.initialized.load():
|
if not consoleLogging.initialized.load():
|
||||||
ls.global.initThreadedConsoleLogging()
|
initThreadedConsoleLogging()
|
||||||
|
|
||||||
try:
|
try:
|
||||||
ls.global.console.chan.send(ConsoleMessage(
|
consoleLogging.chan.send(ConsoleMessage(
|
||||||
message: cla.formatter(msg),
|
message: cla.formatter(msg),
|
||||||
useStderr: cla.useStderr))
|
useStderr: cla.useStderr))
|
||||||
except Exception:
|
except Exception:
|
||||||
@ -732,67 +784,6 @@ proc initFileLogAppender*(
|
|||||||
formatter: formatter,
|
formatter: formatter,
|
||||||
absPath: absolutePath(Path(filePath)))
|
absPath: absolutePath(Path(filePath)))
|
||||||
|
|
||||||
# TODO: initialize global state for the file log writer
|
|
||||||
|
|
||||||
|
|
||||||
proc fileWriterLoop(gls: GlobalLogService) {.thread.} =
|
|
||||||
const bufLen = 128
|
|
||||||
var msgsByPath = newTable[Path, seq[FileMessage]]()
|
|
||||||
|
|
||||||
while not gls.file.shutdown.load():
|
|
||||||
var didSomething = false
|
|
||||||
|
|
||||||
var msgBuf: array[bufLen, FileMessage]
|
|
||||||
var recvIdx = 0
|
|
||||||
var writeIdx = 0
|
|
||||||
var dataAvailable = true
|
|
||||||
|
|
||||||
while dataAvailable and recvIdx < bufLen:
|
|
||||||
# Fill our message buffer if we can
|
|
||||||
(dataAvailable, msgBuf[recvIdx]) = gls.file.chan.tryRecv()
|
|
||||||
if dataAvailable: inc recvIdx
|
|
||||||
|
|
||||||
# Organize messages by destination file
|
|
||||||
msgsByPath.clear()
|
|
||||||
while writeIdx < recvIdx:
|
|
||||||
let msg = msgBuf[writeIdx]
|
|
||||||
inc writeIdx
|
|
||||||
|
|
||||||
if msg.message.len > 0: # skip empty sentinel messages
|
|
||||||
if not msgsByPath.contains(msg.absPath): msgsByPath[msg.absPath] = @[]
|
|
||||||
msgsByPath[msg.absPath].add(msg)
|
|
||||||
didSomething = true
|
|
||||||
|
|
||||||
# Write all messages in file order to optimize file open/flush/close
|
|
||||||
for path, msgs in pairs(msgsByPath):
|
|
||||||
var f: File
|
|
||||||
|
|
||||||
if not open(f, $path, fmAppend):
|
|
||||||
# TODO: can we do better than silently failing here?
|
|
||||||
continue
|
|
||||||
|
|
||||||
for m in msgs:
|
|
||||||
try: writeLine(f, m.message)
|
|
||||||
except Exception: discard
|
|
||||||
flushFile(f)
|
|
||||||
close(f)
|
|
||||||
|
|
||||||
# Wait a bit if we had no work to prevent busy waiting
|
|
||||||
if not didSomething: sleep(100)
|
|
||||||
|
|
||||||
|
|
||||||
proc initThreadedFileLogging(gls: GlobalLogService) =
|
|
||||||
if gls.file.initialized.load(): return
|
|
||||||
|
|
||||||
withLock gls.lock:
|
|
||||||
if gls.file.initialized.load(): return
|
|
||||||
gls.file.chan.open()
|
|
||||||
gls.file.shutdown.store(false)
|
|
||||||
|
|
||||||
# Create writer thread with reference to the service
|
|
||||||
createThread(gls.file.writerThread, fileWriterLoop, gls)
|
|
||||||
gls.file.initialized.store(true)
|
|
||||||
|
|
||||||
|
|
||||||
method clone*(fla: FileLogAppender): LogAppender {.gcsafe.} =
|
method clone*(fla: FileLogAppender): LogAppender {.gcsafe.} =
|
||||||
result = FileLogAppender(
|
result = FileLogAppender(
|
||||||
@ -807,11 +798,11 @@ proc appendLogMessageMultiThreaded(
|
|||||||
ls: ref LogService,
|
ls: ref LogService,
|
||||||
msg: LogMessage) {.gcsafe.} =
|
msg: LogMessage) {.gcsafe.} =
|
||||||
|
|
||||||
if not ls.global.file.initialized.load():
|
if not fileLogging.initialized.load():
|
||||||
ls.global.initThreadedFileLogging()
|
initThreadedFileLogging()
|
||||||
|
|
||||||
try:
|
try:
|
||||||
ls.global.file.chan.send(FileMessage(
|
fileLogging.chan.send(FileMessage(
|
||||||
message: fla.formatter(msg),
|
message: fla.formatter(msg),
|
||||||
absPath: fla.absPath))
|
absPath: fla.absPath))
|
||||||
except Exception: discard
|
except Exception: discard
|
||||||
@ -890,113 +881,14 @@ method appendLogMessage*(
|
|||||||
|
|
||||||
|
|
||||||
# -----------------------------------------------------------------------------
|
# -----------------------------------------------------------------------------
|
||||||
# Autoconfiguration Implementation
|
# Cleanup
|
||||||
# -----------------------------------------------------------------------------
|
# -----------------------------------------------------------------------------
|
||||||
|
|
||||||
var autoGls = GlobalLogService()
|
addExitProc(proc() =
|
||||||
# we create the global reference so that it is maintained by the thread that
|
shutdownThreadedConsoleLogging()
|
||||||
# first imported this module, but leave it uninitialized until
|
shutdownThreadedFileLogging()
|
||||||
# initAutoconfiguredLogService is actually called (when
|
)
|
||||||
# namespaced_logging/autoconfigured is imported)
|
|
||||||
|
|
||||||
var autoTlls {.threadvar.}: ThreadLocalLogService
|
|
||||||
var autoLogger {.threadvar.}: Logger
|
|
||||||
|
|
||||||
|
|
||||||
proc initAutoconfiguredLogService*() =
|
|
||||||
## This exists primarily for namespaced_logging/autoconfigured to call as
|
|
||||||
## part of its setup process. This function needs to live here and be
|
|
||||||
## exported for the autoconfigured module's visibility as many of the internal
|
|
||||||
## fields required to properly manage the autoconfigured LogService are not
|
|
||||||
## exported, to avoid confusion and prevent misuse of the library (from a
|
|
||||||
## thread-safety POV).
|
|
||||||
|
|
||||||
assert not autoGls.isNil
|
|
||||||
|
|
||||||
let oldGls = autoGls
|
|
||||||
autoGls = initGlobalLogService()
|
|
||||||
|
|
||||||
if oldGls.initialized.load:
|
|
||||||
# If we already have an auto-configured GLS, let's log to the existing GLS
|
|
||||||
# that we're replacing it.
|
|
||||||
|
|
||||||
withLock oldGls.lock:
|
|
||||||
if autoTlls.isNil:
|
|
||||||
# If we somehow have an auto-configured GLS but never instantiated a
|
|
||||||
# thread-local LogService, let's do so temporarily.
|
|
||||||
autoTlls = new(LogService)
|
|
||||||
autoTlls.global = oldGls
|
|
||||||
ensureFreshness(autoTlls)
|
|
||||||
|
|
||||||
warn(
|
|
||||||
getLogger(autoTlls, "namespaced_logging/autoconfigured"),
|
|
||||||
"initializing a new auto-configured logging service, replacing this one")
|
|
||||||
|
|
||||||
oldGls.takeOverGls = some(autoGls)
|
|
||||||
oldGls.configVersion.atomicInc
|
|
||||||
|
|
||||||
autoTlls = threadLocalRef(initLogService(autoGls))
|
|
||||||
autoLogger = autoTlls.getLogger("")
|
|
||||||
|
|
||||||
|
|
||||||
proc getAutoconfiguredLogService*(): ThreadLocalLogService =
|
|
||||||
if autoTlls.isNil:
|
|
||||||
if not autoGls.initialized.load():
|
|
||||||
initAutoconfiguredLogService()
|
|
||||||
assert autoGls.initialized.load()
|
|
||||||
|
|
||||||
autoTlls = threadLocalRef(initLogService(autoGls))
|
|
||||||
|
|
||||||
return autoTlls
|
|
||||||
|
|
||||||
|
|
||||||
proc getAutoconfiguredLogger*(): Logger =
|
|
||||||
if autoLogger.isNil:
|
|
||||||
autoLogger = getLogger(getAutoconfiguredLogService(), "")
|
|
||||||
|
|
||||||
return autoLogger
|
|
||||||
|
|
||||||
|
|
||||||
proc useForAutoconfiguredLogging*(ls: LogService) =
|
|
||||||
# Reconfigure the autoconfigured logging behavior to use the given LogService
|
|
||||||
# configuration instead of the existing autoconfigured configuration. This is
|
|
||||||
# useful in applications that want to control the behavior of third-party
|
|
||||||
# libraries or code that use namespaced_logging/autoconfigured.
|
|
||||||
#
|
|
||||||
# Libraries and other non-application code are suggested to use
|
|
||||||
# namespaced_logging/autoconfigured. The autoconfigured log service has no
|
|
||||||
# appenders when it is initialized which means that applications which are
|
|
||||||
# unaware of namespaced_logging are unaffected and no logs are generated.
|
|
||||||
|
|
||||||
if ls.global == autoGls:
|
|
||||||
# As of Nim 2 `==` on `ref`s performs a referential equality check by
|
|
||||||
# default, and we don't overload `==`. Referential equality is what we're
|
|
||||||
# after here. If the reference in ls already points to the same place as
|
|
||||||
# autoGls, we have nothing to do
|
|
||||||
return
|
|
||||||
|
|
||||||
if autoGls.initialized.load:
|
|
||||||
# if there is an existing autoGls, let's leave instructions for loggers and
|
|
||||||
# LogService instances to move to the newly provided GLS before we change
|
|
||||||
# our autoGls reference.
|
|
||||||
withLock autoGls.lock:
|
|
||||||
autoGls.takeOverGls = some(ls.global)
|
|
||||||
autoGls.configVersion.atomicInc
|
|
||||||
|
|
||||||
autoGls = ls.global
|
|
||||||
|
|
||||||
|
|
||||||
proc useForAutoconfiguredLogging*(tlls: ThreadLocalLogService) =
|
|
||||||
useForAutoconfiguredLogging(tlls[])
|
|
||||||
|
|
||||||
|
|
||||||
proc resetAutoconfiguredLogging*() =
|
|
||||||
## Reset the auto-configured logging service. In general it is suggested to
|
|
||||||
# define a new LogService, configure it, and pass it to
|
|
||||||
# *useForAutoconfiguredLogging* instead. in a way that disconnects it
|
|
||||||
#from
|
|
||||||
autoGls = GlobalLogService()
|
|
||||||
initAutoconfiguredLogService()
|
|
||||||
|
|
||||||
# -----------------------------------------------------------------------------
|
# -----------------------------------------------------------------------------
|
||||||
# Tests
|
# Tests
|
||||||
|
@ -1,220 +0,0 @@
|
|||||||
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
|
|
Reference in New Issue
Block a user