TunnelLogger never reports ->isVerbose() == true #1124

Open
opened 2026-02-08 11:43:16 +00:00 by sterni · 2 comments

Describe the bug

Every logger has a isVerbose() method which is (as far as I can tell) used for determining whether to print the last 20 or so log lines when a build fails. The idea is to not print any log output if Nix has already been printing them as they happen which I agree with (it is pretty annoying if the issue is not apparent in the 20 log lines and you have scroll up the same 20 lines again since they were printed twice).

if (!logger->isVerbose() && !logTail.empty()) {
msg += fmt(";\nlast %d log lines:\n", logTail.size());
for (auto & line : logTail) {
msg += "> ";
msg += line;
msg += "\n";
}
auto nixLogCommand =
experimentalFeatureSettings.isEnabled(Xp::NixCommand) ? "nix log" : "nix-store -l";
msg +=
fmt("For full logs, run:\n\t" ANSI_BOLD "%s %s" ANSI_NORMAL "",
nixLogCommand,
worker.store.printStorePath(drvPath));
}

The issue turns out to be the following: The default method for Logger reports false always. SimpleLogger changes this and returns printBuildLogs which is what we want. Hence, everything works as expected when using Nix in single user mode / opening the store directly.

When using the daemon, buildErrorContents is executed by the daemon which uses TunnelLogger instead of SimpleLogger for obvious reasons. That one doesn't implement a custom isVerbose() method.

Proposed solution

Unfortunately, the daemon does not seem to know whether the client wants to print logs or not at the moment. Given that isVerbose() only seems to control this aspect of the whole machinery, my proposal would be the following:

  • Rename isVerbose() to doesPrintBuildLogs or something.
  • Make printBuildLogs a proper client setting and report it to the daemon, so it can actually properly use that information.

I'd be happy to implement that myself (I've already been trying at it), but wanted to hear some opinions on this first. I may be missing something since how this all works is pretty weird. I also get the impression that the whole way logging is weird up could use some refactoring, so maybe there are already some plans in place for that?

Steps To Reproduce

  • Build a failing build with log output using the daemon with nix-build or using --log-format raw. You'll see the last 20 log lines being printed
  • Run the same command, but open the store directly, e.g. sudo <command> --store /. You'll see everything working as expected.

nix --version output

Happens on main

## Describe the bug Every `logger` has a `isVerbose()` method which is (as far as I can tell) used for determining whether to print the last 20 or so log lines when a build fails. The idea is to not print any log output if Nix has already been printing them as they happen which I agree with (it is pretty annoying if the issue is not apparent in the 20 log lines and you have scroll up the same 20 lines again since they were printed twice). https://git.lix.systems/lix-project/lix/src/commit/e9cccd47e216f0b90d68e471162a651176feb5b4/lix/libstore/build/derivation-goal.cc#L918-L931 The issue turns out to be the following: The default method for `Logger` reports `false` always. `SimpleLogger` changes this and returns `printBuildLogs` which is what we want. Hence, everything works as expected when using Nix in single user mode / opening the store directly. When using the daemon, `buildErrorContents` is executed by the daemon which uses `TunnelLogger` instead of `SimpleLogger` for obvious reasons. That one doesn't implement a custom `isVerbose()` method. ## Proposed solution Unfortunately, the daemon does not seem to know whether the client wants to print logs or not at the moment. Given that `isVerbose()` only seems to control this aspect of the whole machinery, my proposal would be the following: - Rename `isVerbose()` to `doesPrintBuildLogs` or something. - Make `printBuildLogs` a proper client setting and report it to the daemon, so it can actually properly use that information. I'd be happy to implement that myself (I've already been trying at it), but wanted to hear some opinions on this first. I may be missing something since how this all works is pretty weird. I also get the impression that the whole way logging is weird up could use some refactoring, so maybe there are already some plans in place for that? ## Steps To Reproduce - Build a failing build with log output using the daemon with `nix-build` or using `--log-format raw`. You'll see the last 20 log lines being printed - Run the same command, but open the store directly, e.g. `sudo <command> --store /`. You'll see everything working as expected. ## `nix --version` output Happens on `main`
Owner

there's a cl for this here. we don't agree that this is a good idea because the last n lines are only truly duplicated if no other derivations were being built and producing output at the time; this is not a huge issue for the nix3 cli (since each log line is prefixed with the derivation name), but the nix2 cli does suffer greatly. for this reason we also think that the code you quoted is actually wrong and should not be inspecting isVerbose to print the log tail but do it for all failures :/

there's a cl for this [here](https://gerrit.lix.systems/c/lix/+/4823). we don't agree that this is a good idea because the last n lines are only *truly* duplicated if no other derivations were being built and producing output at the time; this is not a huge issue for the nix3 cli (since each log line is prefixed with the derivation name), but the nix2 cli does suffer greatly. for this reason we also think that the code you quoted is actually wrong and should *not* be inspecting `isVerbose` to print the log tail but do it for all failures :/
Member

This issue was mentioned on Gerrit on the following CLs:

  • comment in cl/4823 ("libmain: fix double logs on daemon builds")
<!-- GERRIT_LINKBOT: {"cls": [{"backlink": "https://gerrit.lix.systems/c/lix/+/4823", "number": 4823, "kind": "comment"}], "cl_meta": {"4823": {"change_title": "libmain: fix double logs on daemon builds"}}} --> This issue was mentioned on Gerrit on the following CLs: * comment in [cl/4823](https://gerrit.lix.systems/c/lix/+/4823) ("libmain: fix double logs on daemon builds")
Sign in to join this conversation.
No milestone
No project
No assignees
3 participants
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
lix-project/lix#1124
No description provided.