Rare nbdkit crash on RISC-V
This is quite rare, it happens perhaps one in 10 runs: qemu-img: Could not read file metadata: Input/output error nbdkit: nbdkit command was killed by signal 11 ... FAIL test-sh-extents.sh (exit status: 4) Full log and stack trace is attached. systemd-coredump collects a core dump. The stack trace seems to indicate memory corruption. On one run (not the one attached) I got an error message from malloc, the exact text I forget, but it seemed to indicate corruption in the glibc allocator. It's a bit mysterious and quite surprising that it doesn't happen on non-riscv64 platforms as far as I've seen. Unfortunately there's no valgrind for RISC-V :-( Still investigating ... Rich. glibc-2.32-4.fc33.riscv64 nbdkit compiled from git Thread 6 (Thread 0x3fc15e1e50 (LWP 74051)): #0 0x0000003fc3b0425a in __lll_lock_wait () from /lib64/lp64d/libpthread.so.0 #1 0x0000003fc3afe090 in pthread_mutex_lock () from /lib64/lp64d/libpthread.so.0 #2 0x0000002aea1b2928 in protocol_recv_request_send_reply.isra.0 () at protocol.c:632 #3 0x0000002aea1ac600 in connection_worker (data=0x2b303b0700) at connections.c:127 #4 0x0000003fc3afc606 in start_thread () from /lib64/lp64d/libpthread.so.0 #5 0x0000003fc3a76546 in __thread_start () from /lib64/lp64d/libc.so.6 Thread 5 (Thread 0x3fc25e3e50 (LWP 74049)): #0 0x0000003fc3b04426 in read () from /lib64/lp64d/libpthread.so.0 #1 0x0000002aea1aa1d6 in read (__nbytes=28, __buf=0x3fc25e34a8, __fd=8) at /usr/include/bits/unistd.h:46 #2 raw_recv (vbuf=<optimized out>, len=28) at connections.c:459 #3 0x0000002aea1b293e in protocol_recv_request_send_reply.isra.0 () at protocol.c:636 #4 0x0000002aea1ac600 in connection_worker (data=0x2b303b0700) at connections.c:127 #5 0x0000003fc3afc606 in start_thread () from /lib64/lp64d/libpthread.so.0 #6 0x0000003fc3a76546 in __thread_start () from /lib64/lp64d/libc.so.6 Thread 4 (Thread 0x3fc35e76b0 (LWP 74028)): #0 0x0000003fc3a6f978 in poll () from /lib64/lp64d/libc.so.6 #1 0x0000002aea1b0e18 in poll (__timeout=-1, __nfds=2, __fds=<optimized out>) at /usr/include/bits/poll2.h:46 #2 check_sockets_and_quit_fd (socks=0x3ffff1cd58) at sockets.c:466 #3 accept_incoming_connections (socks=0x3ffff1cd58) at sockets.c:540 #4 0x0000002aea1a8c6e in start_serving () at main.c:975 #5 main (argc=<optimized out>, argv=<optimized out>) at main.c:736 Thread 3 (Thread 0x3fc35e5e50 (LWP 74037)): #0 0x0000003fc3a305a2 in __lll_lock_wait_private () from /lib64/lp64d/libc.so.6 #1 0x0000003fc3a342f4 in malloc_check () from /lib64/lp64d/libc.so.6 #2 0x0000002aea1aefee in handle_single_connection (sockin=<optimized out>, sockout=<optimized out>) at connections.c:192 #3 0x0000002aea1b248a in start_thread (datav=0x2b303afd10) at sockets.c:354 #4 0x0000003fc3afc606 in start_thread () from /lib64/lp64d/libpthread.so.0 #5 0x0000003fc3a76546 in __thread_start () from /lib64/lp64d/libc.so.6 Thread 2 (Thread 0x3fc2de4e50 (LWP 74048)): #0 0x0000003fc3a6f978 in poll () from /lib64/lp64d/libc.so.6 #1 0x0000003fc3cca56e in poll (__timeout=-1, __nfds=3, __fds=0x3fc2de4150) at /usr/include/bits/poll2.h:46 #2 call3 (wbuf=wbuf@entry=0x0, wbuflen=wbuflen@entry=0, rbuf=rbuf@entry=0x3fc2de4260, rbuflen=rbuflen@entry=0x3fc2de4258, ebuf=ebuf@entry=0x3fc2de41f0, ebuflen=ebuflen@entry=0x3fc2de41e8, argv=argv@entry=0x3fc2de42e0) at call.c:257 #3 0x0000003fc3ccb4a8 in call_read (rbuf=rbuf@entry=0x3fc2de4260, rbuflen=rbuflen@entry=0x3fc2de4258, argv=argv@entry=0x3fc2de42e0) at call.c:521 --Type <RET> for more, q to quit, c to continue without paging-- #4 0x0000003fc3ccc678 in sh_extents (handle=<optimized out>, count=<optimized out>, offset=0, flags=<optimized out>, extents=0x2b303ce390) at methods.c:1046 #5 0x0000002aea1ae294 in plugin_extents (c=<optimized out>, count=<optimized out>, offset=<optimized out>, flags=<optimized out>, extents=0x2b303ce390, err=0x3fc2de4490) at plugins.c:761 #6 0x0000002aea1adedc in backend_extents (c=0x2b303cded0, count=<optimized out>, offset=0, flags=<optimized out>, extents=0x2b303ce390, err=0x3fc2de4490) at backend.c:703 #7 0x0000002aea1b2ff2 in handle_request (extents=0x2b303ce390, buf=0x0, count=<optimized out>, offset=<optimized out>, flags=<optimized out>, cmd=<optimized out>) at protocol.c:285 #8 protocol_recv_request_send_reply.isra.0 () at protocol.c:716 #9 0x0000002aea1ac600 in connection_worker (data=0x2b303b0120) at connections.c:127 #10 0x0000003fc3afc606 in start_thread () from /lib64/lp64d/libpthread.so.0 #11 0x0000003fc3a76546 in __thread_start () from /lib64/lp64d/libc.so.6 Thread 1 (Thread 0x3fc1de2e50 (LWP 74050)): #0 0x0000003fc3a32440 in _int_free () from /lib64/lp64d/libc.so.6 #1 0x0000003fc3a3309c in free_check () from /lib64/lp64d/libc.so.6 #2 0x0000002aea1ac5f4 in connection_worker (data=0x2b303b0120) at connections.c:124 #3 0x0000003fc3afc606 in start_thread () from /lib64/lp64d/libpthread.so.0 #4 0x0000003fc3a76546 in __thread_start () from /lib64/lp64d/libc.so.6 -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-p2v converts physical machines to virtual machines. Boot with a live CD or over the network (PXE) and turn machines into KVM guests. http://libguestfs.org/virt-v2v
I should add that these tests are run with MALLOC_CHECK_=1 MALLOC_PERTURB_=<random> which is probably why malloc_check appears in the stack trace. I commented out MALLOC_CHECK_ and ran the test a few more times, and it still crashed (again, it's rare). The new stack trace is below. I've omitted threads which were waiting on pthread_mutex_lock. Thread 4 (Thread 0x3fd2b876b0 (LWP 77382)): #0 0x0000003fd300f978 in poll () from /lib64/lp64d/libc.so.6 #1 0x0000002ad4c60e18 in poll (__timeout=-1, __nfds=2, __fds=<optimized out>) at /usr/include/bits/poll2.h:46 #2 check_sockets_and_quit_fd (socks=0x3fffe43d78) at sockets.c:466 #3 accept_incoming_connections (socks=0x3fffe43d78) at sockets.c:540 #4 0x0000002ad4c58c6e in start_serving () at main.c:975 #5 main (argc=<optimized out>, argv=<optimized out>) at main.c:736 Thread 3 (Thread 0x3fd1382e50 (LWP 77404)): #0 0x0000003fd30a4426 in read () from /lib64/lp64d/libpthread.so.0 #1 0x0000002ad4c5a1d6 in read (__nbytes=28, __buf=0x3fd13824a8, __fd=8) at /usr/include/bits/unistd.h:46 #2 raw_recv (vbuf=<optimized out>, len=28) at connections.c:459 #3 0x0000002ad4c6293e in protocol_recv_request_send_reply.isra.0 () at protocol.c:636 #4 0x0000002ad4c5c600 in connection_worker (data=0x3fcc0017e0) at connections.c:127 #5 0x0000003fd309c606 in start_thread () from /lib64/lp64d/libpthread.so.0 #6 0x0000003fd3016546 in __thread_start () from /lib64/lp64d/libc.so.6 Thread 2 (Thread 0x3fd2b85e50 (LWP 77391)): #0 0x0000003fd309d650 in __pthread_clockjoin_ex () from /lib64/lp64d/libpthread.so.0 #1 0x0000002ad4c5e9a8 in handle_single_connection (sockin=<optimized out>, sockout=<optimized out>) at connections.c:221 #2 0x0000002ad4c6248a in start_thread (datav=0x2af1f2a160) at sockets.c:354 #3 0x0000003fd309c606 in start_thread () from /lib64/lp64d/libpthread.so.0 #4 0x0000003fd3016546 in __thread_start () from /lib64/lp64d/libc.so.6 Thread 1 (Thread 0x3fd1b83e50 (LWP 77403)): #0 0x0000003fd2fd4a7e in __malloc_fork_lock_parent () from /lib64/lp64d/libc.so.6 #1 0x0000003fd2ff47ec in fork () from /lib64/lp64d/libc.so.6 #2 0x0000003fd326a50e in call3 (wbuf=wbuf@entry=0x0, wbuflen=wbuflen@entry=0, rbuf=rbuf@entry=0x3fd1b83260, rbuflen=rbuflen@entry=0x3fd1b83258, ebuf=ebuf@entry=0x3fd1b831f0, ebuflen=ebuflen@entry=0x3fd1b831e8, argv=argv@entry=0x3fd1b832e0) at call.c:214 #3 0x0000003fd326b4a8 in call_read (rbuf=rbuf@entry=0x3fd1b83260, rbuflen=rbuflen@entry=0x3fd1b83258, argv=argv@entry=0x3fd1b832e0) at call.c:521 #4 0x0000003fd326c678 in sh_extents (handle=<optimized out>, count=<optimized out>, offset=32768, flags=<optimized out>, extents=0x3fc8000bc0) at methods.c:1046 #5 0x0000002ad4c5e294 in plugin_extents (c=<optimized out>, count=<optimized out>, offset=<optimized out>, flags=<optimized out>, extents=0x3fc8000bc0, err=0x3fd1b83490) at plugins.c:761 #6 0x0000002ad4c5dedc in backend_extents (c=0x3fcc001040, count=<optimized out>, offset=32768, flags=<optimized out>, extents=0x3fc8000bc0, err=0x3fd1b83490) at backend.c:703 #7 0x0000002ad4c62ff2 in handle_request (extents=0x3fc8000bc0, buf=0x0, count=<optimized out>, offset=<optimized out>, flags=<optimized out>, cmd=<optimized out>) at protocol.c:285 #8 protocol_recv_request_send_reply.isra.0 () at protocol.c:716 --Type <RET> for more, q to quit, c to continue without paging-- #9 0x0000002ad4c5c600 in connection_worker (data=0x3fcc001650) at connections.c:127 #10 0x0000003fd309c606 in start_thread () from /lib64/lp64d/libpthread.so.0 #11 0x0000003fd3016546 in __thread_start () from /lib64/lp64d/libc.so.6 Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com libguestfs lets you edit virtual machines. Supports shell scripting, bindings from many languages. http://libguestfs.org
David, if you have one of your fast RISC-V machines, could you see if you can reproduce this? I believe the following is sufficient: # dnf builddep nbdkit $ git clone https://gitlab.com/nbdkit/nbdkit $ autoreconf -i $ ./configure CFLAGS="$(rpm --eval '%{optflags}')" \ CXXFLAGS="$(rpm --eval '%{optflags}')" \ LDFLAGS="$(rpm --eval '%{__global_ldflags}')" $ make $ make -C tests check TESTS=test-sh-extents.sh Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-builder quickly builds VMs from scratch http://libguestfs.org/virt-builder.1.html
On Sat, May 01, 2021 at 11:57:07AM +0100, Richard W.M. Jones wrote:
David, if you have one of your fast RISC-V machines, could you see if you can reproduce this?
I believe the following is sufficient:
# dnf builddep nbdkit
$ git clone https://gitlab.com/nbdkit/nbdkit $ autoreconf -i $ ./configure CFLAGS="$(rpm --eval '%{optflags}')" \ CXXFLAGS="$(rpm --eval '%{optflags}')" \ LDFLAGS="$(rpm --eval '%{__global_ldflags}')" $ make $ make -C tests check TESTS=test-sh-extents.sh
I think I've got this one - it seems to be a latent bug in nbdkit. Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com virt-top is 'top' for virtual machines. Tiny program with many powerful monitoring features, net stats, disk stats, logging, etc. http://people.redhat.com/~rjones/virt-top
participants (1)
-
Richard W.M. Jones