diff --git a/README.md b/README.md index 002f53f..1ee93ec 100644 --- a/README.md +++ b/README.md @@ -76,6 +76,33 @@ proc configureLogging(localLogSvc: ThreadLocalLogService, verbose: bool) = # Changes automatically propagate to all threads ``` +### Avoiding Expensive Log Preparation + +Use `isEnabled` to guard expensive work performed before a logging call: + +```nim +if logger.isEnabled(lvlDebug): + let details = buildExpensiveDetails() + logger.debug(details) +``` + +`isEnabled` checks the logger's effective threshold without refreshing its +configuration. It uses cached namespace thresholds and the shared root fallback +level. Namespace changes can remain unseen until the local service refreshes. +Normal logging calls and `getLogger` refresh the cache; callers can also use +`ensureFreshness(localLogSvc)` explicitly. + +If all logging is guarded by `isEnabled`, a cached disabled level can keep +skipping those logging calls indefinitely. To pick up runtime namespace changes +in that situation, refresh the local service at suitable application boundaries, +such as the start of a request or work batch. + +A true result does not guarantee delivery: the logging call refreshes +configuration and appenders apply their own filters. For a single expression, +`logger.debug(buildExpensiveDetails())` already delays evaluation until the +logger's threshold permits the message. A separate guard is useful when +preparation requires multiple statements. + ## Loggers and Appenders The logging system is composed of two main components: loggers and appenders. @@ -310,13 +337,13 @@ No explicit flush or delay is needed after joining the threads that log. You can change logging configuration through a service copy or a local service in any thread. Those changes are intended to take effect automatically on subsequent logging calls in every thread using that service, without recreating -loggers or configuring each worker separately. +loggers or configuring each worker separately. `isEnabled` intentionally does +not refresh configuration; see [Avoiding Expensive Log Preparation](#avoiding-expensive-log-preparation). > [!NOTE] > Thread-safety work is still in progress. Custom state and captured -> 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. +> formatters must follow the ownership rules above. 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. diff --git a/config.nims b/config.nims new file mode 100644 index 0000000..8ee48d2 --- /dev/null +++ b/config.nims @@ -0,0 +1,4 @@ +# begin Nimble config (version 2) +when withDir(thisDir(), system.fileExists("nimble.paths")): + include "nimble.paths" +# end Nimble config diff --git a/src/namespaced_logging.nim b/src/namespaced_logging.nim index 9d8e9a8..4cb837f 100644 --- a/src/namespaced_logging.nim +++ b/src/namespaced_logging.nim @@ -541,7 +541,6 @@ func getEffectiveThreshold(logger: Logger): Level {.gcsafe.} = ## Get the effective logging level threshold for a logger. This is the most ## specific level that is set for the logger or any of its parents. The root ## logger is used as the default if no other level is set. - result = logger.threadSvc.shared.rootLevel.load # Check for exact match first if logger.threadSvc.thresholds.hasKey(logger.scope): @@ -555,10 +554,27 @@ func getEffectiveThreshold(logger: Logger): Level {.gcsafe.} = # If we have matches, return the threshold configured for the most specific. if namespaces.len > 0: - result = logger.threadSvc.thresholds[namespaces[0]] + return logger.threadSvc.thresholds[namespaces[0]] + + return logger.threadSvc.shared.rootLevel.load proc isEnabled*(l: Logger, lvl: Level): bool {.inline,gcsafe.} = + ## Check the logger's effective threshold without refreshing configuration. + ## Use this to guard expensive log preparation performed outside a logging + ## call. Namespace thresholds come from the thread-local cache; the root + ## fallback level is read from the shared service. + ## + ## Repeated checks do not refresh that cache. Namespace changes can remain + ## unseen until a logging call, getLogger, or an explicit ensureFreshness on + ## the local service refreshes it. Applications that only log behind these + ## guards should refresh their local service at suitable execution boundaries + ## if they need to observe configuration changes. + ## + ## A true result does not guarantee delivery: the subsequent logging call + ## refreshes configuration and appenders apply their own filters. Expressions + ## passed directly to the level/message logging templates are already + ## evaluated only when the logger's threshold permits the message. lvl >= l.getEffectiveThreshold diff --git a/tests/README.md b/tests/README.md index 7a3b1a9..397f6a5 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. Refresh tests verify that repeated clone failures +handle from a local service. `isEnabled` tests verify that namespace thresholds +remain cached until an explicit refresh, a logging call, or `getLogger`, while +the root fallback is read from shared state. This behavior is intentional so +guards can avoid configuration refresh work. +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. @@ -113,8 +117,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, -local-time timestamp construction, and allocator reports remain for +exercise the new ownership contracts. 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 06afacf..cbd5fb6 100644 --- a/tests/regressions.nim +++ b/tests/regressions.nim @@ -112,7 +112,7 @@ suite "ORC service handle lifetime": check destroyed == 1 suite "ORC ownership and configuration regressions": - test "isEnabled observes a namespace change before any log call": + test "isEnabled uses cached namespace thresholds until a refresh": var service = initLogService() service.setThreshold("worker", lvlError) let local = service.threadLocalRef() @@ -122,8 +122,35 @@ suite "ORC ownership and configuration regressions": # Simulate a change from another service handle without introducing a # reference-count race into this deterministic configuration test. service.setThreshold("worker", lvlInfo) + check not logger.isEnabled(lvlInfo) + + local.ensureFreshness() check logger.isEnabled(lvlInfo) + # A stale true result can become false when the logging call refreshes. + service.setThreshold("worker", lvlError) + check logger.isEnabled(lvlInfo) + logger.info("filtered after refreshing configuration") + check not logger.isEnabled(lvlInfo) + + # Creating another logger also refreshes their shared local service. + service.setThreshold("worker", lvlInfo) + check not logger.isEnabled(lvlInfo) + discard local.getLogger("another") + check logger.isEnabled(lvlInfo) + + test "isEnabled reads the shared root fallback without refreshing namespaces": + var service = initLogService(rootLevel = lvlError) + let local = service.threadLocalRef() + let logger = local.getLogger("worker") + check not logger.isEnabled(lvlInfo) + + service.setRootThreshold(lvlInfo) + service.setThreshold("worker", lvlError) + check logger.isEnabled(lvlInfo) + local.ensureFreshness() + check not logger.isEnabled(lvlInfo) + test "a failed refresh is retried without another configuration change": var control: CloneControl var service = initLogService()