Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 26 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,33 @@ from version 5.0.0 onward. Pre-fork releases (`1.x`–`4.2.0`) were authored by

## [Unreleased]

### Fixed
- **`LlamaModel.setLogger` was silently overridden by every model load, and never saw the server's own
log lines.** llama.cpp's `common_init()` — run on each load — re-points `llama_log_set()` at its own
default callback, so a logger set *before* `new LlamaModel(…)` (the natural order) stopped receiving
anything; and the `srv …` / `slot …` lines (per-request timings, slot state) are written by the server
macros straight into `common_log`, which `llama_log_set()` never carried, so they went to stderr no
matter what Java configured. The logger is now a sink on `common_log` itself
(`patches/0014-common-log-callback-sink.patch`, `common_log_set_callback`): it survives loads, it
receives every line — the server's and llama/ggml's — and it replaces the console output instead of
duplicating it (a `setLogFile` file keeps being written). Messages are delivered from llama.cpp's log
worker thread; replacing or removing the logger flushes what is queued to the previous callback first,
so `setLogger(format, null)` is a synchronous drain. Behaviour change to know: the verbosity threshold
now applies before the callback (as on the console), so llama/ggml INFO lines reach the logger only
from `setLogVerbosity(4)` on. `LlamaModelTest#testLogText/testLogJSON` are re-enabled (they were
`@Disabled` because of exactly this), `#testLoggerSetBeforeLoadSurvivesTheLoad` pins the ordering, and
the model-free `LlamaLoggerTest` plus six C++ tests guard the sink on every platform.
- The `setLogger` Javadoc and the README "Logging" section claimed JSON to stdout as the default; the
default is llama.cpp's text format on stderr. `enableLogPrefix()` / `enableLogTimestamps()` are
documented as the no-ops they are (`common_init()` forces both on), `setLogFile` as additive.

### Added
- **`llama-atmosphere-agent`: `--log-verbosity <n>` (default `2`) and `--verbose`** for the in-process
`--model` mode. llama.cpp's per-request INFO lines go to stderr, the console the streamed answer is
printed to, and interleaved with it; the agent now loads the model with warnings-and-errors only. A
`.mvn/jvm.config` pins `-Dstdout.encoding=UTF-8 -Dstderr.encoding=UTF-8` for the `mvn exec:java`
JVM, because on Windows `common_init()` switches the console to UTF-8 after the JVM fixed its stdout
encoding from the old code page (umlauts/emoji in answers rendered as `�`/`?`).
- **`llama-atmosphere-agent/` — a local, offline JVM coding agent** (Claude Code / OpenCode reduced to
the essentials) that drives [Atmosphere](https://github.com/Atmosphere/atmosphere)'s built-in
OpenAI-compatible agent runtime **headless** (no Spring Boot, no servlet container) against this
Expand Down
11 changes: 9 additions & 2 deletions CLAUDE.md

Large diffs are not rendered by default.

25 changes: 16 additions & 9 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -1146,21 +1146,28 @@ app already uses. The pattern is verified end-to-end by

### Logging

Per default, logs are written to stdout.
This can be intercepted via the static method `LlamaModel.setLogger(LogFormat, BiConsumer<LogLevel, String>)`.
There is text- and JSON-based logging. The default is JSON.
Note, that text-based logging will include additional output of the GGML backend, while JSON-based logging
only provides request logs (while still writing GGML messages to stdout).
To only change the log format while still writing to stdout, `null` can be passed for the callback.
Logging can be disabled by passing an empty callback.
Per default, llama.cpp writes its log as text to **stderr** (`0.00.035.060 I slot …` once a model is
loaded): the server's own `srv …` / `slot …` lines and, from verbosity 4 on, the llama/ggml lines.
All of it can be intercepted via the static method
`LlamaModel.setLogger(LogFormat, BiConsumer<LogLevel, String>)`: with a callback set, every line goes
to the callback instead of the console (a `setLogFile` file keeps receiving them). The callback
survives model loads, so set it before `new LlamaModel(…)` to capture the loading lines too.
`LogFormat.TEXT` hands over the bare message, `LogFormat.JSON` one JSON object per line. Passing
`null` as the callback restores the console output (always llama.cpp's own text format; the format
argument only matters with a callback). Logging can be disabled by passing an empty callback.
Messages arrive asynchronously from llama.cpp's log worker thread; replacing or removing the logger
flushes what is queued to the previous callback first. The verbosity threshold
(`ModelParameters.setLogVerbosity(int)`, llama.cpp's `-lv`: 1 errors, 2 warnings, 3 info, 4 trace,
5 debug) applies before the callback: `2` keeps warnings and errors and silences the per-request
INFO lines, which is what a console application sharing the terminal with its own output wants.

```java
// Re-direct log messages however you like (e.g. to a logging library)
LlamaModel.setLogger(LogFormat.TEXT, (level, message) -> System.out.println(level.name() + ": " + message));
// Log to stdout, but change the format
// Back to llama.cpp's own console output (stderr)
LlamaModel.setLogger(LogFormat.TEXT, null);
// Disable logging by passing a no-op
LlamaModel.setLogger(null, (level, message) -> {});
LlamaModel.setLogger(LogFormat.TEXT, (level, message) -> {});
```

The `LogLevel` enum values passed to the callback correspond to the native llama.cpp log levels:
Expand Down
8 changes: 4 additions & 4 deletions TODO.md
Original file line number Diff line number Diff line change
Expand Up @@ -171,10 +171,10 @@ These are JNI plumbing items for upstream API additions. Policy: add only after
- **`--log-jsonl` / `--no-log-jsonl`** (a positive/negative flag pair, so it would fit `ModelFlag`
directly). The only one of the three with real consumer value, but it is **not a free addition**:
it flips `common_log_set_jsonl(common_log_main(), …)`, i.e. the process-wide llama.cpp logger,
whose output for this library goes through the JNI log callback. The project already has its own
JSON logging at the Java level — the `args.LogFormat` enum plus `log_helpers.hpp`'s
`format_log_as_json` — so the two would overlap and could contradict each other on the same
stream. Deciding which layer owns the format is a **feature decision**, not a correctness fix,
whose console output (and, since `patches/0014`, the sink `LlamaModel.setLogger` hooks) it would
reformat. The project already has its own JSON logging at the Java level — the `args.LogFormat`
enum plus `log_helpers.hpp`'s `format_log_as_json` — so the two would overlap and could contradict
each other on the same stream. Deciding which layer owns the format is a **feature decision**, not a correctness fix,
and needs its own change with its own tests.
- **`--spec-synth-len` and `--spec-synth-rates`** — a documented non-goal, not deferred work. The
reasoning lives in its own entry below (**"deliberately NOT exposed, and this should stay that
Expand Down
2 changes: 2 additions & 0 deletions llama-atmosphere-agent/.mvn/jvm.config
Original file line number Diff line number Diff line change
@@ -0,0 +1,2 @@
-Dstdout.encoding=UTF-8
-Dstderr.encoding=UTF-8
14 changes: 14 additions & 0 deletions llama-atmosphere-agent/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,7 @@ irrelevant: inference stays in the running server, the agent's JVM loads no mode
| `--base-url <url>` | OpenAI-compatible base URL of a running server | — |
| `--model <file.gguf>` | load this GGUF in-process instead | — |
| `--ngl <n>` / `--ctx-size <n>` | GPU layers / context size for `--model` | `0` / `8192` |
| `--log-verbosity <n>` / `--verbose` | llama.cpp log threshold for `--model` (1 errors, 2 warnings, 3 info, 4 trace, 5 debug) / log everything | `2` / off |
| `--workspace <dir>` | directory the file tools (and `run_command`) are confined to | cwd |
| `--allow-shell` | register `run_command` | off |
| `--system <text>` | replace the default system prompt | built-in |
Expand All @@ -89,6 +90,19 @@ irrelevant: inference stays in the running server, the agent's JVM loads no mode
Exactly one of `--base-url` / `--model` is required. Exit code 0 = turn completed, 1 = the turn
errored, 2 = usage error. Set `-Dorg.slf4j.simpleLogger.defaultLogLevel=debug` to see every request.

**Console output with `--model`.** llama.cpp writes its own log (`slot …`, `srv …`, model loading)
to **stderr**, the same console the streamed answer goes to on stdout, so at llama.cpp's default
threshold (INFO) the per-request timing lines land in the middle of the answer. The agent therefore
loads the in-process model with `--log-verbosity 2` (warnings and errors only); `--log-verbosity 3`
brings the INFO lines back and `--verbose` logs everything. With `--base-url` the server is a separate
process and keeps its own log settings (`-lv` on `llama-server` / `NativeServer`). Two things stay
true whatever the threshold: the agent's own status lines (`Loading …`, `Endpoint …`) also go to
stderr, and `2> llama.log` therefore hides both. On Windows, loading a model switches the console to
UTF-8 (llama.cpp calls `SetConsoleOutputCP(CP_UTF8)`), while the JVM keeps encoding stdout in the
code page it saw at startup, so umlauts and emoji in the answer would turn into `�` / `?`; the
project's `.mvn/jvm.config` pins `-Dstdout.encoding=UTF-8 -Dstderr.encoding=UTF-8` for the `mvn`
JVM so both sides agree.

Pick a **tool-capable instruct model** (Qwen2.5/Qwen3-Instruct, Llama-3.x-Instruct, Mistral,
Hermes, …). Quality of the loop is the model's: a 1.5B model calls one tool and reads its result, a
7B–32B model does multi-step edit/build/test work.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -37,10 +37,21 @@ public final class AgentOptions {
/** Context size for the in-process model ({@code --model}). */
public static final int DEFAULT_CTX_SIZE = 8192;

/**
* Log verbosity threshold of the in-process model ({@code --model}): llama.cpp's {@code -lv}
* scale, {@code 0} output only, {@code 1} errors, {@code 2} warnings, {@code 3} info, {@code 4}
* trace, {@code 5} debug. The default keeps warnings and errors but drops the per-request
* {@code slot …} / {@code srv …} INFO lines, which otherwise interleave with the streamed answer
* on the console (llama.cpp writes them to stderr).
*/
public static final int DEFAULT_LOG_VERBOSITY = 2;

private final @Nullable String baseUrl;
private final @Nullable String modelPath;
private final int gpuLayers;
private final int ctxSize;
private final int logVerbosity;
private final boolean verbose;
private final String apiKey;
private final String modelId;
private final Path workspace;
Expand All @@ -57,6 +68,8 @@ private AgentOptions(Builder b) {
this.modelPath = b.modelPath;
this.gpuLayers = b.gpuLayers;
this.ctxSize = b.ctxSize;
this.logVerbosity = b.logVerbosity;
this.verbose = b.verbose;
this.apiKey = b.apiKey;
this.modelId = b.modelId;
this.workspace = b.workspace;
Expand Down Expand Up @@ -88,6 +101,8 @@ public static AgentOptions parse(String[] args) {
case "--model" -> b.modelPath = value(args, ++i, a);
case "--ngl", "--gpu-layers" -> b.gpuLayers = intValue(args, ++i, a);
case "--ctx-size" -> b.ctxSize = intValue(args, ++i, a);
case "--log-verbosity" -> b.logVerbosity = intValue(args, ++i, a);
case "--verbose", "-v" -> b.verbose = true;
case "--api-key" -> b.apiKey = value(args, ++i, a);
case "--model-id" -> b.modelId = value(args, ++i, a);
case "--workspace" ->
Expand Down Expand Up @@ -146,6 +161,9 @@ public static String usage() {
" --model <file.gguf> load this GGUF in-process and serve it to the agent",
" --ngl <n> GPU layers for --model (default 0 = CPU only)",
" --ctx-size <n> context size for --model (default " + DEFAULT_CTX_SIZE + ")",
" --log-verbosity <n> llama.cpp log threshold for --model: 1 errors, 2 warnings,",
" 3 info, 4 trace, 5 debug (default " + DEFAULT_LOG_VERBOSITY + ")",
" --verbose, -v log everything for --model (same as llama-server -v)",
"",
"Agent:",
" --workspace <dir> directory the file tools are confined to (default: cwd)",
Expand Down Expand Up @@ -196,6 +214,24 @@ public int getCtxSize() {
return ctxSize;
}

/**
* Log verbosity threshold for the in-process model.
*
* @return the {@code -lv} threshold; ignored when {@link #isVerbose()} is set
*/
public int getLogVerbosity() {
return logVerbosity;
}

/**
* Whether {@code --verbose} was given.
*
* @return {@code true} to log every message of the in-process model
*/
public boolean isVerbose() {
return verbose;
}

/**
* Bearer token.
*
Expand Down Expand Up @@ -289,7 +325,8 @@ public boolean isHelp() {
@Override
public String toString() {
return "AgentOptions{baseUrl=" + baseUrl + ", modelPath=" + modelPath + ", gpuLayers=" + gpuLayers
+ ", ctxSize=" + ctxSize + ", modelId=" + modelId + ", workspace=" + workspace
+ ", ctxSize=" + ctxSize + ", logVerbosity=" + (verbose ? "verbose" : logVerbosity)
+ ", modelId=" + modelId + ", workspace=" + workspace
+ ", allowShell=" + allowShell + ", temperature=" + temperature + ", maxTokens=" + maxTokens
+ ", maxToolRounds=" + maxToolRounds + ", prompt=" + (prompt == null ? "<interactive>" : "<set>")
+ "}";
Expand All @@ -304,6 +341,8 @@ private static final class Builder {

int gpuLayers = 0;
int ctxSize = DEFAULT_CTX_SIZE;
int logVerbosity = DEFAULT_LOG_VERBOSITY;
boolean verbose;
String apiKey = DEFAULT_API_KEY;
String modelId = DEFAULT_MODEL_ID;
Path workspace = Paths.get("").toAbsolutePath().normalize();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -179,14 +179,30 @@ private static boolean turn(
return finished && session.failure() == null;
}

private static ModelParameters modelParameters(AgentOptions options) {
/**
* The native parameters for {@code --model}.
*
* <p>Visible for tests: the log threshold is the one knob whose effect is only observable on a
* console, so the test pins the flags that leave here instead.
*
* @param options the parsed options
* @return the parameters the in-process {@link LlamaModel} is loaded with
*/
static ModelParameters modelParameters(AgentOptions options) {
ModelParameters parameters = new ModelParameters()
.setModel(options.getModelPath())
.setCtxSize(options.getCtxSize())
.setGpuLayers(options.getGpuLayers())
.setFit(false)
// Jinja rendering is what lets the native parser apply the model's tool-call template.
.enableJinja();
// llama.cpp logs to stderr, which shares the console with the streamed answer on stdout; the
// default threshold keeps warnings and errors and drops the per-request INFO lines.
if (options.isVerbose()) {
parameters.setVerbose();
} else {
parameters.setLogVerbosity(options.getLogVerbosity());
}
if (options.getGpuLayers() == 0) {
parameters.setDevices("none");
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -28,10 +28,37 @@ void baseUrlModeWithDefaults() {
assertThat(options.getTemperature(), is(AgentOptions.DEFAULT_TEMPERATURE));
assertThat(options.getMaxTokens(), is(AgentOptions.DEFAULT_MAX_TOKENS));
assertThat(options.getMaxToolRounds(), is(AgentOptions.DEFAULT_MAX_TOOL_ROUNDS));
assertThat(options.getLogVerbosity(), is(AgentOptions.DEFAULT_LOG_VERBOSITY));
assertThat(options.isVerbose(), is(false));
assertThat(options.getPrompt(), is(nullValue()));
assertThat(options.isHelp(), is(false));
}

@Test
void logVerbosityIsAnIntegerThreshold() {
AgentOptions options = AgentOptions.parse(new String[] {"--model", "m.gguf", "--log-verbosity", "4"});

assertThat(options.getLogVerbosity(), is(4));
assertThat(options.isVerbose(), is(false));
assertThat(
assertThrows(
IllegalArgumentException.class,
() -> AgentOptions.parse(new String[] {"--model", "m.gguf", "--log-verbosity", "loud"}))
.getMessage(),
containsString("--log-verbosity"));
}

@Test
void verboseIsAFlagWithAShortForm() {
assertThat(
AgentOptions.parse(new String[] {"--model", "m.gguf", "--verbose"})
.isVerbose(),
is(true));
assertThat(AgentOptions.parse(new String[] {"--model", "m.gguf", "-v"}).isVerbose(), is(true));
assertThat(AgentOptions.usage(), containsString("--log-verbosity"));
assertThat(AgentOptions.usage(), containsString("--verbose"));
}

@Test
void inProcessModeParsesEveryOption() {
AgentOptions options = AgentOptions.parse(new String[] {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,8 +6,11 @@

import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.containsString;
import static org.hamcrest.Matchers.hasItem;
import static org.hamcrest.Matchers.hasSize;
import static org.hamcrest.Matchers.is;
import static org.hamcrest.Matchers.lessThan;
import static org.hamcrest.Matchers.not;

import com.fasterxml.jackson.databind.JsonNode;
import java.io.ByteArrayOutputStream;
Expand Down Expand Up @@ -145,4 +148,28 @@ void failedTurnExitsNonZero() throws Exception {
assertThat(exit, is(1));
}
}

@Test
void inProcessModelIsLoadedWithAQuietLogThresholdByDefault() {
// llama.cpp prints its per-request INFO lines to stderr, the very console the streamed answer
// goes to; the default threshold has to stay below INFO (3) or the two interleave again.
List<String> args = List.of(LocalAgent.modelParameters(AgentOptions.parse(new String[] {"--model", "m.gguf"}))
.toArray());

assertThat(args, hasItem("--log-verbosity"));
assertThat(
args.get(args.indexOf("--log-verbosity") + 1), is(String.valueOf(AgentOptions.DEFAULT_LOG_VERBOSITY)));
assertThat(AgentOptions.DEFAULT_LOG_VERBOSITY, lessThan(3));
assertThat(args, not(hasItem("--verbose")));
}

@Test
void verboseReplacesTheThresholdWithLlamaCppsOwnVerboseFlag() {
List<String> args = List.of(LocalAgent.modelParameters(
AgentOptions.parse(new String[] {"--model", "m.gguf", "--log-verbosity", "1", "--verbose"}))
.toArray());

assertThat(args, hasItem("--verbose"));
assertThat(args, not(hasItem("--log-verbosity")));
}
}
1 change: 1 addition & 0 deletions llama/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -606,6 +606,7 @@ if(BUILD_TESTING)
src/test/cpp/test_jni_helpers.cpp
src/test/cpp/test_json_helpers.cpp
src/test/cpp/test_log_helpers.cpp
src/test/cpp/test_common_log_callback.cpp
src/test/cpp/test_tts_wav.cpp
src/test/cpp/test_tts_params.cpp
src/test/cpp/test_model_split.cpp
Expand Down
Loading
Loading