Re: [Qemu-devel] [PATCH 5/9] monitor: suspend monitor instead of send CMD_DROP

[Markus Armbruster]

Peter Xu <address@hidden> writes:

> On Fri, Jul 06, 2018 at 03:19:56PM +0200, Markus Armbruster wrote:
[...]
>> Your experiment shows the patch succeeds at limiting the response queue
>> length.  However, the "response queue mon->qmp..qmp_requests gets
>> drained into the output buffer mon->outbuf by bottom half
>> monitor_qmp_bh_responder().  The response queue remains small, it's the
>> output buffer that grows without bounds".
>> 
>> To demonstrate that, let me add another tracepoint:
>> 
>> diff --git a/monitor.c b/monitor.c
>> index 3bea239bc7..e35e15b43e 100644
>> --- a/monitor.c
>> +++ b/monitor.c
>> @@ -451,6 +451,7 @@ static void monitor_flush_locked(Monitor *mon)
>>  
>>      buf = qstring_get_str(mon->outbuf);
>>      len = qstring_get_length(mon->outbuf);
>> +    trace_monitor_flush_locked(mon, len);
>>  
>>      if (len && !mon->mux_out) {
>>          rc = qemu_chr_fe_write(&mon->chr, (const uint8_t *) buf, len);
>> diff --git a/trace-events b/trace-events
>> index bd9dade938..b6d5d28041 100644
>> --- a/trace-events
>> +++ b/trace-events
>> @@ -54,6 +54,7 @@ monitor_qmp_suspend(void *mon) "mon=%p"
>>  monitor_qmp_resume(void *mon) "mon=%p"
>>  monitor_qmp_request_queue(void *mon, int len) "mon=%p len=%d"
>>  monitor_qmp_response_queue(void *mon, int len) "mon=%p len=%d"
>> +monitor_flush_locked(void *mon, int len) "mon=%p len=%d"
>>  
>>  # dma-helpers.c
>>  dma_blk_io(void *dbs, void *bs, int64_t offset, bool to_dev) "dbs=%p bs=%p 
>> offset=%" PRId64 " to_dev=%d"
>> 
>> Start this QEMU:
>> 
>>     $ upstream-qemu -chardev socket,id=qmp,path=test-qmp,server=on,wait=off 
>> -mon mode=control,chardev=qmp -display none -nodefaults -trace 
>> enable="monitor_qmp*" -trace enable=monitor_flush_locked
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=2
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=107
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=82
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>> 
>> Now let me feed a couple of commands to that without reading any of
>> their responses.  To do that, run in another terminal:
>> 
>>     $ socat -u STDIO UNIX:test-qmp
>>     { "execute": "qmp_capabilities", "arguments": { "enable": ["oob"] } }
>> 
>> Note that -u makes socat use the first address (STDIO) only for reading,
>> and the second one (the QMP socket) only for writing.  This QMP client
>> fails to read any responses.
>
> This is useful. :)

socat is one of my favorites :)

>> QEMU prints:
>> 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=136
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_suspend mon=0x56192215baf0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_resume mon=0x56192215baf0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=16
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>> 
>> Back in socat, execute a few commands, one after the other, with short
>> pauses in between:
>> 
>>     { "execute": "query-qmp-schema" }
>>     { "execute": "query-qmp-schema" }
>>     { "execute": "query-qmp-schema" }
>>     { "execute": "query-qmp-schema" }
>>     { "execute": "query-qmp-schema" }
>>     { "execute": "quit" }
>> 
>> QEMU prints:
>> 
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=129073
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=129073
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=148514
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=277587
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=406660
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_cmd_in_band 
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=2
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=1
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=406676
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=406787
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_flush_locked mon=0x56192215baf0 len=406787
>>     address@hidden:monitor_qmp_request_queue mon=0x56192215baf0 len=0
>>     address@hidden:monitor_qmp_response_queue mon=0x56192215baf0 len=0
>> 
>> The response queue length stays small (the bottom half drains it just
>> fine), but the output buffer keeps growing.
>
> Yes, I think I understood this part.  Indeed we have an unbound output
> buffer, I think we should fix it somehow, though for now I am not sure
> that'll be a trivial fix for 3.0.  What I wanted to demostrate is that
> the queue limitation is working, so basically we should fix both
> places at last, and this patch fixes the first problem.

The response queue can only grow if the bottom half doesn't run in a
timely manner.  But if bottom halves don't run in a timely manner, we
likely got much bigger problems than queue growth.

> After all IIUC this output buffer problem exists even before the
> out-of-band work, and it's there for at least years.

I agree it's not a blocker bug for OOB.  I'd be fine with a FIXME
comment.

>> >> Marc-André has a patch to cut out the response queue.  Whether it still
>> >> makes sense I don't know.
>> >> [PATCH v3 03/38] Revert "qmp: isolate responses into io thread"
>> >
>> > I think we discussed this before, I agree with Marc-Andre that most of
>> > the codes that are related to response flushing should be thread safe
>> > now.  Actually it was not when we started to draft the out-of-band
>> > thing, and that's the major reason why I refactored my old code to
>> > explicitly separate the dispatcher and the responder, so that
>> > responder can be isolated and be together with the parser.
>> >
>> > I don't have obvious reason to remove this layer of isolation if it
>> > works well (and actually the code is not that much, and IMHO the
>> > response queue is a clear interface that maybe we can use in the
>> > future too), I think my major concern now is that we're in rc phase
>> > for QEMU-3.0 so that it at least seems to be a big change to monitor
>> > layer.  We might consider to revert back to no-responder way if we
>> > really want, but I guess we'd better do as much testing as when we
>> > started to play with out-of-band to make sure we won't miss anything
>> > important (and I guess the patch will need a non-trivial rebase after
>> > we worked upon the queues recently).  Considering that, I don't really
>> > see much help on removing that layer.  Or, do we have any other reason
>> > to remove the response queue that I'm not aware of?
>> 
>> I think we first need to figure out where we want to go.  That includes
>> how to provide flow control.  Then we can decide how far to go in 3.0,
>> and whether we need to detour.
>
> For my own opinion, I'll see it a bit awkward (as I mentioned) to
> revert the response queue part.  Again, it's mostly working well
> there, we just fix things up when needed.  It's not really a big part
> of code to maintain, and it still looks sane to me to have such an
> isolation so that we can have the dispatcher totally separate from the
> chardev IO path (I'd say if I design a QMP interface from scratch,
> I'll do that from the first day).  So I am not against reverting that
> part at all, I just don't see much gain from that as well, especially
> if we want to make QMP more modular in the future.

Since it's not broken, there's no need to mess with it for 3.0, and no
need to have it block OOB.

Marc-André, I trust you'll respin the monitor core parts of "[PATCH v3
00/38] RFC: monitor: add asynchronous command type" as a separate series
for 3.1.  Please include a patch to rip out the response queue if you
think it's a worthwhile simplification.  Our discussion of the response
queue will then be grounded by working patches.