07.08.2018 22:57, Eric Blake wrote:
On 08/06/2018 05:04 PM, Eric Blake wrote:
On 06/18/2018 11:44 AM, Kevin Wolf wrote:
From: Greg Kurz <address@hidden>
Removing a drive with drive_del while it is being used to run an I/O
intensive workload can cause QEMU to crash.
...
Test 83 sets up a client that intentionally disconnects at critical
points in the NBD protocol exchange, to ensure that the server
reacts sanely.
Rather, nbd-fault-injector.py is a server that disconnects at
critical points, and the test is of client reaction.
I suspect that somewhere in the NBD code, the server detects the
disconnect and was somehow calling into blk_remove_bs() (although I
could not quickly find the backtrace); and that prior to this patch,
the 'Connection closed' message resulted from other NBD coroutines
getting a shot at the (now-closed) connection, while after this
patch, the additional blk_drain() somehow tweaks things in a way
that prevents the other NBD coroutines from printing a message. If
so, then the change in 83 reference output is probably intentional,
and we should update it.
It seems like this condition is racy, and that the race is more
likely to be lost prior to this patch than after. It's a question of
whether the client has time to start a request to the server prior to
the server hanging up, as the message is generated during
nbd_co_do_receive_one_chunk. Here's a demonstration of the fact that
things are racy:
$ git revert f45280cbf
$ make
$ cd tests/qemu-iotests
$ cat fault.txt
[inject-error "a"]
event=neg2
when=after
$ python nbd-fault-injector.py localhost:10809 ./fault.txt &
Listening on 127.0.0.1:10809
$ ../../qemu-io -f raw nbd://localhost:10809 -c 'r 0 512'
Closing connection on rule match inject-error "a"
Connection closed
read failed: Input/output error
$ python nbd-fault-injector.py localhost:10809 ./fault.txt &
Listening on 127.0.0.1:10809
$ ../../qemu-io -f raw nbd://localhost:10809
Closing connection on rule match inject-error "a"
qemu-io> r 0 512
read failed: Input/output error
qemu-io> q
So, depending on whether the read command is kicked off quickly (via
-c) or slowly (via typing into qemu-io) determines whether the
message appears.
What's more, in commit f140e300, we specifically called out in the
commit message that maybe it was better to trace when we detect
connection closed rather than log it to stdout, and in all cases in
that commit, the additional 'Connection closed' messages do not add
any information to the error message already displayed by the rest of
the code.
I don't know how much the proposed NBD reconnect code will change
things in 3.1. Meanwhile, we've missed any chance for 3.0 to fix
test 83.
But I'm having a hard time convincing myself that this is the case,
particularly since I'm not even sure how to easily debug the
assumptions I made above.
Since I'm very weak on the whole notion of what blk_drain() vs.
blk_remove_bs() is really supposed to be doing, and could easily be
persuaded that the change in output is a regression instead of a fix.
At this point, I don't think we have a regression, just merely a bad
iotests reference output. The extra blk_drain() merely adds more time
before the NBD code can send out its first request, and thus makes it
more likely that the fault injector has closed the connection before
the read request is issued rather than after (the message only
appears when read beats the race), but the NBD code shouldn't be
printing the error message in the first place, and 083 needs to be
tweaked to remove the noisy lines added in f140e300 (not just the
three lines that are reliably different due to this patch, but all
other such lines due to strategic server drops at other points in the
NBD protocol).
Ok, agree, I'll do it in reconnect series.