nix develop does not print output in GitLab CI

[mschwaig]

Describe the bug

I'm trying to use the new nix command in CI.

If I run nix develop nixpkgs#tree --command tree locally, it produces the following output

warning: unknown setting 'extra-sandbox-paths'
.

0 directories, 0 files

If i run the same thing in a GitLab CI Runner, it produces the following output

Running with gitlab-runner 13.5.0 (v13.5.0)
  on shell_nixos-gitlab-runner_6a9b50e2300a 9YssniSh
Preparing the "shell" executor
00:00
Using Shell executor...
Preparing environment
00:00
Running on nixos-gitlab-runner...
Getting source from Git repository
00:01
Fetching changes with git depth set to 50...
Initialized empty Git repository in /var/lib/private/gitlab-runner/builds/9YssniSh/0/mschwaig/gitlab_ci_output_test_flake/.git/
Created fresh repository.
Checking out f477a4b2 as try_nix-host_runner...
Skipping Git submodules setup
Executing "step_script" stage of the job script
00:10
$ nix develop nixpkgs#tree --command tree
warning: unknown setting 'extra-sandbox-paths'
Cleaning up file based variables
00:00
Job succeeded

So there is no output from the actual nix develop command.

I ran into this when running actual cargo and python tests via nix develop so it's not specific to the tree command. I just could not think of a better minimal example.

Steps To Reproduce

I have published a repo with an assigned CI Runner that produces this error. You can take a look at that repo and the output CI pipline in GitLab.

The runner I'm using is a NixOS based GitLab Runner that I have set up in the cloud. The builds I originally ran were run on a completely different host, but I could reproduce it with my own Runner, so I think you should be able to too.

I am happy to try out a few suggested modifications or provide access to my setup. Here is the config for the runner.

Expected behavior

Same output to the terminal in CI as well as I got when running locally.

Additional context

I have created a few different kinds of Runners wit the GitLab Runner module in nixpkgs. Each branch in my repo uses a different kind of runner, but the all run into the same issue.

I never got any output from cargo. Python would at least give me some output when the a builder failed, like so:

$ nix develop --impure --command python3 -m pytest
trace: 
applying fix 'rm-tensorboard' (postInstall) for tensorflow:2.3.1
error: --- Error --- nix
builder for '/nix/store/mq7k3i10f994c8kn1alrnwaw97sjac1r-python3.8-tensorflow-2.3.1.drv' failed with exit code 1; last 10 log lines:
  configuring
  no configure script, doing nothing
  building
  no Makefile, doing nothing
  installing
  Executing pipInstallPhase
  /tmp/nix-build-python3.8-tensorflow-2.3.1.drv-0/dist /tmp/nix-build-python3.8-tensorflow-2.3.1.drv-0
  Processing ./tensorflow-2.3.1-cp38-cp38-manylinux2010_x86_64.whl
  ERROR: Could not install packages due to an EnvironmentError: [Errno 28] No space left on device
  
error: --- Error --- nix
1 dependencies of derivation '/nix/store/q9d3m5qcc8cvdvx8v0d76c1pjkc64cs2-python3-3.8.5-env.drv' failed to build
error: --- Error --- nix
1 dependencies of derivation '/nix/store/b6wh8bjqvgkq7dmkpfig8zr49gjg205s-mach-nix-python-env.drv' failed to build
error: --- Error --- nix
1 dependencies of derivation '/nix/store/ndqk2jg1xhvjv3qnq791mlk7kx9rp0xd-mach-nix-python-shell-env.drv' failed to build
ERROR: Job failed: exit code 100

Additinally for the python build the

trace: 
applying fix 'rm-tensorboard' (postInstall) for tensorflow:2.3.1

lines were always present. This is something that mach-nix prints.

My suspicion

It looks like there is just no output from the actual execution. Since locally nix develop redraws lines while it's downloading I suspect that might cause the issue if there is no graceful fallback for a less capable terminal.

One thing I tried was setting $TERM to ansi or dumb, but that did not help and I don't know enough about terminals to know what else to try, or how to try and confirm that suspicion without the GitLab Runner.

[expipiplus1]

Similarly, command nix copy don't generate any output. It would be nice if there was a flag/detection to get them to output regular lines to stdout/stderr instead of the very nice interactive terminal behavior they have currently.

[mschwaig]

Maybe what's described in #4234 is the underlying issue here. 👀

[thufschmitt]

Technically you can switch to the “old” logging format by passing --log-format raw. The issue with this and nix copy is that strictly speaking it doesn't log anything but just sends some commands to update the status bar

[mschwaig]

I don't really understand the problem I'm having well, so I am not sure if you are addressing me, @regnat.

I did try switching the log format on the weekend and that did not change anything as you can see from the pipeline run that is linked there.

[thufschmitt]

I don't really understand the problem I'm having well, so I am not sure if you are addressing me, @regnat.

Oh sorry, I was actually answering @expipiplus1's comment. And it's probably unrelated to your own issue.

As for your issue, I think your usage of nix develop is wrong as nix develop nixpkgs#tree will drop you into a shell with the dependencies of tree in scope (and not tree itself). It might not be the whole issue, but probably wanted nix shell here.

(I also don't think it's related to #4234 because the gitlab runner isn't using a Nix daemon − besides the output of the tree command shouldn't happen client-side)

[mschwaig]

As for your issue, I think your usage of nix develop is wrong as nix develop nixpkgs#tree will drop you into a shell with the dependencies of tree in scope (and not tree itself). It might not be the whole issue, but probably wanted nix shell here.

You're right, thanks. I made that mistake when trying to come up with a simple example to reproduce my issue. nix shell --command in fact gives output there.

Still I think nix develop --command should return the output of the invoked command in CI in the same way and that does as expected locally. I will try to come up with a better example.

[thufschmitt]

Still I think nix develop --command should return the output of the invoked command in CI in the same way and that does as expected locally

Yup', I totally agree. And there's indeed something strange going on with the stderr of nix develop:

$ nix develop nixpkgs#hello --command make
warning: unknown setting 'extra-sandbox-paths'
make: *** No targets specified and no makefile found.  Stop.
$ nix develop nixpkgs#hello --command make |& cat
warning: unknown setting 'extra-sandbox-paths'
**hangs**

I looked at this a bit, and what I think happens is that nix develop --command foo eventually runs bash --rcfile <some_generated_file>, where <some_generated_file> ends up with exec foo.
But (although that's not utterly clear from the docs), bash doesn't load the rc file if it's started as a non-interactive shell, which is the case if stderr points to to something that's not a terminal. This is the case in the example above and probably in your CI too.

I guess this could be fixed either by passing -i to force it to be interactive or by using another mechanism to load the environment and execute the command

[thufschmitt]

This might actually be fixed by #4233

[chshersh]

I found this issue when nix develop was constantly being killed on Circle CI after not producing any output for 10 minutes:

error: interrupted by the user

Too long with no output (exceeded 10m0s): context deadline exceeded

I went searching for answers and this issue seemed the most relevant. In case anyone happens to be here while facing the same problem, adding the --print-build-logs flag actually solved the problem for me.

Full command in my case:

nix develop .#my-backend --print-build-logs --profile cabal-shell --command true