Eric Blake
2019-Mar-23 14:52 UTC
Re: [Libguestfs] nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
On 3/23/19 7:58 AM, Richard W.M. Jones wrote:>> A good point here is what happens with the block-status branch[1]. >> Let's see: >> >> $ ./nbdkit memory size=64M --run '/home/rjones/d/qemu/qemu-img convert $nbd /var/tmp/out' >> qemu-img: Payload too large >> nbdkit: memory.1: error: write reply: NBD_CMD_BLOCK_STATUS: Broken pipe >> >> Oh dear. I believe this is actually a bug in the block status code so >> let's see if I can narrow this down first ... > > OK I fixed this bug (in nbdkit).Which is why the block-status branch is still in flux :)> > The block-status branch *works* with qemu 2.12.0, so another option > here is to do nothing and wait until that work is finished and merged.Well, it works as long as you don't send a simple error reply (our mails crossed, and I submitted that patch for that issue already).> > NB During this I discovered another (but minor) bug in qemu. If you > feed qemu a long series of block status replies then it eventually > closes the connection. However it does not print an error message. >Which version(s) of qemu? Was REQ_ONE in force or not? Was it a long series of status replies that could have been coalesced, or were they alternating status? Did the replies extend beyond the client's original request? I'd like to reproduce the failure, to determine if qemu needs more patches. -- Eric Blake, Principal Software Engineer Red Hat, Inc. +1-919-301-3226 Virtualization: qemu.org | libvirt.org
Richard W.M. Jones
2019-Mar-23 17:00 UTC
Re: [Libguestfs] nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
On Sat, Mar 23, 2019 at 09:52:41AM -0500, Eric Blake wrote:> On 3/23/19 7:58 AM, Richard W.M. Jones wrote: > > NB During this I discovered another (but minor) bug in qemu. If you > > feed qemu a long series of block status replies then it eventually > > closes the connection. However it does not print an error message. > > > > Which version(s) of qemu? Was REQ_ONE in force or not? Was it a long > series of status replies that could have been coalesced, or were they > alternating status? Did the replies extend beyond the client's original > request? > > I'd like to reproduce the failure, to determine if qemu needs more patches.Here's how to reproduce it. You will need nbdkit block-status https://github.com/rwmjones/nbdkit/tree/block-status @ 8c3b6cbe81bdf with the small patch attached to this email on top. Then run it against qemu (from git) like this: ./nbdkit -fv memory size=64M \ --run '/path/to/qemu-img convert $nbd /var/tmp/out' You should see: nbdkit: memory.0: debug: pread count=512 offset=0 nbdkit: memory.1: debug: extents count=67108864 offset=0 req_one=1 nbdkit: memory.3: debug: client sent NBD_CMD_DISC, closing connection nbdkit: memory.3: debug: exiting worker thread memory.3 and qemu-img exits with code 1, but there is no message printed. (You can use --run '... || echo FAIL' if you don't believe that qemu-img is exiting with a failure.) While preparing this email I noticed that v3.1.0 printed an error message: qemu-img: Protocol error: invalid payload for NBD_REPLY_TYPE_BLOCK_STATUS So I have bisected this to the following commit: d8b4bad846f08ff0f167b46dc156a5310b750484 is the first bad commit commit d8b4bad846f08ff0f167b46dc156a5310b750484 Author: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> Date: Fri Nov 2 18:11:52 2018 +0300 block/nbd-client: use traces instead of noisy error_report_err Reduce extra noise of nbd-client, change 083 correspondingly. In various commits (be41c100 in 2.10, f140e300 in 2.11, 78a33ab in 2.12), we added spots where qemu as an NBD client would report problems communicating with the server to stderr, because there was no where else to send the error to. However, this is racy, particularly since the most common source of these errors is when either the client or the server abruptly hangs up, leaving one coroutine to report the error only if it wins (or loses) the race in attempting the read from the server before another thread completes its cleanup of a protocol error that caused the disconnect in the first place. The race is also apparent in the fact that differences in the flush behavior of the server can alter the frequency of encountering the race in the client (see commit 6d39db96). Rather than polluting stderr, it's better to just trace these situations, for use by developers debugging a flaky connection, particularly since the real error that either triggers the abrupt disconnection in the first place, or that results from the EIO when a request can't receive a reply, DOES make it back to the user in the normal Error propagation channels. Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> Message-Id: <20181102151152.288399-4-vsementsov@virtuozzo.com> [eblake: drop depedence on error hint, enhance commit message] Signed-off-by: Eric Blake <eblake@redhat.com> :040000 040000 8cabc7689a7ea1667850d7d670ad4791873ce0a5 80fcc304538a7c7d47d8cb0d15e69cf5f1472ea9 M block :040000 040000 eb3965069b953ae0a5e7f00169a22c91cc428d81 0dbd45dc86117204869fb8f5bae584be07806d5b M tests Rich. -- Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones Read my programming and virtualization blog: http://rwmj.wordpress.com Fedora Windows cross-compiler. Compile Windows programs, test, and build Windows installers. Over 100 libraries supported. http://fedoraproject.org/wiki/MinGW
Eric Blake
2019-Mar-23 17:48 UTC
Re: [Libguestfs] nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
Adding some cc's; my reply truncates, so if you want to catch up to the full original mail, see https://www.redhat.com/archives/libguestfs/2019-March/msg00124.html On 3/23/19 12:00 PM, Richard W.M. Jones wrote:> On Sat, Mar 23, 2019 at 09:52:41AM -0500, Eric Blake wrote: >> On 3/23/19 7:58 AM, Richard W.M. Jones wrote: >>> NB During this I discovered another (but minor) bug in qemu. If you >>> feed qemu a long series of block status replies then it eventually >>> closes the connection. However it does not print an error message. >>> >> >> Which version(s) of qemu? Was REQ_ONE in force or not? Was it a long >> series of status replies that could have been coalesced, or were they >> alternating status? Did the replies extend beyond the client's original >> request? >> >> I'd like to reproduce the failure, to determine if qemu needs more patches. > > Here's how to reproduce it.... Thanks, that helps.> with the small patch attached to this email on top.> diff --git a/server/protocol.c b/server/protocol.c > index ac6eb2c..d406dc8 100644 > --- a/server/protocol.c > +++ b/server/protocol.c > @@ -503,6 +503,9 @@ send_structured_reply_block_status (struct connection *conn, > if (blocks == NULL) > return connection_set_status (conn, -1); > > + nr_blocks = 32; > + blocks[0].length = htobe32 (4096); > + > reply.magic = htobe32 (NBD_STRUCTURED_REPLY_MAGIC); > reply.handle = handle; > reply.flags = htobe16 (NBD_REPLY_FLAG_DONE); > @@ -526,7 +529,7 @@ send_structured_reply_block_status (struct connection *conn, > > /* Send each block descriptor. */ > for (i = 0; i < nr_blocks; ++i) { > - r = conn->send (conn, &blocks[i], sizeof blocks[i]); > + r = conn->send (conn, &blocks[0], sizeof blocks[0]);So you hack the server into sending adjacent replies that were not coalesced, and sending a reply that covers 128k of the image regardless of how much length the client requested. There are several ways in which that can violate protocol (but hey - testing qemu resiliency is WORTH temporary protocol violations): - If the client requested REQ_ONE, you sent too many extents (sadly, qemu still uses REQ_ONE always, even though I'd like to lift that restriction in the future; the rest of my bullets are applicable when REQ_ONE is not in use) - If the client requested an offset that is less than 128k from end-of-image, you sent a reply that exceeds the advertised image size - If the client requested a length < 127k, you sent too many extents But there are other situations where your reply is valid: - If the client requested a length in [127k, 128k), your reply gave more information than the client asked for, but the protocol allows that because your extra information lies in the final extent when REQ_ONE is not in use - If the client requested a length > 128k, your reply ended early, but the protocol allows that> ./nbdkit -fv memory size=64M \ > --run '/path/to/qemu-img convert $nbd /var/tmp/out' > > You should see: > > nbdkit: memory.0: debug: pread count=512 offset=0 > nbdkit: memory.1: debug: extents count=67108864 offset=0 req_one=1 > nbdkit: memory.3: debug: client sent NBD_CMD_DISC, closing connection > nbdkit: memory.3: debug: exiting worker thread memory.3 >So the immediate NBD_CMD_DISC is reasonable, implying that the client flagged one of the ways you could have violated protocol (but whether qemu should just hang up, or should just ignore that particular reply but still keep the connection alive, is a QoI question for qemu).> and qemu-img exits with code 1, but there is no message printed. > (You can use --run '... || echo FAIL' if you don't believe that > qemu-img is exiting with a failure.) > > While preparing this email I noticed that v3.1.0 printed an > error message: > > qemu-img: Protocol error: invalid payload for NBD_REPLY_TYPE_BLOCK_STATUSWhich says that qemu used to be noisy at diagnosing the protocol error, and now it is not. Ideally, qemu as a client shouldn't encounter a server that is violating protocol, but when it does, it makes sense for qemu to call attention to the buggy server. That sounds like a regression in qemu worth fixing, so I'll whip up a patch.> > So I have bisected this to the following commit: > > d8b4bad846f08ff0f167b46dc156a5310b750484 is the first bad commit > commit d8b4bad846f08ff0f167b46dc156a5310b750484 > Author: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> > Date: Fri Nov 2 18:11:52 2018 +0300 > > block/nbd-client: use traces instead of noisy error_report_errThat's also helpful, as it pinpoints where we regressed at flagging the protocol error. -- Eric Blake, Principal Software Engineer Red Hat, Inc. +1-919-301-3226 Virtualization: qemu.org | libvirt.org
Maybe Matching Threads
- Re: nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
- Re: nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
- nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
- Re: nbdkit & qemu 2.12: qemu-img: Protocol error: simple reply when structured reply chunk was expected
- [PATCH v2 1/6] spec: Recommend cap on NBD_REPLY_TYPE_BLOCK_STATUS length