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.
+ 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
