Re: [Qemu-devel] [PULL 21/35] block: fix QEMU crash with scsi-hd and drive_del

[Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>]

08.08.2018 12:33, Vladimir Sementsov-Ogievskiy wrote:
> 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 <groug@kaod.org>
>>>>
>>>> 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.
>


hmm, do what?

I was going to change these error messages to be traces, but now I'm not 
sure that it's a good idea. We have generic errp returned from the 
function, and why to drop it from logs? Fixing iotest is not a good 
reason, better is to adjust iotest itself a bit (just commit changed 
output) and forget about it. Is iotest racy itself, did you see 
different output running 83 iotest, not testing by hand?

-- 
Best regards,
Vladimir