From 14e71c72ca03907f1bac8e3aeb33612e75594112 Mon Sep 17 00:00:00 2001 From: Jonathan Bernard Date: Mon, 28 Sep 2026 15:09:26 -0500 Subject: [PATCH] Preserve cached configuration when refresh fails Build replacement appenders and thresholds before installing them and advancing the local version. Release partial replacements and old caches outside the configuration lock. In order to make the `ensureFreshness` version check as cheap as posible and only incur overhead when we actually need to update the local cache, isolate the refresh logic in a separate scope to prevent initialization and cleanup of temporary variables when the version has not changed Add regression coverage for repeated clone failures, cache preservation, cleanup, and retry without another configuration change. Update documentation to reflect the remaining freshness issue. --- README.md | 20 ++++++++------ src/namespaced_logging.nim | 48 ++++++++++++++++++++-------------- tests/README.md | 10 ++++--- tests/regressions.nim | 53 ++++++++++++++++++++++++++++++++++++-- 4 files changed, 99 insertions(+), 32 deletions(-) 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)