Re: [PATCH] trace2: log progress time and throughput
- From
- Jeff Hostetler <git@jeffhostetler.com>
- Date
- May 15, 2020, 19:44 UTC
- Message-ID
- <369ab235-e23a-712a-d2bf-82735194ceff@jeffhostetler.com>
- In-Reply-To
- <90f800d5-c647-6750-52d1-da973f036bd0@jeffhostetler.com>
On 5/15/20 3:37 PM, Jeff Hostetler wrote:
Show 41 quoted lines
>
>
> On 5/12/20 5:44 PM, Emily Shaffer wrote:
>> Rather than teaching only one operation, like 'git fetch', how to write
>> down throughput to traces, we can learn about a wide range of user
>> operations that may seem slow by adding tooling to the progress library
>> itself. Operations which display progress are likely to be slow-running
>> and the kind of thing we want to monitor for performance anyways. By
>> showing object counts and data transfer size, we should be able to
>> make some derived measurements to ensure operations are scaling the way
>> we expect.
>>
>> Signed-off-by: Emily Shaffer <emilyshaffer@google.com>
>
> We need to be careful here. The region_enter and _leave calls need
> to always be properly nested. Having an implicit region within the
> progress code means the code path between all of the different start_
> and stop_progress calls need to not interleave with explicit regions.
>
> How about putting something like this in stop_progress:
>
> struct json_writer jw = JSON_WRITER_INIT;
> jw_object_begin(&jw, 0);
> jw_object_intmax(&jw, "total", p->total);
> if (p->throughput)
> jw_object_intmax(&jw, "throughput", p->throughput->curr_total);
> /*
> * and so on...
> * and maybe include the elapsed time in since the start_progress.
> */
> jw_end(&jw);
> trace2_data_json("progress", NULL, p->title, &jw);
> jw_release(&jw);
>
> That will give you a single record summary of the progress meter
> and you won't have to worry about any interleaving.
>
> You could also add a bit to `struct progress` to let you opt-in
> or opt-out of the message on a case-by-case basis.
>
> JeffHit send too quickly...
One of the advantages of a "data_json" event is that it will keep the multiple values together in one event. This makes it easier to correlate them during post processing.
For example, you could grep for "\"data_json\".*\"progress\".*<title>" and easily parse and see the total and time and etc in one record.