On 2022.07.25 20:04, Jeff Hostetler wrote:
>
>
> On 7/25/22 6:13 PM, Josh Steadmon wrote:
> > Currently, negotiation for V0/V1/V2 fetch have trace2 regions covering
> > the entire negotiation process. However, we'd like additional data, such
> > as timing for each round of negotiation or the number of "haves" in each
> > round. Additionally, "independent negotiation" (AKA push negotiation)
> > has no tracing at all. Having this data would allow us to compare the
> > performance of the various negotation implementations, and to debug
> > unexpectedly slow fetch & push sessions.
> >
> > Fix this by adding per-round trace2 regions for all negotiation
> > implementations (V0+V1, V2, and independent negotiation), as well as an
> > overall region for independent negotiation. Add trace2 data logging for
> > the number of haves and "in vain" objects for each round, and for the
> > total number of rounds once negotiation completes. Finally, add a few
> > checks into various tests to verify that the number of rounds is logged
> > as expected.
>
> I've been wanting to add data like this around the negotiation
> code for a while now. Thanks!
>
> >
> > Signed-off-by: Josh Steadmon <steadmon@xxxxxxxxxx>
> > ---
> > fetch-pack.c | 62 +++++++++++++++++++++++++++++-
> > t/t5500-fetch-pack.sh | 4 +-
> > t/t5516-fetch-push.sh | 10 ++++-
> > t/t5601-clone.sh | 6 ++-
> > t/t5703-upload-pack-ref-in-want.sh | 6 ++-
> > 5 files changed, 81 insertions(+), 7 deletions(-)
> >
> > diff --git a/fetch-pack.c b/fetch-pack.c
> > index cb6647d657..01a451e456 100644
> > --- a/fetch-pack.c
> > +++ b/fetch-pack.c
> > @@ -299,6 +299,7 @@ static int find_common(struct fetch_negotiator *negotiator,
> > {
> > int fetching;
> > int count = 0, flushes = 0, flush_at = INITIAL_FLUSH, retval;
> > + int negotiation_round = 0, haves = 0;
> > const struct object_id *oid;
> > unsigned in_vain = 0;
> > int got_continue = 0;
> > @@ -441,9 +442,19 @@ static int find_common(struct fetch_negotiator *negotiator,
> > packet_buf_write(&req_buf, "have %s\n", oid_to_hex(oid));
> > print_verbose(args, "have %s", oid_to_hex(oid));
> > in_vain++;
> > + haves++;
> > if (flush_at <= ++count) {
> > int ack;
> > + negotiation_round++;
> > + trace2_region_enter_printf("negotiation_v0_v1", "round",
> > + the_repository, "round-%d",
> > + negotiation_round);
>
> I'm wondering here if the "round-%d" should have some number
> of leading zeros so that multiple rounds will sort correctly
> when you have a bunch of them.
>
> I'm also wondering (and this is more of a style thing, so feel
> free to ignore) if we could just use trace2_region_enter()
> and make the "label" field be the "round/%04d" and not need
> the extra args.
Junio suggested just dropping the prefix altogether, so that's what I've
done for V2, but if you feel strongly about it we can discuss further
for V3.
> > + trace2_data_intmax("negotiation_v0_v1", the_repository,
> > + "haves_added", haves);
> > + trace2_data_intmax("negotiation_v0_v1", the_repository,
> > + "in_vain", in_vain);
> > + haves = 0;
>
> Thanks,
> Jeff
