search

nix-community / lorri

Your project’s nix-env [maintainer=@Profpatsch,@nyarly]
Apache License 2.0
639 stars 24 forks source link

lorri daemon fails with "No such file or directory (os error 2)", but lorri watch succeeds #90

Open avh4 opened 1 year ago

avh4 commented 1 year ago

Describe the bug

The lorri daemon fails to build my project's environment, saying "No such file or directory (os error 2)" in the logs. But running lorri watch successfully builds it.

To Reproduce Steps to reproduce the behavior:

  1. Start journalctl --user -u lorri.service --no-pager -f to monitor the lorri daemon log
  2. In a separate terminal, cd into the project using lorri
  3. The lorri daemon log shows an error 
    Jul 28 01:12:50 host lorri[358780]: Jul 28 01:12:50.503 INFO build status, message: BuildEvent(Started { nix_file: NixFile(AbsPathBuf("/home/avh4/workspace/music/shell.nix")), reason: PingReceived })
Jul 28 01:12:50 host lorri[358780]: Jul 28 01:12:50.503 INFO build status, message: BuildEvent(Failure { nix_file: NixFile(AbsPathBuf("/home/avh4/workspace/music/shell.nix")), failure: Spawn { cmd: "\"nix-instantiate\" \"-vv\" \"--add-root\" \"/tmp/.tmpedU3ei/result\" \"--indirect\" \"--argstr\" \"runTimeClosure\" \"/nix/store/69pg642v7d9s1z0nb0i3n2jynkmjkd9n-runtime-closure.nix\" \"--argstr\" \"src\" \"/home/avh4/workspace/music/shell.nix\" \"--\" \"/home/avh4/.cache/lorri/cas/de251a4170888ea8b8fb1ece0590735a\"", msg: "No such file or directory (os error 2)" } })
  4. Run lorri watch in the project directory (it succeeds) 
    Jul 28 01:14:59.356 INFO build message, message: BuildEvent(Started { nix_file: NixFile(AbsPathBuf("/home/avh4/workspace/music/shell.nix")), reason: PingReceived }), nix_file: /home/avh4/workspace/music/shell.nix
Jul 28 01:15:04.476 INFO build message, message: BuildEvent(Completed { nix_file: NixFile(AbsPathBuf("/home/avh4/workspace/music/shell.nix")), rooted_output_paths: OutputPath { shell_gc_root: RootPath(AbsPathBuf("/home/avh4/.cache/lorri/gc_roots/96cf60f25c1bca4f0bab7e20322abdeb/gc_root/shell_gc_root")) } }), nix_file: /home/avh4/workspace/music/shell.nix

Expected behavior

The lorri daemon build should succeed.

Metadata

$ lorri info
error: The following required arguments were not provided:
    --shell-file <nix_file>

USAGE:
    lorri info --shell-file <nix_file>

For more information try --help
$ lorri info --shell-file shell.nix 
lorri version: 1.5
GC roots exist, shell_gc_root: /home/avh4/.cache/lorri/gc_roots/96cf60f25c1bca4f0bab7e20322abdeb/gc_root/shell_gc_root
$ uname -a
Linux host 5.15.0-41-generic #44-Ubuntu SMP Wed Jun 22 14:20:53 UTC 2022 x86_64 GNU/Linux

Additional context

After restarting the daemon with systemctl --user restart lorri.service, the result is the same.

Profpatsch commented 1 year ago

Ah, the rust stdlib thing where they don’t give you the file that it tried to access.

Can you strace it to see which file it tried to access?

Profpatsch commented 1 year ago

strace -e trace=%file and probably the last file before the crash, something where the syscall returns -1.

Gastove commented 1 year ago

Hullo! Hitting the same problem. After a lorri self-update, the error is slightly more descriptive; here's systemd logs with RUST_BACKTRACE=full set: 

Jan 20 12:11:39 beignet systemd[1736]: Stopping lorri.service - Lorri Daemon...
Jan 20 12:11:39 beignet systemd[1736]: Stopped lorri.service - Lorri Daemon.
Jan 20 12:11:39 beignet systemd[1736]: Started lorri.service - Lorri Daemon.
Jan 20 12:11:39 beignet lorri[184729]: lorri: ready
Jan 20 12:11:43 beignet lorri[184729]: Started
Jan 20 12:11:43 beignet lorri[184729]: thread '<unnamed>' panicked at 'Unrecoverable error!
Jan 20 12:11:43 beignet lorri[184729]: Build(
Jan 20 12:11:43 beignet lorri[184729]:     Instantiate(
Jan 20 12:11:43 beignet lorri[184729]:         Os {
Jan 20 12:11:43 beignet lorri[184729]:             code: 2,
Jan 20 12:11:43 beignet lorri[184729]:             kind: NotFound,
Jan 20 12:11:43 beignet lorri[184729]:             message: "No such file or directory"
Jan 20 12:11:43 beignet lorri[184729]:         }
Jan 20 12:11:43 beignet lorri[184729]:     )
Jan 20 12:11:43 beignet lorri[184729]: )', src/build_loop.rs:84:56
Jan 20 12:11:43 beignet lorri[184729]: stack backtrace:
Jan 20 12:11:43 beignet lorri[184729]:    0:     0x5653f98ebc1f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::hfad0220813d5e5c3
Jan 20 12:11:43 beignet lorri[184729]:    1:     0x5653f98fc657 - std::sys_common::backtrace::print::h16017ddc8b354e39
Jan 20 12:11:43 beignet lorri[184729]:    2:     0x5653f98ef4c3 - std::panicking::default_hook::{{closure}}::h8b06d3b8a7138cc5
Jan 20 12:11:43 beignet lorri[184729]:    3:     0x5653f98ef243 - std::panicking::default_hook::h8cac4830452b35df
Jan 20 12:11:43 beignet lorri[184729]:    4:     0x5653f98efbbf - std::panicking::rust_panic_with_hook::hd32c26e1600a179b
Jan 20 12:11:43 beignet lorri[184729]:    5:     0x5653f98ef751 - std::panicking::continue_panic_fmt::h24b78f7279f44cef
Jan 20 12:11:43 beignet lorri[184729]:    6:     0x5653f98ef69e - std::panicking::begin_panic_fmt::h98672d172280200e
Jan 20 12:11:43 beignet lorri[184729]:    7:     0x5653f9774566 - lorri::build_loop::BuildLoop::forever::h107a54d9d12e731b
Jan 20 12:11:43 beignet lorri[184729]:    8:     0x5653f9776d73 - std::sys_common::backtrace::__rust_begin_short_backtrace::h6de3911e47385787
Jan 20 12:11:43 beignet lorri[184729]:    9:     0x5653f97859d8 - std::panicking::try::do_call::ha622cd5ff1ae34b0
Jan 20 12:11:43 beignet lorri[184729]:   10:     0x5653f9907499 - __rust_maybe_catch_panic
Jan 20 12:11:43 beignet lorri[184729]:   11:     0x5653f977fa92 - <F as alloc::boxed::FnBox<A>>::call_box::hed14b3946e261b17
Jan 20 12:11:43 beignet lorri[184729]:   12:     0x5653f98ea9ed - std::sys_common::thread::start_thread::h09a6bf95952964d1
Jan 20 12:11:43 beignet lorri[184729]:   13:     0x5653f98f58e5 - std::sys::unix::thread::Thread::new::thread_start::h165ad4e27a9c9315
Jan 20 12:11:43 beignet lorri[184729]:   14:     0x7f9ddbc2aef6 - start_thread
Jan 20 12:11:43 beignet lorri[184729]:   15:     0x7f9ddb93d22e - __GI___clone
Jan 20 12:11:43 beignet lorri[184729]:   16:                0x0 - <unknown>

I dunno if src/build_loop.rs:84:56 helps at all; I'll see if I can't strace lorri too, find an exact missing file.

Gastove commented 1 year ago

Hrm. strace isn't getting me a lot more than has already been reported. Here's with trace=%file:

  54   │ 260545 mkdir("/home/gastove/.cache/lorri/gc_roots/bf6b9439896465a85d1a5ca860f8615d/gc_root", 0777) = -1 EEXIST (File exists)
  55   │ 260545 stat("/home/gastove/.cache/lorri/gc_roots/bf6b9439896465a85d1a5ca860f8615d/gc_root",  <unfinished ...>
  56   │ 260657 +++ exited with 0 +++
  57   │ 260545 <... stat resumed>{st_mode=S_IFDIR|0755, st_size=42, ...}) = 0
  58   │ 260659 openat(AT_FDCWD, "/home/gastove/.cache/lorri/cas/4a06de72ed6a4fe178f4a02ad1d642be", O_WRONLY|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = -1 EEXI
       │ ST (File exists)
  59   │ 260659 mkdir("/tmp/.tmp13Tpyg", 0777)   = 0
  60   │ 260659 openat(AT_FDCWD, "/dev/null", O_RDONLY|O_CLOEXEC) = 11
  61   │ 260661 execve("/usr/local/bin/nix-instantiate", ["nix-instantiate", "-vv", "--add-root", "/tmp/.tmp13Tpyg/result", "--indirect", "--argstr",
       │ "runTimeClosure", "/nix/store/1manqjxzqpriw9hq5lfqlc6pgdwfmgbh-runtime-closure.nix", "--argstr", "src", "/home/gastove/Code/groupie/shell.nix
       │ ", "--", "/home/gastove/.cache/lorri/cas/4a06de72ed6a4fe178f4a02ad1d642be"], 0x564d4e3da990 /* 36 vars */) = -1 ENOENT (No such file or direc
       │ tory)
  62   │ 260661 execve("/usr/local/sbin/nix-instantiate", ["nix-instantiate", "-vv", "--add-root", "/tmp/.tmp13Tpyg/result", "--indirect", "--argstr",
       │  "runTimeClosure", "/nix/store/1manqjxzqpriw9hq5lfqlc6pgdwfmgbh-runtime-closure.nix", "--argstr", "src", "/home/gastove/Code/groupie/shell.ni
       │ x", "--", "/home/gastove/.cache/lorri/cas/4a06de72ed6a4fe178f4a02ad1d642be"], 0x564d4e3da990 /* 36 vars */) = -1 ENOENT (No such file or dire
       │ ctory)
  63   │ 260661 execve("/usr/bin/nix-instantiate", ["nix-instantiate", "-vv", "--add-root", "/tmp/.tmp13Tpyg/result", "--indirect", "--argstr", "runTi
       │ meClosure", "/nix/store/1manqjxzqpriw9hq5lfqlc6pgdwfmgbh-runtime-closure.nix", "--argstr", "src", "/home/gastove/Code/groupie/shell.nix", "--
       │ ", "/home/gastove/.cache/lorri/cas/4a06de72ed6a4fe178f4a02ad1d642be"], 0x564d4e3da990 /* 36 vars */) = -1 ENOENT (No such file or directory)
  64   │ 260661 execve("/usr/sbin/nix-instantiate", ["nix-instantiate", "-vv", "--add-root", "/tmp/.tmp13Tpyg/result", "--indirect", "--argstr", "runT
       │ imeClosure", "/nix/store/1manqjxzqpriw9hq5lfqlc6pgdwfmgbh-runtime-closure.nix", "--argstr", "src", "/home/gastove/Code/groupie/shell.nix", "-
       │ -", "/home/gastove/.cache/lorri/cas/4a06de72ed6a4fe178f4a02ad1d642be"], 0x564d4e3da990 /* 36 vars */) = -1 ENOENT (No such file or directory)
  65   │ 260661 +++ exited with 127 +++

If you've got moer/other/different flags I can run with, very happy to!

For reference: