facebookexperimental / facebookexperimental/hermit
warnings while running bash (or programs with line editing)
- Dominant language
- Rust
- Stars
- 1.4k
- Forks
- 50
- PR merge metrics
- No merged PRs in 30d
Description
**Describe the bug**
hermit prints large amounts of debugging output about "Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.".
**To Reproduce**
First, fix reverie with https://github.com/samth/reverie/commit/a7f6cae58c8dbdedb1708ff2d12dc76cffaa4c69 to run under current ubuntu.
Then, run `hermit run /bin/bash`. The output is below. Note the running `/bin/bash -c ls` produces no warnings, so I think the problem is with `readline`. Testing other programs that also support line editing suggests this as well.
```
[samth@huor:~/tmp/hermit (main) plt] ./target/debug/hermit run /bin/bash
2022-11-23T17:25:14.690407Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.692529Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.748850Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.750980Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.812312Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.814456Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.857796Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.859945Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.869533Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.871786Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.939757Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(19)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.968010Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.969855Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.978599Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.980856Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.989715Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:14.991932Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.000958Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.003443Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.012902Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.015336Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.025019Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.027279Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.057962Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.059981Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.093697Z ERROR detcore::syscalls::threads: sched_getaffinity: Not expecting request for more than 1024 byte cpu mask, actual was 8192 bytes
fatal error: sigaction failed
runtime stack:
runtime.throw(0x6fa2ca, 0x10)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/panic.go:1117 +0x72
runtime.sysSigaction.func1()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:488 +0x36
runtime.sysSigaction(0x10, 0x0, 0x7fffffffe1d8)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:487 +0x6c
runtime.sigaction(0x7fff00000010, 0x0, 0x7fffffffe1d8)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/cgo_sigaction.go:75 +0xd5
runtime.getsig(0x10, 0x44d2a0)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:456 +0x3a
runtime.initsig(0x7fff00000000)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/signal_unix.go:131 +0x68
runtime.mstartm0()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1330 +0x38
runtime.mstart1()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1302 +0xdb
runtime.mstart()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1272 +0x6e
goroutine 1 [runnable]:
runtime.main()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:115
runtime.goexit()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/asm_amd64.s:1371 +0x1
2022-11-23T17:25:15.137348Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.171460Z ERROR detcore::syscalls::threads: sched_getaffinity: Not expecting request for more than 1024 byte cpu mask, actual was 8192 bytes
fatal error: sigaction failed
runtime stack:
runtime.throw(0x6fa2ca, 0x10)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/panic.go:1117 +0x72
runtime.sysSigaction.func1()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:488 +0x36
runtime.sysSigaction(0x10, 0x0, 0x7fffffffe1d8)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:487 +0x6c
runtime.sigaction(0x7fff00000010, 0x0, 0x7fffffffe1d8)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/cgo_sigaction.go:75 +0xd5
runtime.getsig(0x10, 0x44d2a0)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:456 +0x3a
runtime.initsig(0x7fff00000000)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/signal_unix.go:131 +0x68
runtime.mstartm0()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1330 +0x38
runtime.mstart1()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1302 +0xdb
runtime.mstart()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1272 +0x6e
goroutine 1 [runnable]:
runtime.main()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:115
runtime.goexit()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/asm_amd64.s:1371 +0x1
2022-11-23T17:25:15.214560Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.366470Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.368761Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.432993Z ERROR detcore::syscalls::threads: sched_getaffinity: Not expecting request for more than 1024 byte cpu mask, actual was 8192 bytes
fatal error: sigaction failed
runtime stack:
runtime.throw(0x50ed23, 0x10)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/panic.go:1117 +0x72
2022-11-23T17:25:15.453879Z ERROR detcore::syscalls::threads: sched_getaffinity: Not expecting request for more than 1024 byte cpu mask, actual was 8192 bytes
runtime.sysSigaction.func1()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go2022-11-23T17:25:15.477802Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
:488 +0x36
runtime.sysSigaction(0x10, 0x0, 0x7fffffffe1e8)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:487 +0x6c
runtime.sigaction(0x7fff00000010, 0x0, 0x7fffffffe1e8)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/cgo_sigaction.go:75 +0xd5
runtime.getsig(0x10, 0x449c80)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/os_linux.go:456 +0x3a
runtime.initsig(0x7fff00000000)
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/signal_unix.go:131 +0x68
runtime.mstartm0()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1330 +0x38
runtime.mstart1()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1302 +0xdb
runtime.mstart()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:1272 +0x6e
goroutine 1 [runnable]:
runtime.main()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/proc.go:115
runtime.goexit()
/opt/hostedtoolcache/go/1.16.10/x64/src/runtime/asm_amd64.s:1371 +0x1
2022-11-23T17:25:15.510119Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.547140Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (3 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.550521Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.663525Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.714734Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(65)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.715459Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(65)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.716437Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.719841Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.797015Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(71)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.826331Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.828562Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.859544Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.861853Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.915452Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.918893Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.976242Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (2 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.979484Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.989958Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:15.992247Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.066235Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(87)] jumped in the middle of runnable work (3 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.068727Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(87)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.113414Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(87)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.118293Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.120409Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.150599Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
2022-11-23T17:25:16.151543Z WARN detcore::scheduler: Nondeterministic external actions [DetPid(3)] jumped in the middle of runnable work (1 tasks). Need to record this for reproducibility.
[root@hermetic-container:~/tmp/hermit (main) plt]
exit
```
**Environment**
- [x] Linux kernel version (`uname -a`): `Linux huor 5.19.0-23-generic #24-Ubuntu SMP PREEMPT_DYNAMIC Fri Oct 14 15:39:57 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux`
- [x] Linux distro flavor (`/etc/issue`, `/etc/redhat-release`): `Ubuntu 22.10`
**Additional context**
Attach the logs to this issue as a text file generated by `hermit --log=trace --log-file=log.txt run`.
Add any other context about the problem here.
[log.txt.gz](https://github.com/facebookexperimental/hermit/files/10077874/log.txt.gz)
Contributor guide
Assessment
This issue has not been assessed yet.