Re: [patch v0] qapi/qmp: Add timestamps to qmp command responses.

[Markus Armbruster <armbru@redhat.com>]

Daniel P. Berrangé <berrange@redhat.com> writes:

> On Mon, Sep 26, 2022 at 12:59:40PM +0300, Denis Plotnikov wrote:
>> Add "start" & "end" timestamps to qmp command responses.
>> It's disabled by default, but can be enabled with 'timestamp=on'
>> monitor's parameter, e.g.:
>>     -chardev  socket,id=mon1,path=/tmp/qmp.socket,server=on,wait=off
>>     -mon chardev=mon1,mode=control,timestamp=on
>
> I'm not convinced a cmdline flag is the right approach here.
>
> I think it ought be something defined by the QMP spec.

The QMP spec is docs/interop/qmp-spec.txt.  The feature needs to be
defined there regardless of how we control it.

> The "QMP" greeting should report "timestamp" capabilities.
>
> The 'qmp_capabilities' command can be used to turn on this
> capability for all commands henceforth.

Yes, this is how optional QMP protocol features should be controlled.

Bonus: control is per connection, not just globally.

> As an option extra, the 'execute' command could gain a
> parameter to allow this to be requested for only an
> individual command.

Needs a use case.

> Alternatively we could say the overhead of adding the timestmaps
> is small enough that we just add this unconditionally for
> everything hence, with no opt-in/opt-out.

Yes, because the extension is backwards compatible.

Aside: qmp-spec.txt could be clearer on what that means.

>> Example of result:
>> 
>>     ./qemu/scripts/qmp/qmp-shell /tmp/qmp.socket
>> 
>>     (QEMU) query-status
>>     {"end": {"seconds": 1650367305, "microseconds": 831032},
>>      "start": {"seconds": 1650367305, "microseconds": 831012},
>>      "return": {"status": "running", "singlestep": false, "running": true}}
>> 
>> The responce of the qmp command contains the start & end time of
>> the qmp command processing.

Seconds and microseconds since when?  The update to qmp-spec.txt should
tell.

Why split the time into seconds and microseconds?  If you use
microseconds since the Unix epoch (1970-01-01 UTC), 64 bit unsigned will
result in a year 586524 problem:

    $ date --date "@`echo '2^64/1000000' | bc`"
    Wed Jan 19 09:01:49 CET 586524

Even a mere 53 bits will last until 2255.

>> These times may be helpful for the management layer in understanding of
>> the actual timeline of a qmp command processing.
>
> Can you explain the problem scenario in more detail.

Yes, please, because:

> The mgmt app already knows when it send the QMP command and knows
> when it gets the QMP reply.  This covers the time the QMP was
> queued before processing (might be large if QMP is blocked on
> another slow command) , the processing time, and the time any
> reply was queued before sending (ought to be small).
>
> So IIUC, the value these fields add is that they let the mgmt
> app extract only the command processing time, eliminating
> any variance do to queue before/after.
>
>> Suggested-by: Andrey Ryabinin <arbn@yandex-team.ru>
>> Signed-off-by: Denis Plotnikov <den-plotnikov@yandex-team.ru>