[Libguestfs] Rare nbdkit crash on RISC-V
Richard W.M. Jones
rjones at redhat.com
Sat May 1 10:45:30 UTC 2021
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 at entry=0x0, wbuflen=wbuflen at entry=0, rbuf=rbuf at entry=0x3fc2de4260, rbuflen=rbuflen at entry=0x3fc2de4258, ebuf=ebuf at entry=0x3fc2de41f0, ebuflen=ebuflen at entry=0x3fc2de41e8, argv=argv at entry=0x3fc2de42e0) at call.c:257
#3 0x0000003fc3ccb4a8 in call_read (rbuf=rbuf at entry=0x3fc2de4260, rbuflen=rbuflen at entry=0x3fc2de4258, argv=argv at 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
-------------- next part --------------
+ requires_plugin sh
+ requires nbdkit sh --version
+ requires jq --version
+ requires qemu-img --version
+ requires qemu-img map --help
+ out=test-sh-extents.out
+ expected=test-sh-extents.expected
+ files='test-sh-extents.out test-sh-extents.expected'
+ rm -f test-sh-extents.out test-sh-extents.expected
+ cleanup_fn rm -f test-sh-extents.out test-sh-extents.expected
+ _cleanup_hook[${#_cleanup_hook[@]}]='rm -f test-sh-extents.out test-sh-extents.expected'
+ cat
+ do_test
+ jq -c '.[] | {start:.start, length:.length, data:.data, zero:.zero}'
+ nbdkit -v -U - sh - --run 'qemu-img map -f raw --output=json $nbd'
/home/rjones/d/nbdkit/server/nbdkit -v -U - "--run=qemu-img map -f raw --output=json \$nbd" -- /home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so -
nbdkit: debug: nbdkit 1.25.6
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/nbdkitYD8y2t
nbdkit: debug: sh: config key=script, value=-
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh load
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh load: status 2
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh magic_config_key
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh magic_config_key: status 2
nbdkit: debug: sh: config_complete
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh config_complete
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh config_complete: status 2
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh thread_model
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh thread_model: status 0
nbdkit: debug: using thread model: parallel
nbdkit: debug: sh: get_ready
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh get_ready
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh get_ready: status 2
nbdkit: debug: bound to unix socket /tmp/nbdkitFcp05s/socket
nbdkit: debug: forked into background (new pid = 73926)
nbdkit: debug: sh: after_fork
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh after_fork
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh after_fork: status 2
nbdkit: debug: accepted connection
nbdkit: sh[1]: debug: sh: preconnect
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh preconnect false
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh preconnect: status 2
nbdkit: sh[1]: debug: newstyle negotiation: flags: global 0x3
nbdkit: sh[1]: debug: newstyle negotiation: client flags: 0x3
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_STRUCTURED_REPLY: client requested structured replies
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: client requested export ''
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: set count: 1
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: set base:allocation
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: replying with base:allocation id 1
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: reply complete
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_GO: client requested export ''
nbdkit: sh[1]: debug: sh: open readonly=0 exportname="" tls=0
nbdkit: sh[1]: debug: sh: default_export readonly=0 tls=0
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh default_export false false
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh default_export: status 2
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh open false "" false
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh open: status 2
nbdkit: sh[1]: debug: sh: open returned handle 0x2b15381530
nbdkit: sh[1]: debug: sh: prepare readonly=0
nbdkit: sh[1]: debug: sh: get_size
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh get_size ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh get_size: status 0
nbdkit: sh[1]: debug: sh: can_write
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh can_write ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh can_write: status 2
nbdkit: sh[1]: debug: sh: can_zero
nbdkit: sh[1]: debug: sh: can_fast_zero
nbdkit: sh[1]: debug: sh: can_trim
nbdkit: sh[1]: debug: sh: can_fua
nbdkit: sh[1]: debug: sh: can_flush
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh can_flush ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh can_flush: status 2
nbdkit: sh[1]: debug: sh: is_rotational
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh is_rotational ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh is_rotational: status 2
nbdkit: sh[1]: debug: sh: can_multi_conn
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh can_multi_conn ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh can_multi_conn: status 2
nbdkit: sh[1]: debug: sh: can_cache
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh can_cache ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh can_cache: status 2
nbdkit: sh[1]: debug: sh: can_extents
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh can_extents ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh can_extents: status 0
nbdkit: sh[1]: debug: newstyle negotiation: flags: export 0x83
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_GO: ignoring NBD_INFO_* request 3 (NBD_INFO_BLOCK_SIZE)
nbdkit: sh[1]: debug: handshake complete, processing requests with 16 threads
nbdkit: debug: starting worker thread sh.0
nbdkit: sh.0: debug: sh: extents count=65536 offset=0 req_one=1
nbdkit: debug: starting worker thread sh.1
nbdkit: sh.0: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh extents "" 65536 0 req_one
nbdkit: debug: starting worker thread sh.2
nbdkit: debug: starting worker thread sh.3
nbdkit: debug: starting worker thread sh.4
nbdkit: debug: starting worker thread sh.5
nbdkit: debug: starting worker thread sh.6
nbdkit: debug: starting worker thread sh.7
nbdkit: debug: starting worker thread sh.8
nbdkit: debug: starting worker thread sh.9
nbdkit: debug: starting worker thread sh.10
nbdkit: debug: starting worker thread sh.11
nbdkit: debug: starting worker thread sh.12
nbdkit: debug: starting worker thread sh.13
nbdkit: debug: starting worker thread sh.14
nbdkit: debug: starting worker thread sh.15
nbdkit: sh.0: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh extents: status 0
nbdkit: sh.0: debug: /tmp/nbdkitYD8y2t/inline-script.sh: adding extent 0 65536 3
nbdkit: sh.1: debug: client sent NBD_CMD_DISC, closing connection
nbdkit: sh.1: debug: exiting worker thread sh.1
nbdkit: sh.3: debug: exiting worker thread sh.3
nbdkit: sh.4: debug: exiting worker thread sh.4
nbdkit: sh.6: debug: exiting worker thread sh.6
nbdkit: sh.5: debug: exiting worker thread sh.5
nbdkit: sh.2: debug: exiting worker thread sh.2
nbdkit: sh.8: debug: exiting worker thread sh.8
nbdkit: sh.9: debug: exiting worker thread sh.9
nbdkit: sh.11: debug: exiting worker thread sh.11
nbdkit: sh.12: debug: exiting worker thread sh.12
nbdkit: sh.7: debug: exiting worker thread sh.7
nbdkit: sh.10: debug: exiting worker thread sh.10
nbdkit: sh.0: debug: exiting worker thread sh.0
nbdkit: sh.14: debug: exiting worker thread sh.14
nbdkit: sh.15: debug: exiting worker thread sh.15
nbdkit: sh.13: debug: exiting worker thread sh.13
nbdkit: sh[1]: debug: sh: finalize
nbdkit: sh[1]: debug: sh: close
nbdkit: sh[1]: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh close ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh close: status 2
nbdkit: debug: sh: unload plugin
nbdkit: debug: calling: /tmp/nbdkitYD8y2t/inline-script.sh unload
nbdkit: debug: completed: /tmp/nbdkitYD8y2t/inline-script.sh unload: status 2
+ cmp test-sh-extents.out test-sh-extents.expected
+ cat
+ do_test
+ jq -c '.[] | {start:.start, length:.length, data:.data, zero:.zero}'
+ nbdkit -v -U - sh - --run 'qemu-img map -f raw --output=json $nbd'
/home/rjones/d/nbdkit/server/nbdkit -v -U - "--run=qemu-img map -f raw --output=json \$nbd" -- /home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so -
nbdkit: debug: nbdkit 1.25.6
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/nbdkitetZmUk
nbdkit: debug: sh: config key=script, value=-
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh load
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh load: status 2
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh magic_config_key
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh magic_config_key: status 2
nbdkit: debug: sh: config_complete
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh config_complete
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh config_complete: status 2
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh thread_model
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh thread_model: status 0
nbdkit: debug: using thread model: parallel
nbdkit: debug: sh: get_ready
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh get_ready
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh get_ready: status 2
nbdkit: debug: bound to unix socket /tmp/nbdkit6WH5ji/socket
nbdkit: debug: forked into background (new pid = 73977)
nbdkit: debug: sh: after_fork
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh after_fork
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh after_fork: status 2
nbdkit: debug: accepted connection
nbdkit: sh[1]: debug: sh: preconnect
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh preconnect false
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh preconnect: status 2
nbdkit: sh[1]: debug: newstyle negotiation: flags: global 0x3
nbdkit: sh[1]: debug: newstyle negotiation: client flags: 0x3
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_STRUCTURED_REPLY: client requested structured replies
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: client requested export ''
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: set count: 1
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: set base:allocation
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: replying with base:allocation id 1
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: reply complete
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_GO: client requested export ''
nbdkit: sh[1]: debug: sh: open readonly=0 exportname="" tls=0
nbdkit: sh[1]: debug: sh: default_export readonly=0 tls=0
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh default_export false false
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh default_export: status 2
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh open false "" false
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh open: status 2
nbdkit: sh[1]: debug: sh: open returned handle 0x2af29d5530
nbdkit: sh[1]: debug: sh: prepare readonly=0
nbdkit: sh[1]: debug: sh: get_size
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh get_size ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh get_size: status 0
nbdkit: sh[1]: debug: sh: can_write
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh can_write ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh can_write: status 2
nbdkit: sh[1]: debug: sh: can_zero
nbdkit: sh[1]: debug: sh: can_fast_zero
nbdkit: sh[1]: debug: sh: can_trim
nbdkit: sh[1]: debug: sh: can_fua
nbdkit: sh[1]: debug: sh: can_flush
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh can_flush ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh can_flush: status 2
nbdkit: sh[1]: debug: sh: is_rotational
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh is_rotational ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh is_rotational: status 2
nbdkit: sh[1]: debug: sh: can_multi_conn
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh can_multi_conn ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh can_multi_conn: status 2
nbdkit: sh[1]: debug: sh: can_cache
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh can_cache ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh can_cache: status 2
nbdkit: sh[1]: debug: sh: can_extents
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh can_extents ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh can_extents: status 0
nbdkit: sh[1]: debug: newstyle negotiation: flags: export 0x83
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_GO: ignoring NBD_INFO_* request 3 (NBD_INFO_BLOCK_SIZE)
nbdkit: sh[1]: debug: handshake complete, processing requests with 16 threads
nbdkit: debug: starting worker thread sh.0
nbdkit: sh.0: debug: sh: extents count=65536 offset=0 req_one=1
nbdkit: debug: starting worker thread sh.1
nbdkit: sh.0: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh extents "" 65536 0 req_one
nbdkit: debug: starting worker thread sh.2
nbdkit: debug: starting worker thread sh.3
nbdkit: debug: starting worker thread sh.4
nbdkit: debug: starting worker thread sh.5
nbdkit: debug: starting worker thread sh.6
nbdkit: debug: starting worker thread sh.7
nbdkit: debug: starting worker thread sh.8
nbdkit: debug: starting worker thread sh.9
nbdkit: debug: starting worker thread sh.10
nbdkit: debug: starting worker thread sh.11
nbdkit: debug: starting worker thread sh.12
nbdkit: debug: starting worker thread sh.13
nbdkit: debug: starting worker thread sh.14
nbdkit: debug: starting worker thread sh.15
nbdkit: sh.0: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh extents: status 0
nbdkit: sh.0: debug: /tmp/nbdkitetZmUk/inline-script.sh: adding extent 0 65536 0
nbdkit: sh.1: debug: client sent NBD_CMD_DISC, closing connection
nbdkit: sh.1: debug: exiting worker thread sh.1
nbdkit: sh.3: debug: exiting worker thread sh.3
nbdkit: sh.4: debug: exiting worker thread sh.4
nbdkit: sh.6: debug: exiting worker thread sh.6
nbdkit: sh.7: debug: exiting worker thread sh.7
nbdkit: sh.8: debug: exiting worker thread sh.8
nbdkit: sh.5: debug: exiting worker thread sh.5
nbdkit: sh.9: debug: exiting worker thread sh.9
nbdkit: sh.10: debug: exiting worker thread sh.10
nbdkit: sh.2: debug: exiting worker thread sh.2
nbdkit: sh.11: debug: exiting worker thread sh.11
nbdkit: sh.12: debug: exiting worker thread sh.12
nbdkit: sh.13: debug: exiting worker thread sh.13
nbdkit: sh.14: debug: exiting worker thread sh.14
nbdkit: sh.0: debug: exiting worker thread sh.0
nbdkit: sh.15: debug: exiting worker thread sh.15
nbdkit: sh[1]: debug: sh: finalize
nbdkit: sh[1]: debug: sh: close
nbdkit: sh[1]: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh close ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh close: status 2
nbdkit: debug: sh: unload plugin
nbdkit: debug: calling: /tmp/nbdkitetZmUk/inline-script.sh unload
nbdkit: debug: completed: /tmp/nbdkitetZmUk/inline-script.sh unload: status 2
+ cmp test-sh-extents.out test-sh-extents.expected
+ cat
+ do_test
+ jq -c '.[] | {start:.start, length:.length, data:.data, zero:.zero}'
+ nbdkit -v -U - sh - --run 'qemu-img map -f raw --output=json $nbd'
/home/rjones/d/nbdkit/server/nbdkit -v -U - "--run=qemu-img map -f raw --output=json \$nbd" -- /home/rjones/d/nbdkit/plugins/sh/.libs/nbdkit-sh-plugin.so -
nbdkit: debug: nbdkit 1.25.6
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/nbdkit45F6z9
nbdkit: debug: sh: config key=script, value=-
nbdkit: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh load
nbdkit: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh load: status 2
nbdkit: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh magic_config_key
nbdkit: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh magic_config_key: status 2
nbdkit: debug: sh: config_complete
nbdkit: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh config_complete
nbdkit: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh config_complete: status 2
nbdkit: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh thread_model
nbdkit: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh thread_model: status 0
nbdkit: debug: using thread model: parallel
nbdkit: debug: sh: get_ready
nbdkit: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh get_ready
nbdkit: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh get_ready: status 2
nbdkit: debug: bound to unix socket /tmp/nbdkitaxtsi8/socket
nbdkit: debug: forked into background (new pid = 74028)
nbdkit: debug: sh: after_fork
nbdkit: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh after_fork
nbdkit: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh after_fork: status 2
nbdkit: debug: accepted connection
nbdkit: sh[1]: debug: sh: preconnect
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh preconnect false
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh preconnect: status 2
nbdkit: sh[1]: debug: newstyle negotiation: flags: global 0x3
nbdkit: sh[1]: debug: newstyle negotiation: client flags: 0x3
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_STRUCTURED_REPLY: client requested structured replies
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: client requested export ''
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: set count: 1
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: set base:allocation
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: replying with base:allocation id 1
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_SET_META_CONTEXT: reply complete
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_GO: client requested export ''
nbdkit: sh[1]: debug: sh: open readonly=0 exportname="" tls=0
nbdkit: sh[1]: debug: sh: default_export readonly=0 tls=0
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh default_export false false
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh default_export: status 2
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh open false "" false
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh open: status 2
nbdkit: sh[1]: debug: sh: open returned handle 0x2b303b0530
nbdkit: sh[1]: debug: sh: prepare readonly=0
nbdkit: sh[1]: debug: sh: get_size
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh get_size ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh get_size: status 0
nbdkit: sh[1]: debug: sh: can_write
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh can_write ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh can_write: status 2
nbdkit: sh[1]: debug: sh: can_zero
nbdkit: sh[1]: debug: sh: can_fast_zero
nbdkit: sh[1]: debug: sh: can_trim
nbdkit: sh[1]: debug: sh: can_fua
nbdkit: sh[1]: debug: sh: can_flush
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh can_flush ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh can_flush: status 2
nbdkit: sh[1]: debug: sh: is_rotational
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh is_rotational ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh is_rotational: status 2
nbdkit: sh[1]: debug: sh: can_multi_conn
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh can_multi_conn ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh can_multi_conn: status 2
nbdkit: sh[1]: debug: sh: can_cache
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh can_cache ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh can_cache: status 2
nbdkit: sh[1]: debug: sh: can_extents
nbdkit: sh[1]: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh can_extents ""
nbdkit: sh[1]: debug: completed: /tmp/nbdkit45F6z9/inline-script.sh can_extents: status 0
nbdkit: sh[1]: debug: newstyle negotiation: flags: export 0x83
nbdkit: sh[1]: debug: newstyle negotiation: NBD_OPT_GO: ignoring NBD_INFO_* request 3 (NBD_INFO_BLOCK_SIZE)
nbdkit: sh[1]: debug: handshake complete, processing requests with 16 threads
nbdkit: debug: starting worker thread sh.0
nbdkit: sh.0: debug: sh: extents count=65536 offset=0 req_one=1
nbdkit: debug: starting worker thread sh.1
nbdkit: sh.0: debug: calling: /tmp/nbdkit45F6z9/inline-script.sh extents "" 65536 0 req_one
nbdkit: debug: starting worker thread sh.2
nbdkit: debug: starting worker thread sh.3
qemu-img: Could not read file metadata: Input/output error
nbdkit: nbdkit command was killed by signal 11
parse error: Unfinished JSON term at EOF at line 1, column 1
+ _run_cleanup_hooks
+ local _status=4 _i
+ set +e
+ trap '' INT QUIT TERM EXIT ERR
+ echo ./test-sh-extents.sh: run cleanup hooks: exit code 4
./test-sh-extents.sh: run cleanup hooks: exit code 4
+ (( _i = 0 ))
+ (( _i < 1 ))
+ rm -f test-sh-extents.out test-sh-extents.expected
+ (( ++_i ))
+ (( _i < 1 ))
+ exit 4
FAIL test-sh-extents.sh (exit status: 4)
More information about the Libguestfs
mailing list