diff --git a/README.md b/README.md index 080ec60..002f53f 100644 --- a/README.md +++ b/README.md @@ -314,9 +314,10 @@ loggers or configuring each worker separately. > [!NOTE] > Thread-safety work is still in progress. Custom state and captured -> formatters must follow the ownership rules above. Runtime configuration -> refresh and concurrent local-time timestamp construction still have known -> failures. Nim 2.2.10 also produces sanitizer reports in its default allocator +> formatters must follow the ownership rules above. Standalone `isEnabled()` +> checks do not yet notice changed namespace thresholds, and concurrent +> local-time timestamp construction still has a known failure. +> Nim 2.2.10 also produces sanitizer reports in its default allocator > during some cross-thread allocation patterns. See > [the regression tests](tests/README.md) for the remaining work. @@ -375,9 +376,10 @@ let handle = localLogSvc.service ``` Configuration methods remain available on both types. Shared handles contain no -cache; `ensureFreshness(handle)` only validates initialization, and -`handle.appenders()` clones the current shared configuration. Local services -retain their per-thread caches and refresh them through `ensureFreshness(local)`. +cache; `handle.appenders()` clones the current shared configuration. +`ensureFreshness` applies only to *ThreadLocalLogService*, which maintains a +per-thread cache. Calls to `ensureFreshness(handle)` must be removed or changed +to refresh the relevant local service when migrating to version 3.0.0. *ThreadLocalLogService* is the object that users are expected to interact with during regular operation and support both the configuration functions of @@ -450,8 +452,10 @@ proc ensureFreshness*(ls: ThreadLocalLogService) = # Only acquire lock and copy if versions differ withLock ls.shared.lock: - ls.configVersion = ls.shared.configVersion.load - # Sync state... + let version = ls.shared.configVersion.load() + # Build the complete replacement cache, then install it after success. + # If building raises, preserve the previous cache and version for retry. + ls.configVersion = version ``` Goals/Motivation: diff --git a/src/namespaced_logging.nim b/src/namespaced_logging.nim index 3a5ce36..9d8e9a8 100644 --- a/src/namespaced_logging.nim +++ b/src/namespaced_logging.nim @@ -285,15 +285,6 @@ proc shutdownThreadedConsoleLogging() = proc shutdownThreadedFileLogging() = shutdownWriter(fileLogging) - -proc ensureFreshness*(ls: var LogService) = - ## A shared handle has no cached configuration. Retained for callers that - ## previously refreshed LogService values; only local services need refresh. - if ls.shared == nil: - raise newException(ValueError, - "LogService not properly initialized. Use initLogService") - - proc ensureFreshness*(ls: ThreadLocalLogService) = ## Check our thread-local version of the logging service configuration ## against the global log service definition. This uses an atomic version @@ -304,22 +295,41 @@ proc ensureFreshness*(ls: ThreadLocalLogService) = "LogService not properly initialized. Use initLogService to obtain a" & "properly initialized LogService object") - # Keep a stable borrowed pointer while inspecting configuration. In - # particular, do not iterate a seq through a function-returned expression: - # that can create an owning temporary and register its shared appender refs - # with this thread's ORC cycle collector even while the lock is held. + # ORC's cycle collector maintains some thread-local bookkeeping state. + # Because of this, we have to be careful here while making a copy of the + # shared logging configuration state to avoid behavior that would result in + # temporary variables with ownership semantics (specifically the shared + # appender references in the seq). + # + # We will keep a stable borrowed pointer while inspecting configuration and + # will create temporary variables to own the data being copied that can be + # cleaned up in this proc's scope. let state = ls.serviceHandle.shared if ls.configVersion == state.configVersion.load(): return - withLock state.lock: - ls.configVersion = state.configVersion.load + block: + # This block is a performance optimization. By putting these variables and + # operations in their own scope they won't get initialized or cleaned up + # unless ls.configVersion != state.configVersion.load(). - ls.appenders = @[] - for a in state.appenders: ls.appenders.add(clone(a)) + # We want the following vars to be in the outer scope (not in the lock) so + # that their cleanup happens after the lock is released. + var newAppenders: seq[LogAppender] + var newThresholds: TableRef[string, Level] - ls.thresholds = newTable[string, Level]() - for ns, t in pairs(state.thresholds): ls.thresholds[ns] = t + withLock state.lock: + let version = state.configVersion.load() + for a in state.appenders: newAppenders.add(clone(a)) + newThresholds = newTable[string, Level]() + for ns, t in pairs(state.thresholds): newThresholds[ns] = t + + # Record the version update only after every copy succeeds; a failure + # leaves the old version in place so the next freshness check retries the + # refresh. + swap(ls.appenders, newAppenders) + swap(ls.thresholds, newThresholds) + ls.configVersion = version proc initSharedLogServiceState( rootLevel = lvlAll, diff --git a/tests/README.md b/tests/README.md index a293fca..7a3b1a9 100644 --- a/tests/README.md +++ b/tests/README.md @@ -84,7 +84,11 @@ the unsafe forms are tested as compilation failures. The in-process regression tests are deterministic. The lifetime suite checks copying, self-assignment, replacement, moving, container copies, and exporting a -handle from a local service. Shutdown tests launch +handle from a local service. Refresh tests verify that repeated clone failures +preserve the old appenders and thresholds, release partial replacements, and +allow a later retry without another configuration change. A successful refresh +releases the replaced cache and installs both appenders and thresholds. +Shutdown tests launch a fresh process for each scenario and check all 10,000 numbered messages after normal exit, using isolated temporary paths and a 15-second deadline. Scenarios cover stdout, stderr, files, empty formatted messages, multiple file destinations, @@ -109,8 +113,8 @@ The suite provides targeted regressions; it does not exhaust thread scheduling or ORC cycle-collector interleavings. The ownership scenarios, lifetime suite, and appender-state cleanup regression -exercise the new ownership contracts. `isEnabled` freshness, failed-refresh -recovery, local-time timestamp construction, and allocator reports remain for +exercise the new ownership contracts. `isEnabled` freshness, +local-time timestamp construction, and allocator reports remain for subsequent work. The standalone `ownership.nim` regression suite passed AddressSanitizer and diff --git a/tests/regressions.nim b/tests/regressions.nim index 92de9b0..06afacf 100644 --- a/tests/regressions.nim +++ b/tests/regressions.nim @@ -14,6 +14,18 @@ method clone(app: FallibleAppender): LogAppender {.gcsafe.} = raise newException(ValueError, "injected clone failure") FallibleAppender(control: app.control) +type + RefreshProbeObj = object of LogAppender + destroyed: ptr int + RefreshProbe = ref RefreshProbeObj + +proc `=destroy`(app: RefreshProbeObj) = + if app.destroyed != nil: inc app.destroyed[] + `=destroy`(app.namespace) + +method clone(app: RefreshProbe): LogAppender {.gcsafe.} = + RefreshProbe(namespace: app.namespace, destroyed: app.destroyed) + type LifetimeProbeObj = object destroyed: ptr int @@ -26,10 +38,11 @@ proc `=destroy`(probe: LifetimeProbeObj) = proc ignoreMessage(state: var LifetimeProbe, msg: LogMessage) {.gcsafe, noconv.} = discard -proc watchedService(destroyed: ptr int): LogService = +proc watchedService(destroyed: ptr int, namespace = ""): LogService = result = initLogService() result.addAppender(initCustomLogAppender( - initSharedLogState(LifetimeProbeObj(destroyed: destroyed)), ignoreMessage)) + initSharedLogState(LifetimeProbeObj(destroyed: destroyed)), ignoreMessage, + namespace = namespace)) proc createAndReleaseService(destroyed: ptr int) = var service = watchedService(destroyed) @@ -128,6 +141,42 @@ suite "ORC ownership and configuration regressions": local.ensureFreshness() check local.appenders().len == 1 + test "failed refresh preserves the old cache and releases partial replacements": + var oldStateDestroyed, discardedClones: int + var control: CloneControl + var service = watchedService(addr oldStateDestroyed, "old") + service.setThreshold("worker", lvlError) + let local = service.threadLocalRef() + let logger = local.getLogger("worker") + + # Only the local cache retains the old appender's state after this change. + service.clearAppenders() + service.addAppender(RefreshProbe(namespace: "new", destroyed: addr discardedClones)) + service.addAppender(FallibleAppender(control: addr control)) + service.setThreshold("worker", lvlInfo) + let initiallyDestroyed = discardedClones + + for attempt in 1 .. 2: + control.failNext = true + expect ValueError: + local.ensureFreshness() + check oldStateDestroyed == 0 + check discardedClones == initiallyDestroyed + attempt + block: + let cached = local.appenders() + require cached.len == 1 + check cached[0].namespace == "old" + check not logger.isEnabled(lvlInfo) + + # No further configuration update is needed to retry and install both + # the new appenders and the new namespace thresholds. + local.ensureFreshness() + check oldStateDestroyed == 1 + let cached = local.appenders() + require cached.len == 2 + check cached[0].namespace == "new" + check logger.isEnabled(lvlInfo) + test "releasing the service releases state owned by its appenders": var destroyed = 0 createAndReleaseService(addr destroyed)