Richard W.M. Jones
2022-Jun-27 12:54 UTC
[Libguestfs] nbdkit test fails with: nbdkit: error: /home/rjones/d/nbdkit/tests/test-parallel-sh.script: there seem to be leaked fds, curr_fds=3
Hi Eric,
tests/test-parallel-sh.sh fails reliably for me, when run under
valgrind:
$ make && make -C tests check-valgrind TESTS=test-parallel-sh.sh
FAIL: test-parallel-sh.sh
The test is kind of complicated, any ideas? Nothing in the code has
changed recently as far as I know.
qemu-7.0.0-6.fc37.x86_64
glibc-2.35.9000-22.fc37.x86_64
valgrind-3.19.0-3.fc37.x86_64
bash-5.1.16-2.fc36.x86_64
Rich.
--
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
nbdkit - Flexible, fast NBD server with plugins
https://gitlab.com/nbdkit/nbdkit
-------------- next part --------------
==2193882== Memcheck, a memory error detector
==2193882== Copyright (C) 2002-2022, and GNU GPL'd, by Julian Seward et al.
==2193882== Using Valgrind-3.19.0 and LibVEX; rerun with -h for copyright info
==2193882== Command: /home/rjones/d/nbdkit/server/nbdkit --dump-plugin --
/home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so
==2193882==
==2193882==
==2193882== HEAP SUMMARY:
==2193882== in use at exit: 97,558 bytes in 677 blocks
==2193882== total heap usage: 1,443 allocs, 766 frees, 144,938 bytes allocated
==2193882==
==2193882== LEAK SUMMARY:
==2193882== definitely lost: 0 bytes in 0 blocks
==2193882== indirectly lost: 0 bytes in 0 blocks
==2193882== possibly lost: 0 bytes in 0 blocks
==2193882== still reachable: 0 bytes in 0 blocks
==2193882== suppressed: 97,558 bytes in 677 blocks
==2193882==
==2193882== For lists of detected and suppressed errors, rerun with: -s
==2193882== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 1 from 1)
wrote 512/512 bytes at offset 0
512 bytes, 1 ops; 00.00 sec (151.167 KiB/sec and 302.3344 ops/sec)
wrote 512/512 bytes at offset 512
512 bytes, 1 ops; 00.00 sec (112.598 KiB/sec and 225.1968 ops/sec)
using curr_fds=3
valgrind --vgdb=no --leak-check=full --show-leak-kinds=all --error-exitcode=119
--suppressions=/home/rjones/d/nbdkit/valgrind/suppressions --trace-children=no
--run-libc-freeres=no --num-callers=100 --read-inline-info=no
/home/rjones/d/nbdkit/server/nbdkit -v -t 1 -U -
--filter=/home/rjones/d/nbdkit/filters/delay/.libs/nbdkit-delay-filter.so
"--run=timeout 60s </dev/null qemu-io -f raw \\
-c \"aio_write -P 2 512 512\" -c \"aio_read -P 1 0 512\"
-c aio_flush \$nbd" --
/home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so
test-parallel-sh.script wdelay=2 rdelay=1
==2194584== Memcheck, a memory error detector
==2194584== Copyright (C) 2002-2022, and GNU GPL'd, by Julian Seward et al.
==2194584== Using Valgrind-3.19.0 and LibVEX; rerun with -h for copyright info
==2194584== Command: /home/rjones/d/nbdkit/server/nbdkit -v -t 1 -U -
--filter=/home/rjones/d/nbdkit/filters/delay/.libs/nbdkit-delay-filter.so
--run=timeout\ 60s\ \</dev/null\ qemu-io\ -f\ raw\ \\_\ \ \ \ -c\
"aio_write\ -P\ 2\ 512\ 512"\ -c\ "aio_read\ -P\ 1\ 0\ 512"\
-c\ aio_flush\ $nbd --
/home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so
test-parallel-sh.script wdelay=2 rdelay=1
==2194584==
nbdkit: debug: nbdkit 1.31.9
nbdkit: debug: TLS disabled: could not load TLS certificates
nbdkit: debug: registering plugin
/home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so
nbdkit: debug: registered plugin
/home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so (name sh)
nbdkit: debug: sh: load
nbdkit: debug: load: tmpdir: /tmp/nbdkitMoHSMY
nbdkit: debug: registering filter
/home/rjones/d/nbdkit/filters/delay/.libs/nbdkit-delay-filter.so
nbdkit: debug: registered filter
/home/rjones/d/nbdkit/filters/delay/.libs/nbdkit-delay-filter.so (name delay)
nbdkit: debug: delay: load
nbdkit: debug: delay: config key=script, value=test-parallel-sh.script
nbdkit: debug: sh: config key=script, value=test-parallel-sh.script
nbdkit: debug: calling: /home/rjones/d/nbdkit/tests/test-parallel-sh.script load
nbdkit: debug: completed: /home/rjones/d/nbdkit/tests/test-parallel-sh.script
load: status 5
nbdkit: debug: /home/rjones/d/nbdkit/tests/test-parallel-sh.script: there seem
to be leaked fds, curr_fds=3
total 0
lr-x------. 1 rjones rjones 64 Jun 27 12:49 0 -> pipe:[1724165448]
l-wx------. 1 rjones rjones 64 Jun 27 12:49 1 -> pipe:[1724165449]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 10 -> pipe:[1724154362]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 11 -> pipe:[1724154369]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 12 -> pipe:[1724149297]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 13 -> pipe:[1724154373]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 14 -> pipe:[1724149303]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 15 -> pipe:[1724168431]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 16 -> pipe:[1724168425]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 17 -> pipe:[1724147613]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 18 -> pipe:[1724168437]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 19 -> pipe:[1724164172]
l-wx------. 1 rjones rjones 64 Jun 27 12:49 2 -> pipe:[1724165450]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 20 -> pipe:[1724153514]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 21 -> pipe:[1724164178]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 22 -> pipe:[1724160348]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 23 -> pipe:[1724160342]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 24 -> pipe:[1724160357]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 25 -> pipe:[1724153542]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 255 ->
/home/rjones/d/nbdkit/tests/test-parallel-sh.script
lr-x------. 1 rjones rjones 64 Jun 27 12:49 26 -> pipe:[1724160360]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 27 -> pipe:[1724160363]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 28 -> pipe:[1724166237]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 29 -> pipe:[1724164208]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 30 -> pipe:[1724160378]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 31 -> pipe:[1724166246]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 32 -> pipe:[1724166255]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 33 -> pipe:[1724150284]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 34 -> pipe:[1724166259]
lr-x------. 1 rjones rjones 64 Jun 27 12:49 8 -> pipe:[1724157788]
nbdkit: error: /home/rjones/d/nbdkit/tests/test-parallel-sh.script: there seem
to be leaked fds, curr_fds=3
==2194584==
==2194584== HEAP SUMMARY:
==2194584== in use at exit: 121,659 bytes in 769 blocks
==2194584== total heap usage: 1,510 allocs, 741 frees, 285,535 bytes allocated
==2194584==
==2194584== 3 bytes in 1 blocks are still reachable in loss record 1 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0x11322F: backend_load (backend.c:123)
==2194584== by 0x10F8ED: main (plugins.c:975)
==2194584==
==2194584== 6 bytes in 1 blocks are still reachable in loss record 2 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0x11322F: backend_load (backend.c:123)
==2194584== by 0x10FAD5: main (filters.c:711)
==2194584==
==2194584== 18 bytes in 1 blocks are still reachable in loss record 3 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0x10F221: main (utils.c:195)
==2194584==
==2194584== 25 bytes in 1 blocks are still reachable in loss record 4 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCC97D87: __vasprintf_internal (vasprintf.c:71)
==2194584== by 0xCD32022: __asprintf_chk (asprintf_chk.c:34)
==2194584== by 0x10F24E: main (stdio2.h:186)
==2194584==
==2194584== 25 bytes in 1 blocks are still reachable in loss record 5 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0x10F263: main (main.c:796)
==2194584==
==2194584== 25 bytes in 1 blocks are still reachable in loss record 6 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCC97D87: __vasprintf_internal (vasprintf.c:71)
==2194584== by 0xCD32022: __asprintf_chk (asprintf_chk.c:34)
==2194584== by 0xC98599E: copy_environ (stdio2.h:186)
==2194584== by 0xC985DA6: sh_load (call.c:80)
==2194584== by 0x10F8ED: main (plugins.c:975)
==2194584==
==2194584== 52 bytes in 1 blocks are still reachable in loss record 31 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB4B7C: __libc_scratch_buffer_dupfree
(scratch_buffer_dupfree.c:32)
==2194584== by 0xCC55F3D: realpath_stk (scratch_buffer.h:147)
==2194584== by 0xCC56605: realpath@@GLIBC_2.3 (canonicalize.c:449)
==2194584== by 0x11DA28: nbdkit_realpath (stdlib.h:42)
==2194584== by 0xC987347: sh_config (sh.c:150)
==2194584== by 0x11755D: plugin_config (plugins.c:225)
==2194584== by 0x1115CA: next_config (filters.c:132)
==2194584== by 0x117219: filter_config (filters.c:145)
==2194584== by 0x10FDF0: main (main.c:719)
==2194584==
==2194584== 59 bytes in 1 blocks are still reachable in loss record 35 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0x10F81B: main (backend.c:73)
==2194584==
==2194584== 65 bytes in 1 blocks are still reachable in loss record 38 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0x10FA4D: main (backend.c:73)
==2194584==
==2194584== 688 bytes in 1 blocks are still reachable in loss record 44 of 54
==2194584== at 0xC975464: calloc (vg_replace_malloc.c:1328)
==2194584== by 0x10FA0E: main (filters.c:668)
==2194584==
==2194584== 744 bytes in 1 blocks are still reachable in loss record 45 of 54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0x10F7DE: main (plugins.c:917)
==2194584==
==2194584== 744 bytes in 1 blocks are still reachable in loss record 46 of 54
==2194584== at 0xC9756AF: realloc (vg_replace_malloc.c:1437)
==2194584== by 0xC98589A: copy_environ (vector.c:92)
==2194584== by 0xC985DA6: sh_load (call.c:80)
==2194584== by 0x10F8ED: main (plugins.c:975)
==2194584==
==2194584== 21,852 bytes in 75 blocks are still reachable in loss record 53 of
54
==2194584== at 0xC97086F: malloc (vg_replace_malloc.c:381)
==2194584== by 0xCCB8E4D: strdup (strdup.c:42)
==2194584== by 0xC9858C0: copy_environ (environ.c:60)
==2194584== by 0xC985DA6: sh_load (call.c:80)
==2194584== by 0x10F8ED: main (plugins.c:975)
==2194584==
==2194584== LEAK SUMMARY:
==2194584== definitely lost: 0 bytes in 0 blocks
==2194584== indirectly lost: 0 bytes in 0 blocks
==2194584== possibly lost: 0 bytes in 0 blocks
==2194584== still reachable: 24,306 bytes in 87 blocks
==2194584== suppressed: 97,353 bytes in 682 blocks
==2194584==
==2194584== For lists of detected and suppressed errors, rerun with: -s
==2194584== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 2)
./test-parallel-sh.sh: run cleanup hooks: exit code 1
FAIL test-parallel-sh.sh (exit status: 1)
Richard W.M. Jones
2022-Jun-27 13:17 UTC
[Libguestfs] nbdkit test fails with: nbdkit: error: /home/rjones/d/nbdkit/tests/test-parallel-sh.script: there seem to be leaked fds, curr_fds=3
Don't worry, fixed it. It's because debuginfod opens a dozen pipes which breaks the assumptions made by the test (and is basically yet another bug in debuginfod). I'll push a fix soon. Thanks, 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