Logging follow-up: serialize setLogger callers (JVM crash), pin the logging contracts with tests - #448
Merged
Conversation
Two concurrent setLogger calls raced on common_log's worker std::thread: the swap pauses (joins) and resumes (assigns a fresh thread) the worker, and without serialization one caller joined while the other assigned over the still-joinable object, which is std::terminate -- the JVM died with "terminate called without an active exception". The previous llama_log_set implementation held g_log_mutex for the whole swap; the sink swap cannot (the join needs that mutex on the worker), so a separate g_set_logger_mutex now serializes callers. LlamaLoggerTest#concurrentSetLoggerCallsDoNotRace OnTheLogWorker (4 threads x 200 swaps) reproduced the crash before the fix and passes after it. Javadoc: setLogger now names the second deadlock rule (do not hold a lock the previous callback needs while the drain runs it on the worker); setLogVerbosity no longer claims "the last model loaded wins" -- a load without -lv leaves the process-wide threshold untouched. The per-line attach/detach of the worker thread is documented as the simple, not the cheapest, choice, with the thread_local-guard optimisation filed in TODO.md. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UVwj2UuMPybiK1bHyG9toH
LlamaLoggerTest gains three tests, all against the real libjllama and a
deliberately failing load, no GGUF needed:
- verbosityThresholdIsProcessWideAndEveryLoadSetsIt: -lv 1 hides the
server's INFO line and keeps llama's ERROR line; a load WITHOUT -lv puts
the threshold back to 3. That last part corrects the previous commit's
Javadoc, which followed a review remark claiming such a load leaves the
threshold untouched -- measured, it does not: common_params_parse ends
with common_log_set_verbosity_thold(params.verbosity), default 3. The
Javadoc and CLAUDE.md now say what the test shows.
- deliveryIsAsynchronousOnTheLogWorkerAndRemovingTheLoggerDrains: lines
never arrive on the caller's thread, always on a native-attached one, and
setLogger(format, null) returns only after the queue is drained -- the
facts behind both deadlock rules. It prints the distinct Thread count
(13 lines -> 13 Thread objects today), recorded in TODO.md for the
thread_local-guard optimisation.
- The srv-line matcher is exact now ("srv … loading model '"); the loose
contains("loading model") also matched llama's "error loading model".
LocalAgentTest pins .mvn/jvm.config with -Dstdout.encoding=UTF-8 and
-Dstderr.encoding=UTF-8, so the Windows console fix cannot be dropped
unnoticed.
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01UVwj2UuMPybiK1bHyG9toH
…mit described The LocalAgentTest addition announced in 8753693 had not been written to disk (the script that carried it aborted earlier); this is that test. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01UVwj2UuMPybiK1bHyG9toH
bernardladenthin
had a problem deploying
to
maven-central
September 21, 2026 17:46 — with
GitHub Actions
Failure
bernardladenthin
had a problem deploying
to
startgate
September 21, 2026 17:46 — with
GitHub Actions
Error
bernardladenthin
had a problem deploying
to
maven-central
September 21, 2026 17:46 — with
GitHub Actions
Failure
6 tasks
This branch had an error being deployed
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Follow-up to #447 (merged before these three commits landed on the branch; rebased onto
main).setLoggercalls crashed the JVM. The sink swap introduced in Logging: route setLogger through a common_log sink (patch 0014); quiet agent console #447 pauses (joins) and resumes (assigns a freshstd::thread) llama.cpp's log worker. Two unserialized callers raced on thatstd::thread: one joined it while the other assigned over the still-joinable object, which isstd::terminate(terminate called without an active exception, whole JVM gone). The oldllama_log_setimplementation heldg_log_mutexfor the whole swap; the sink swap cannot (the join needs that mutex on the worker), so a separateg_set_logger_mutexnow serializes callers; the trampoline never takes it, so no deadlock with the join.LlamaLoggerTest#concurrentSetLoggerCallsDoNotRaceOnTheLogWorker(4 threads × 200 swaps) reproduced the crash before the fix and passes after it.libjllama:verbosityThresholdIsProcessWideAndEveryLoadSetsIt(-lv 1hides the server's INFO line, keeps llama's ERROR line; a load without-lvresets the threshold to 3 —common_params_parseends withcommon_log_set_verbosity_thold(params.verbosity), default 3, which a review had assumed the other way round),deliveryIsAsynchronousOnTheLogWorkerAndRemovingTheLoggerDrains(never on the caller's thread, always native-attached,setLogger(format, null)returns only after the drain; prints the distinct-Threadcount: 13 lines → 13 objects today), and the agent'smavenJvmConfigPinsAUtf8ConsoleForExecJava(.mvn/jvm.configkeeps both UTF-8 flags). Thesrv-line matcher is exact now; the loosecontains("loading model")also matched llama'serror loading model.setLoggerJavadoc names the second deadlock rule (do not hold a lock the previous callback needs while the drain runs it on the worker);setLogVerbosityJavadoc states the measured every-load reset; the per-line attach/detach of the worker thread is documented as the simple, not the cheapest, choice, with thethread_local-guard optimisation and its caveats filed inTODO.md; CLAUDE.md patch-table row updated accordingly.Test plan
LlamaLoggerTest6/6 (incl. the race test, which crashed the JVM against the unfixed library),NativeLibraryLoadSmokeTest4/4, agentLocalAgentTest6/6 +AgentOptionsTest8/8; javadoc and spotbugs clean; clang-format 23.1.1 applied.Related issues / PRs
Follow-up to #447. Refs #444 / #445 / #446 (the Atmosphere agent).
Checklist
CONTRIBUTING.mdandCODE_OF_CONDUCT.mdSECURITY.md)🤖 Generated with Claude Code
https://claude.ai/code/session_01UVwj2UuMPybiK1bHyG9toH
Generated by Claude Code