Add failing ORC thread-safety regressions and run all suites with nimble test

tests/README.md

@@ -0,0 +1,53 @@
+# Regression tests
+
+These tests assert the intended behavior. Known bugs are ordinary failures,
+not expected failures: the tasks should become green as the defects are fixed.
+
+Run from the repository root:
+
+| Command | Coverage |
+| --- | --- |
+| `nimble test` | All unit, regression, and ThreadSanitizer tests under ORC with threads enabled |
+| `nimble testUnit` | Existing embedded unit tests |
+| `nimble testRegression` | Configuration freshness, refresh failure recovery, appender-state cleanup, and writer shutdown |
+| `nimble testThreadSafety` | Separate ThreadSanitizer processes for service ownership, custom state, and formatter closures, plus an independent-service control |
+
+`nimble test` attempts every suite even if an earlier suite fails to compile or
+run, summarizes the failing suites, and exits unsuccessfully if any suite fails.
+The subset commands use the same build and execution procedures as the full run.
+
+Executables are generated in ignored `tests/bin/`. The shutdown child is built
+with `-d:multithreaded`; `--threads:on` alone does not enable background writers.
+The other tests do not need background I/O to exercise ownership.
+
+The full run and the sanitizer subset require Linux, Bash, GNU `timeout`, and a
+C compiler and runtime supporting `-fsanitize=thread`. The sanitizer instruments
+the generated Nim C code, including the ORC runtime. A sanitizer report, timeout,
+crash, or runtime startup
+failure causes a nonzero result; consult the diagnostic to distinguish these.
+Each scenario runs separately so one failure does not hide another. To inspect
+one scenario after building:
+
+```sh
+TSAN_OPTIONS=halt_on_error=1:exitcode=66 timeout 30s tests/bin/thread_safety service
+```
+
+The worker start barrier ensures argument setup finishes before the concurrent
+operations begin. Parent owners survive until all workers join. Custom-state
+and closure tests only read application data; their concurrent writes are the
+implicit ownership operations caused by cloning and destruction. The independent
+case creates a separate service inside each worker and should pass. Custom-state
+and formatter cloning is serialized with a lock, matching configuration refresh;
+the copied appenders are used and destroyed outside that lock.
+
+The three in-process regression tests are deterministic. Shutdown tests launch
+a fresh process for each destination and check all 10,000 messages after normal
+exit, using isolated temporary paths and a 15-second deadline. They exercise the
+real exit hook without sleeps to hide queued-message loss. Like the race tests,
+the shutdown failure can depend on scheduling; a passing run is not proof of
+thread safety or reliable draining.
+
+This suite does not yet force an active producer/channel-close race, separately
+exercise the shared `testutil.LoggedMessages` graph, or exhaust ORC cycle-collector
+interleavings. It provides targeted regressions for the reproduced ownership
+defects and the configuration, cleanup, and shutdown findings.

tests/regressions.nim

@@ -0,0 +1,90 @@
+import std/[os, osproc, strutils, tempfiles, unittest]
+import ../src/namespaced_logging
+
+type
+  CloneControl = object
+    failNext: bool
+  FallibleAppender = ref object of LogAppender
+    control: ptr CloneControl
+
+method clone(app: FallibleAppender): LogAppender {.gcsafe.} =
+  if app.control.failNext:
+    app.control.failNext = false
+    raise newException(ValueError, "injected clone failure")
+  FallibleAppender(control: app.control)
+
+type
+  LifetimeProbeObj = object
+    destroyed: ptr int
+  LifetimeProbe = ref LifetimeProbeObj
+
+proc `=destroy`(probe: LifetimeProbeObj) =
+  inc probe.destroyed[]
+
+proc ignoreMessage(state: LifetimeProbe, msg: LogMessage) {.gcsafe, noconv.} =
+  discard
+
+proc createAndReleaseService(destroyed: ptr int) =
+  var service = initLogService()
+  service.addAppender(initCustomLogAppender(
+    LifetimeProbe(destroyed: destroyed), ignoreMessage))
+  # All owning handles leave scope here. No thread or cycle is involved.
+
+suite "ORC ownership and configuration regressions":
+  test "isEnabled observes a namespace change before any log call":
+    var service = initLogService()
+    service.setThreshold("worker", lvlError)
+    let local = service.threadLocalRef()
+    let logger = local.getLogger("worker")
+    check not logger.isEnabled(lvlInfo)
+
+    # Simulate a change from another service handle without introducing a
+    # reference-count race into this deterministic configuration test.
+    service.setThreshold("worker", lvlInfo)
+    check logger.isEnabled(lvlInfo)
+
+  test "a failed refresh is retried without another configuration change":
+    var control: CloneControl
+    var service = initLogService()
+    service.addAppender(FallibleAppender(control: addr control))
+    let local = service.threadLocalRef()
+    discard local.getLogger("worker")
+    service.setRootThreshold(lvlInfo)
+
+    control.failNext = true
+    expect ValueError:
+      local.ensureFreshness()
+
+    # clone now succeeds; the failed refresh must not have marked the
+    # incomplete local configuration as current.
+    local.ensureFreshness()
+    check local.appenders().len == 1
+
+  test "releasing the service releases state owned by its appenders":
+    var destroyed = 0
+    createAndReleaseService(addr destroyed)
+    check destroyed == 1
+
+suite "Background writer shutdown regressions":
+  for destination in ["file", "console"]:
+    test destination & " writer drains accepted messages at normal process exit":
+      let directory = createTempDir("namespaced_logging_shutdown_", "")
+      let outputPath = directory / "messages.log"
+      defer: removeDir(directory)
+
+      let child = startProcess(parentDir(getAppFilename()) / "writer_child",
+        args = [destination, outputPath], options = {poParentStreams})
+      defer: close(child)
+      let exitCode = child.waitForExit(15_000)
+      if exitCode == -1:
+        child.kill()
+        discard child.waitForExit()
+      check exitCode == 0
+      require fileExists(outputPath)
+
+      let received = readFile(outputPath).splitLines()
+      # Check every record and its order, not just file existence. splitLines
+      # includes one final empty item because each record ends with a newline.
+      check received.len == 10_001
+      for i in 0 ..< min(10_000, received.len - 1):
+        check received[i] == "message " & $i

tests/run_tsan.sh

@@ -0,0 +1,16 @@
+#!/usr/bin/env bash
+set -u
+
+binary=${1:?Expected the ThreadSanitizer test executable}
+result=0
+for scenario in independent service custom-state formatter; do
+  echo "ThreadSanitizer scenario: $scenario"
+  if TSAN_OPTIONS=halt_on_error=1:exitcode=66 timeout 30s "$binary" "$scenario"; then
+    echo "PASS: $scenario"
+  else
+    code=$?
+    echo "FAIL: $scenario (exit $code)" >&2
+    result=1
+  fi
+done
+exit "$result"

tests/thread_safety.nim

@@ -0,0 +1,103 @@
+## Run each scenario in its own ThreadSanitizer-instrumented process.
+## Success means no race was reported; a crash is not required to expose UB.
+import std/[atomics, locks, os]
+import ../src/namespaced_logging
+
+const iterations = 1_000
+var start: Atomic[bool]
+var cloneLock: Lock
+
+proc awaitStart() =
+  while not start.load():
+    discard
+
+proc serviceWorker(service: LogService) {.thread.} =
+  awaitStart()
+  for i in 0 ..< iterations:
+    let local = service.threadLocalRef()
+    let logger = local.getLogger("worker")
+    doAssert logger.isEnabled(lvlInfo)
+
+proc independentWorker() {.thread.} =
+  awaitStart()
+  var service = initLogService()
+  service.setThreshold("worker", lvlInfo)
+  for i in 0 ..< iterations:
+    let local = service.threadLocalRef()
+    let logger = local.getLogger("worker")
+    doAssert logger.isEnabled(lvlInfo)
+
+type
+  CustomState = ref object
+    value: int
+  StatefulAppender = CustomLogAppender[CustomState]
+
+proc ignoreMessage(state: CustomState, msg: LogMessage) {.gcsafe, noconv.} =
+  discard
+
+proc stateWorker(source: ptr StatefulAppender) {.thread.} =
+  awaitStart()
+  for i in 0 ..< iterations:
+    var copied: StatefulAppender
+    withLock cloneLock:
+      copied = StatefulAppender(clone(source[]))
+    doAssert copied.state.value == 42
+
+proc makeFormatter(prefix: string): LogMessageFormatter =
+  result = proc(msg: LogMessage): string {.gcsafe.} = prefix & msg.msg
+
+proc formatterWorker(source: ptr ConsoleLogAppender) {.thread.} =
+  awaitStart()
+  # This formatter only needs msg. Avoid clock/timezone initialization so
+  # sanitizer diagnostics identify closure ownership rather than libc state.
+  let msg = LogMessage(msg: "message")
+  for i in 0 ..< iterations:
+    var copied: ConsoleLogAppender
+    withLock cloneLock:
+      copied = ConsoleLogAppender(clone(source[]))
+    doAssert copied.formatter(msg) == "prefix: message"
+
+proc main() =
+  doAssert paramCount() == 1
+  initLock(cloneLock)
+  defer: deinitLock(cloneLock)
+  case paramStr(1)
+  of "independent":
+    var workers: array[4, Thread[void]]
+    for i in 0 ..< workers.len:
+      createThread(workers[i], independentWorker)
+    start.store(true)
+    joinThreads(workers)
+  of "service":
+    var service = initLogService()
+    service.setThreshold("worker", lvlInfo)
+    service.addAppender(initConsoleLogAppender())
+    var workers: array[4, Thread[LogService]]
+    for i in 0 ..< workers.len:
+      createThread(workers[i], serviceWorker, service)
+    # No parent-side copying/configuration changes overlap the workers.
+    # The parent retains service and all thread argument storage until join.
+    start.store(true)
+    joinThreads(workers)
+  of "custom-state":
+    var source = initCustomLogAppender(CustomState(value: 42), ignoreMessage)
+    var workers: array[4, Thread[ptr StatefulAppender]]
+    for i in 0 ..< workers.len:
+      createThread(workers[i], stateWorker, addr source)
+    start.store(true)
+    joinThreads(workers)
+  of "formatter":
+    var source = initConsoleLogAppender()
+    source.formatter = makeFormatter("prefix: ")
+    var workers: array[4, Thread[ptr ConsoleLogAppender]]
+    for i in 0 ..< workers.len:
+      createThread(workers[i], formatterWorker, addr source)
+    start.store(true)
+    joinThreads(workers)
+  else:
+    raise newException(ValueError, "unknown thread safety scenario")
+
+# The pointer-based scenarios borrow immutable source appenders whose owner
+# outlives all workers. This isolates clone/destruction races from LogService
+# copying and from ordinary unsynchronized application-state mutation.
+main()

tests/writer_child.nim

@@ -0,0 +1,29 @@
+import std/os
+import ../src/namespaced_logging
+
+when not defined(multithreaded):
+  {.error: "Compile this fixture with -d:multithreaded to exercise writer threads".}
+
+proc formatLine(msg: LogMessage): string {.gcsafe.} = msg.msg & "\n"
+
+proc main() =
+  doAssert paramCount() == 2
+  var service = initLogService()
+  case paramStr(1)
+  of "file":
+    service.addAppender(initFileLogAppender(paramStr(2)))
+  of "console":
+    # Keep stdout open through the library's exit hook. Redirecting it to a
+    # file also prevents a full parent/child pipe from blocking the writer.
+    doAssert open(stdout, paramStr(2), fmWrite)
+    service.addAppender(initConsoleLogAppender(formatter = formatLine))
+  else:
+    raise newException(ValueError, "unknown writer destination")
+
+  let local = service.threadLocalRef()
+  let logger = local.getLogger("shutdown")
+  for i in 0 ..< 10_000:
+    logger.info("message " & $i)
+  # No sleep or explicit flush: normal exit must preserve accepted messages.
+
+main()