Netcat under bash does not exit properly (blocks instead of exiting) #3558
Description
When running netcat under bash in shadow, the process never exits and appears to get stuck on a poll syscall.
general:
stop_time: 30s
experimental:
strace_logging_mode: standard
network:
graph:
type: gml
inline: |
graph [
directed 0
node [
id 0
host_bandwidth_down "1 Gbit"
host_bandwidth_up "1 Gbit"
]
edge [
source 0
target 0
latency "50 ms"
]
]
hosts:
server:
network_node_id: 0
ip_addr: 1.2.3.4
processes:
- path: nc
args: -l -k 8080
expected_final_state: running
client:
network_node_id: 0
processes:
- path: bash
args:
- -c
- echo "foo" | nc -q 0 1.2.3.4 8080
start_time: 2s
expected_final_state: { exited: 0 }$ shadow shadow.yaml > shadow.log
** Starting Shadow 3.2.0
Error: process 'client.bash.1000' exited with status StoppedByShadow; expected end state was exited: 0 but was running
Error: Failed to run the simulation
Error:
Error: Caused by:
Error: 1 managed processes in unexpected final state
** Shadow did not complete successfully: Failed to run the simulation
** 1 managed processes in unexpected final state
** See the log for details
$ cat shadow.data/hosts/server/nc.openbsd.1000.stdout
foo
$ tail shadow.data/hosts/client/bash.1000.strace
00:00:02.100000000 [tid 1002] pselect6(4, 0x0, 0x7ffc9b303730, 0x0, 0x0 <null>, 0x0) = 1
00:00:02.100000000 [tid 1002] getsockopt(3, 1, 4, 0x7ffc9b3036ec, 4 (0x7ffc9b3036f8)) = 0
00:00:02.100000000 [tid 1002] fcntl(3, 4, 2050) = 0
00:00:02.100000000 [tid 1002] poll(0x7ffc9b2fb7b0, 4, -1) = 1
00:00:02.100000000 [tid 1002] read(0, 0x7ffc9b2fb7e0, 16384) = 4
00:00:02.100000000 [tid 1002] poll(0x7ffc9b2fb7b0, 4, -1) = 2
00:00:02.100000000 [tid 1002] read(0, 0x7ffc9b2fb7e4, 16380) = 0
00:00:02.100000000 [tid 1002] write(3, "foo\n", 4) = 4
00:00:02.100000000 [tid 1002] shutdown(3, 1) = 0
00:00:02.100000000 [tid 1002] poll(0x7ffc9b2fb7b0, 4, -1) = <blocked>
$ tail shadow.data/hosts/server/nc.openbsd.1000.strace
00:00:00.000000000 [tid 1000] bind(3, 0.0.0.0:8080, 16) = 0
00:00:00.000000000 [tid 1000] listen(3, 1) = 0
00:00:00.000000000 [tid 1000] accept4(3, 0x7fff4308ae40, 128 (0x7fff4308ad80), 2048) = <blocked>
00:00:02.150000000 [tid 1000] accept4(3, 0x7fff4308ae40, 16 (0x7fff4308ad80), 2048) = 4
00:00:02.150000000 [tid 1000] poll(0x7fff43082c10, 4, -1) = 2
00:00:02.150000000 [tid 1000] read(0, 0x7fff43082c40, 16384) = 0
00:00:02.150000000 [tid 1000] read(4, 0x7fff43086c40, 16384) = 4
00:00:02.150000000 [tid 1000] poll(0x7fff43082c10, 4, -1) = 1
00:00:02.150000000 [tid 1000] write(1, "foo\n", 4) = 4
00:00:02.150000000 [tid 1000] poll(0x7fff43082c10, 4, -1) = <blocked>
$ strace nc -l -k 8080 </dev/null
[...]
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(3, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
bind(3, {sa_family=AF_INET, sin_port=htons(8080), sin_addr=inet_addr("0.0.0.0")}, 16) = 0
listen(3, 1) = 0
accept4(3, {sa_family=AF_INET, sin_port=htons(42918), sin_addr=inet_addr("127.0.0.1")}, [128 => 16], SOCK_NONBLOCK) = 4
poll([{fd=0, events=POLLIN}, {fd=4, events=0}, {fd=4, events=POLLIN}, {fd=1, events=0}], 4, -1) = 1 ([{fd=0, revents=POLLIN}])
read(0, "", 16384) = 0
poll([{fd=-1}, {fd=-1}, {fd=4, events=POLLIN}, {fd=1, events=0}], 4, -1) = 1 ([{fd=4, revents=POLLIN}])
read(4, "foo\n", 16384) = 4
poll([{fd=-1}, {fd=-1}, {fd=4, events=POLLIN}, {fd=1, events=POLLOUT}], 4, -1) = 2 ([{fd=4, revents=POLLIN}, {fd=1, revents=POLLOUT}])
read(4, "", 16380) = 0
shutdown(4, SHUT_RD) = 0
write(1, "foo\n", 4foo
) = 4
close(4) = 0
accept4(3,
$ strace -f bash -c 'echo "foo" | nc -q 0 127.0.0.1 8080'
[...]
[pid 36205] socket(AF_INET, SOCK_STREAM|SOCK_NONBLOCK, IPPROTO_TCP) = 3
[pid 36205] fcntl(3, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 36205] fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 36205] connect(3, {sa_family=AF_INET, sin_port=htons(8080), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress)
[pid 36205] pselect6(4, NULL, [3], NULL, NULL, NULL) = 1 (out [3])
[pid 36205] getsockopt(3, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
[pid 36205] fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 36205] poll([{fd=0, events=POLLIN}, {fd=3, events=0}, {fd=3, events=POLLIN}, {fd=1, events=0}], 4, -1) = 1 ([{fd=0, revents=POLLIN|POLLHUP}])
[pid 36205] read(0, "foo\n", 16384) = 4
[pid 36205] poll([{fd=0, events=POLLIN}, {fd=3, events=POLLOUT}, {fd=3, events=POLLIN}, {fd=1, events=0}], 4, -1) = 2 ([{fd=0, revents=POLLHUP}, {fd=3, revents=POLLOUT}])
[pid 36205] write(3, "foo\n", 4) = 4
[pid 36205] shutdown(3, SHUT_WR) = 0
[pid 36205] poll([{fd=-1}, {fd=-1}, {fd=3, events=POLLIN}, {fd=1, events=0}], 4, -1) = 1 ([{fd=3, revents=POLLIN|POLLHUP}])
[pid 36205] read(3, "", 16384) = 0
[pid 36205] shutdown(3, SHUT_RD) = -1 ENOTCONN (Transport endpoint is not connected)
[pid 36205] close(3) = 0
[pid 36205] exit_group(0) = ?
[pid 36205] +++ exited with 0 +++
<... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 36205
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7eff23d92250}, {sa_handler=0x55fd6c1c6dd0, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7eff23d92250}, 8) = 0
ioctl(2, TIOCGWINSZ, {ws_row=54, ws_col=286, ws_xpixel=32604, ws_ypixel=1728}) = 0
rt_sigprocmask(SIG_SETMASK, [CHLD], NULL, 8) = 0
close(3) = -1 EBADF (Bad file descriptor)
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=36204, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, 0x7fffb1da7b50, WNOHANG, NULL) = -1 ECHILD (No child processes)
rt_sigreturn({mask=[]}) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
exit_group(0) = ?
+++ exited with 0 +++
$ uname -a
Linux 1e8a16ae6aff 6.13.7-100.fc40.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Mar 13 17:45:36 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux
$ shadow --version
Shadow 3.2.0 — v3.2.0-426-gecaa42d65 2025-04-06--20:09:27
Running on an ubuntu 24.10 container.