test: SIGABRT/crash caused by ASSERT in tcp4_echo_server when running the tcp_shutdown_after_write test
- Platform: Linux Mint 22.3, x86_64
- libuv version: v1.x latest, 1.52.1
After running cmake's ctest (which passed without any errors) I noticed a crash reported for uv_run_test's tcp4_echo_server process during the tcp_shutdown_after_write test. I was able to reproduce this by running the tcp4_echo_server process manually (e.g. ./uv_run_tests tcp_shutdown_after_write tcp4_echo_server under a debugger, then running the test (./tcp_shutdown_after_write tcp_shutdown_after_write). The crash pointed to an ASSERT triggering in the tcp4_echo_server's after_shutdown() callback:
+run tcp_shutdown_after_write tcp4_echo_server
Starting program: /home/ptlomholt/dev/libuv/ptlomholt/libuv/build/uv_run_tests tcp_shutdown_after_write tcp4_echo_server
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Program received signal SIGABRT, Aborted.
__pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:44
warning: 44 ./nptl/pthread_kill.c: No such file or directory
+bt
#0 __pthread_kill_implementation (no_tid=0, signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:44
#1 __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78
#2 __GI___pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3 0x00007ffff7c4527e in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4 0x00007ffff7c288ff in __GI_abort () at ./stdlib/abort.c:79
#5 0x0000555555569ce7 in after_shutdown (req=0x5555565dc690, status=-107) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/test/echo-server.c:68
#6 0x00007ffff7f9cdb1 in uv__drain (stream=0x5555565dc590) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/src/unix/stream.c:656
#7 0x00007ffff7f9e2e3 in uv__stream_io (loop=0x7ffff7fbbbc0 <default_loop_struct>, w=0x5555565dc618, events=25) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/src/unix/stream.c:1238
#8 0x00007ffff7f8b73d in uv__io_cb (loop=0x7ffff7fbbbc0 <default_loop_struct>, w=0x5555565dc618, events=25) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/src/unix/core.c:930
#9 0x00007ffff7fa9152 in uv__io_poll (loop=0x7ffff7fbbbc0 <default_loop_struct>, timeout=-1) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/src/unix/linux.c:1546
#10 0x00007ffff7f8ab8a in uv_run (loop=0x7ffff7fbbbc0 <default_loop_struct>, mode=UV_RUN_DEFAULT) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/src/unix/core.c:460
#11 0x000055555556b123 in run_helper_tcp4_echo_server () at /home/ptlomholt/dev/libuv/ptlomholt/libuv/test/echo-server.c:393
#12 0x000055555556d032 in run_test_part (test=0x5555565dc2fd "tcp_shutdown_after_write", part=0x5555565dc316 "tcp4_echo_server") at /home/ptlomholt/dev/libuv/ptlomholt/libuv/test/runner.c:372
#13 0x000055555556b41e in main (argc=3, argv=0x5555565dc2a0) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/test/run-tests.c:82
+frame 5
#5 0x0000555555569ce7 in after_shutdown (req=0x5555565dc690, status=-107) at /home/ptlomholt/dev/libuv/ptlomholt/libuv/test/echo-server.c:68
68 ASSERT_OK(status);
+list
63 uv_strerror(status));
64 }
65
66
67 static void after_shutdown(uv_shutdown_t* req, int status) {
68 ASSERT_OK(status);
69 uv_close((uv_handle_t*) req->handle, on_close);
70 free(req);
71 }
72
+p status
$4 = -107
+!errno 107
ENOTCONN 107 Transport endpoint is not connectedPresumably this happens because the tcp_shutdown_after_write test closes its client socket 'quickly' after writing to the socket in its shutdown_cb() handler, before the tcp4_echo_server gets a chance to successfully exchange its shutdown/FIN message with the client. Its after_shutdown() handler therefore receives a ENOTCONN status, which triggers the ASSERT. It is likely that this problem is timing dependent, but on my system it was reproduced 100% of the times I tried it.
Now, I think this can relatively easily be fixed by moving tcp_shutdown_after_write's uv_close() call to its read_cb() callback when it receives the UV_EOF back from the server, this should ensure the right ordering of events... In fact, I just tried making this change and it appeared to have fixed the problem. I will be posting a PR shortly and you can see if it makes sense...
Source: libuv/libuv