feat: add env_logger

[olebedev]

Hi there 👋
First I want to say thank you for such a good project, this is a big deal when we talk about extensive use of nix shells.

Currently, the executable prints something like:

cached-nix-shell: updating cache
cached-nix-shell: done in 8.912511625s

And an interactive shell session being restored in macOS, which the system-wide bash will let users know. It looks like:

Restore session: ...

Saving session...
...copying shared history...
...saving history...truncating history files...
...completed.

Which defers from the original behavior.

Motivation

To make the cached-nix-shell a full drop-in-replacement it requires that all the standard errors, outputs and inputs are equivalent to the original program.

In this PR

I intended to put the cached-nix-shell specific logging into stderr, as well as any other logging, behind an environment variable so by default it doesn't add anything extra. But it's still possible to print that information when needed by exporting CNS_LOG_LEVEL=trace, for example. In this PR I introduce a standardized way to for logging.

---

To make this a true drop-in-replacement more work is needed in make the cached-nix-shell bound to dependencies coming from /nix/store instead of exploring users' environment, like is done here.

Happy to chat about implementation details, about the approach in general and update my changes if we decided to, please let me know what do you think!

Kind regards,
Oleg

cc @fwouts, @uri-canva

[xzfc]

Which defers from the original behavior.

The nix-shell itself is not silent by default e.g., it prints to stderr during building or fetching paths from the internet.

However, I see that you might want not to see these messages.
Would supporting --quiet / --verbose options in CNS (with the same semantics as in the nix-shell) solve your case?
I.e., keep the "updating cache" message by default, but suppress them if the --quiet option is given.

[xzfc]

cached-nix-shell --version should not hide its version by default as it would confuse the user.
Also, since the original nix-shell --version prints its version to stdout (not stderr), CNS should too.

[olebedev]

Agreed. I think hiding/swallowing something, version for example or any other useful information is not great, 100%.

However, the intention of the PR is to hide everything that confuse tooling/scripting around automatic nix/nix-shell invocations, not humans. So I would like to tap on this one a bit more if you don't mind :)

In particular, printing anything extra into stdout (not stderr) can have consequences like some tooling can fail due to an unexpected output, like three lines instead of one, like in this example. So the output is unrecognizable by tools if we replace vanilla nix-shell with the cached one.

Another thing that worries me is that the output for nix-store --version and nix-shell --version should be different in case if we decide to print it, right? Because nix-store has nothing to do with cached-nix-shell. So we kind of introduce a divergence that we would rather avoid.

cached-nix-shell --version should not hide its version by default as it would confuse the user.

What do you mean, a user will be confused with which tool nix-shell or cached-nix-shell is actually in use or the versions combination is important?

I think we can reach consensus here by set CNS_LOG_LEVEL=trace by default via Env::filter_or so the output is actually what it was before, but with slightly different formatting, due to the env_logger library use. This would allow to switch all the logs related to cached nix shell by setting CNS_LOG_LEVEL= which it a bit unfortunate for me but I am fine with that option if this sounds to you like something more appropriate.

Let me know what do you think about this.

In the meantime, I redone that so it prints to stdout (in case of --version argument only) and all the logging is still in place by default but can be turned off with CNS_LOG_LEVEL= or downgrade the logging level like CNS_LOG_LEVEL=info, please have a look.

Kind regards,
Oleg

[xzfc]

I do not consider this an error. It is printed when the cache is invalidated (file is changed), which may happen during normal operation.

[olebedev]

Yeah, me neither, I just made it as close to how it was done. Happy to swap over to any level that is less critical that error. Does the info look appropriate to you?

[olebedev]

Changed to info. Let me know if you unhappy with that so I can change it to something else :)

[xzfc]

To make this a true drop-in-replacement more work is needed in make the cached-nix-shell bound to dependencies coming from /nix/store instead of exploring users' environment, like is done here.

Yes, pinning $PATH to /nix/store paths would be helpful to reduce cache misses.

However, I'm not sure how it's related to "true drop-in-replacement" since the nix-shell itself uses these dependencies from the environment, and what CNS does is remove everything from the $PATH except things that nix-shell uses.
E.g., if we remove git from the $PATH, then the upstream nix-shell would fail.

$ rm -rf ~/.cache/nix
$ PATH= $(which nix-shell) -p 'import (fetchGit https://github.com/xzfc/cached-nix-shell) {}'
error: executing 'git': No such file or directory
warning: could not read HEAD ref from repo at 'https://github.com/xzfc/cached-nix-shell', using 'master'
error: executing 'git': No such file or directory
error:
       … while calling the 'derivationStrict' builtin

         at /builtin/derivation.nix:9:12: (source not available)

       … while evaluating derivation 'shell'
         whose name attribute is located at /nix/store/n3hlkkgv04bfikw5kxc1694spmg1rjih-nixos/nixos/pkgs/stdenv/generic/make-derivation.nix:348:7

       … while evaluating attribute 'buildInputs' of derivation 'shell'

         at /nix/store/n3hlkkgv04bfikw5kxc1694spmg1rjih-nixos/nixos/pkgs/stdenv/generic/make-derivation.nix:395:7:

          394|       depsHostHost                = elemAt (elemAt dependencies 1) 0;
          395|       buildInputs                 = elemAt (elemAt dependencies 1) 1;
             |       ^
          396|       depsTargetTarget            = elemAt (elemAt dependencies 2) 0;

       error: program 'git' failed with exit code 1

[olebedev]

However, I'm not sure how it's related to "true drop-in-replacement" since the nix-shell itself uses these dependencies from the environment, and what CNS does is remove everything from the $PATH except things that nix-shell uses.
E.g., if we remove git from the $PATH, then the upstream nix-shell would fail.

Ah, yeah, you're right. Nix depends on system-wide git. By "true drop-in-replacement" I mean make the tool behave and print outputs similar to what would vanilla nix-shell do. But it's obviously not totally possible and not even needed, for example in case of some unpinned dependencies. Also, if we don't evaluate expressions all the time we also missing a lot of similarity with the vanilla nix-shell and this is totally fine!

I don't want to replicate everything but rather do my best to make the cached-nix-shell be a a tool that I can seamlessly switch to and see that most (all 🙏) of our workflows at @Canva won't fail and benefit from caching. We have a quite huge use of nix shells so it's important to have a tool that does the caching magic as this one along with mimic to the vanilla behavior up to certain extent but not totally :)

[olebedev]

Would supporting --quiet / --verbose options in CNS (with the same semantics as in the nix-shell) solve your case?
I.e., keep the "updating cache" message by default, but suppress them if the --quiet option is given.

An explicit CLI argument wouldn't help much since it requires changes to entire codebase to respect that so the codebase become incompatible with the vanilla nix-shell which I don't won't to do. Also, we have cases where we use nested nix shells. In this case we would want to propagate the option all the way down to the depth, which is not quite possible without code change at the only top level.

I would rather go with an env var to reach similar behaviour as you propose. That sounds good to me as a starting point, so I made the change that doesn't suppress the messages and they ar eprinted as they were before the change, but now I can disable them by setting CNS_LOG_LEVEL=, which is not ideal but pretty much acceptable for my use case.

[olebedev]

The nix-shell itself is not silent by default e.g., it prints to stderr during building or fetching paths from the internet.

100%, as long as I capture stderr and stdout it's crucial for me to keep the output similar to what the nix-shell itself produces so the tooling around it can survive substitution of nix-shell with cached-nix-shell.

[olebedev]

Hey @xzfc, any chance you can have another look at this work?