| Message ID | pull.1598.git.1697040242703.gitgitgadget@gmail.com (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | upload-pack: add tracing for fetches | expand |
On Wed, Oct 11, 2023 at 04:04:02PM +0000, Robert Coup via GitGitGadget wrote: > diff --git a/t/t5500-fetch-pack.sh b/t/t5500-fetch-pack.sh > index d18f2823d86..bb15ac34f77 100755 > --- a/t/t5500-fetch-pack.sh > +++ b/t/t5500-fetch-pack.sh > @@ -132,13 +132,18 @@ test_expect_success 'single branch object count' ' > ' > > test_expect_success 'single given branch clone' ' > - git clone --single-branch --branch A "file://$(pwd)/." branch-a && > - test_must_fail git --git-dir=branch-a/.git rev-parse origin/B > + GIT_TRACE2_EVENT="$(pwd)/branch-a/trace2_event" \ > + git clone --single-branch --branch A "file://$(pwd)/." branch-a && > + test_must_fail git --git-dir=branch-a/.git rev-parse origin/B && > + grep \"fetch-info\".*\"haves\":0 branch-a/trace2_event && > + grep \"fetch-info\".*\"wants\":1 branch-a/trace2_event Not at all related to your patch here, but I feel like we have a bunch of these greps sprinkled throughout the test suite which serve to inspect some key(s) of a JSON object printed to the trace2 event stream. It might be nice to have a more robust test-tool that could do this heavy lifting for us instead of having to write these grep expressions ourselves. But definitely outside the scope of this patch ;-). Thanks, Taylor
On Wed, Oct 11, 2023 at 04:04:02PM +0000, Robert Coup via GitGitGadget wrote: > From: Robert Coup <robert@coup.net.nz> > > Information on how users are accessing hosted repositories can be > helpful to server operators. For example, being able to broadly > differentiate between fetches and initial clones; the use of shallow > repository features; or partial clone filters. Indeed. One of the custom patches that GitHub is carrying in its private fork is something similar to this that dumps information from upload-pack into a custom logging system specific to GitHub (called "sockstat", in case anybody was curious). I suspect that we would still live with that patch because we depend on some of the custom logging infrastructure provided by sockstat, but this is definitely a good direction to be pursuing for git.git nonetheless. > @@ -1552,6 +1553,32 @@ static int parse_have(const char *line, struct oid_array *haves) > return 0; > } > > +static void trace2_fetch_info(struct upload_pack_data *data) > +{ > + struct json_writer jw = JSON_WRITER_INIT; > + > + jw_object_begin(&jw, 0); > + { Is there a reason that we have a separate scope here? I think we may want to drop this as unnecessary, but it's entirely possible that I'm missing something here... > + jw_object_intmax(&jw, "haves", data->haves.nr); > + jw_object_intmax(&jw, "wants", data->want_obj.nr); > + jw_object_intmax(&jw, "want-refs", data->wanted_refs.nr); > + jw_object_intmax(&jw, "depth", data->depth); > + jw_object_intmax(&jw, "shallows", data->shallows.nr); > + jw_object_bool(&jw, "deepen-since", data->deepen_since); > + jw_object_intmax(&jw, "deepen-not", data->deepen_not.nr); > + jw_object_bool(&jw, "deepen-relative", data->deepen_relative); > + if (data->filter_options.choice) > + jw_object_string(&jw, "filter", list_object_filter_config_name(data->filter_options.choice)); I'm pretty sure that list_object_filter_config_name() returns characters that are safe for JSON-encoding, and/or that jw_object_string() does any quoting beforehand, but worth checking nonetheless. > + else > + jw_object_null(&jw, "filter"); These all seem like useful things to have. Thanks, Taylor
On Wed, Oct 11, 2023 at 04:04:02PM +0000, Robert Coup via GitGitGadget wrote: > Improve this by emitting a Trace2 JSON event from upload-pack with > summary information on the contents of a fetch request. > > * haves, wants, and want-ref counts can help determine (broadly) between > fetches and clones, and the use of single-branch, etc. > * shallow clone depth, tip counts, and deepening options. > * any partial clone filter type. I think this is a reasonable thing to have. I see Taylor left a more detailed review, but I did notice one thing... > +static void trace2_fetch_info(struct upload_pack_data *data) > +{ > + struct json_writer jw = JSON_WRITER_INIT; > + > + jw_object_begin(&jw, 0); > + { > + jw_object_intmax(&jw, "haves", data->haves.nr); > + jw_object_intmax(&jw, "wants", data->want_obj.nr); > + jw_object_intmax(&jw, "want-refs", data->wanted_refs.nr); > + jw_object_intmax(&jw, "depth", data->depth); > + jw_object_intmax(&jw, "shallows", data->shallows.nr); > + jw_object_bool(&jw, "deepen-since", data->deepen_since); > + jw_object_intmax(&jw, "deepen-not", data->deepen_not.nr); > + jw_object_bool(&jw, "deepen-relative", data->deepen_relative); > + if (data->filter_options.choice) > + jw_object_string(&jw, "filter", list_object_filter_config_name(data->filter_options.choice)); > + else > + jw_object_null(&jw, "filter"); > + } > + jw_end(&jw); > + > + trace2_data_json("upload-pack", the_repository, "fetch-info", &jw); > + > + jw_release(&jw); > +} Generating the json output isn't entirely trivial (and certainly involves allocations), but we throw it away unused if tracing isn't enabled. Maybe we'd want something like: if (!trace2_is_enabled()) return; at the top of the function? It looks like other callers of jw_object_begin() have a similar issue, and this is probably premature optimization to some degree. It just feels like it should be easy for tracing to be zero-cost (beyond a single conditional) when it's disabled. -Peff
Hi Taylor, Thanks for taking a look. On Wed, 11 Oct 2023 at 22:32, Taylor Blau <me@ttaylorr.com> wrote: > > One of the custom patches that GitHub is carrying in its private > fork is something similar to this that dumps information from > upload-pack into a custom logging system specific to GitHub I suspected as much. My initial goal is clones vs fetches, filter use, and shallow use... since I'm changing code is there anything else that you think is worthwhile instrumenting? I thought about casting the ints to booleans (ie: >0 haves; >0 wants; etc) but I figured the actual numbers might come in handy at some point, and changing them back in future would be incompatible. I deliberately didn't add thin/ofs/etc flags: most of that stuff is on by default now so it felt like noise. > > + jw_object_begin(&jw, 0); > > + { > > Is there a reason that we have a separate scope here? I think we may > want to drop this as unnecessary, but it's entirely possible that I'm > missing something here... I just followed the patterns in test-json-writer.c - personally I think since JSON objects/arrays have starts & ends then it's easy to read. But one person's readable is another's coding style violation ;-) > > + jw_object_string(&jw, "filter", list_object_filter_config_name(data->filter_options.choice)); > > I'm pretty sure that list_object_filter_config_name() returns characters > that are safe for JSON-encoding, and/or that jw_object_string() does any > quoting beforehand, but worth checking nonetheless. Yes, jw_object_string() calls append_quoted_string() which deals with escaping and quoting. Thanks, Rob :)
Hi Jeff, On Wed, 11 Oct 2023 at 23:27, Jeff King <peff@peff.net> wrote: > I think this is a reasonable thing to have. Thanks for taking a look > Generating the json output isn't entirely trivial (and certainly > involves allocations), but we throw it away unused if tracing isn't > enabled. Maybe we'd want something like: > > if (!trace2_is_enabled()) > return; > > at the top of the function? It looks like other callers of > jw_object_begin() have a similar issue, and this is probably premature > optimization to some degree. It just feels like it should be easy for > tracing to be zero-cost (beyond a single conditional) when it's > disabled. This definitely makes sense to me. Will add to a v2. Thanks, Rob :)
diff --git a/t/t5500-fetch-pack.sh b/t/t5500-fetch-pack.sh index d18f2823d86..bb15ac34f77 100755 --- a/t/t5500-fetch-pack.sh +++ b/t/t5500-fetch-pack.sh @@ -132,13 +132,18 @@ test_expect_success 'single branch object count' ' ' test_expect_success 'single given branch clone' ' - git clone --single-branch --branch A "file://$(pwd)/." branch-a && - test_must_fail git --git-dir=branch-a/.git rev-parse origin/B + GIT_TRACE2_EVENT="$(pwd)/branch-a/trace2_event" \ + git clone --single-branch --branch A "file://$(pwd)/." branch-a && + test_must_fail git --git-dir=branch-a/.git rev-parse origin/B && + grep \"fetch-info\".*\"haves\":0 branch-a/trace2_event && + grep \"fetch-info\".*\"wants\":1 branch-a/trace2_event ' test_expect_success 'clone shallow depth 1' ' - git clone --no-single-branch --depth 1 "file://$(pwd)/." shallow0 && - test "$(git --git-dir=shallow0/.git rev-list --count HEAD)" = 1 + GIT_TRACE2_EVENT="$(pwd)/shallow0/trace2_event" \ + git clone --no-single-branch --depth 1 "file://$(pwd)/." shallow0 && + test "$(git --git-dir=shallow0/.git rev-list --count HEAD)" = 1 && + grep \"fetch-info\".*\"depth\":1 shallow0/trace2_event ' test_expect_success 'clone shallow depth 1 with fsck' ' @@ -235,7 +240,10 @@ test_expect_success 'add two more (part 2)' ' test_expect_success 'deepening pull in shallow repo' ' ( cd shallow && - git pull --depth 4 .. B + GIT_TRACE2_EVENT="$(pwd)/trace2_event" \ + git pull --depth 4 .. B && + grep \"fetch-info\".*\"depth\":4 trace2_event && + grep \"fetch-info\".*\"shallows\":2 trace2_event ) ' @@ -306,9 +314,12 @@ test_expect_success 'fetch --depth --no-shallow' ' test_expect_success 'turn shallow to complete repository' ' ( cd shallow && - git fetch --unshallow && + GIT_TRACE2_EVENT="$(pwd)/trace2_event" \ + git fetch --unshallow && ! test -f .git/shallow && - git fsck --full + git fsck --full && + grep \"fetch-info\".*\"shallows\":2 trace2_event && + grep \"fetch-info\".*\"depth\":2147483647 trace2_event ) ' @@ -826,13 +837,15 @@ test_expect_success 'clone shallow since ...' ' ' test_expect_success 'fetch shallow since ...' ' - git -C shallow11 fetch --shallow-since "200000000 +0700" origin && + GIT_TRACE2_EVENT=$(pwd)/shallow11/trace2_event \ + git -C shallow11 fetch --shallow-since "200000000 +0700" origin && git -C shallow11 log --pretty=tformat:%s origin/main >actual && cat >expected <<-\EOF && three two EOF - test_cmp expected actual + test_cmp expected actual && + grep \"fetch-info\".*\"deepen-since\":true shallow11/trace2_event ' test_expect_success 'clone shallow since selects no commits' ' @@ -987,13 +1000,16 @@ test_expect_success 'filtering by size' ' test_config -C server uploadpack.allowfilter 1 && test_create_repo client && - git -C client fetch-pack --filter=blob:limit=0 ../server HEAD && + GIT_TRACE2_EVENT=$(pwd)/client/trace2_event \ + git -C client fetch-pack --filter=blob:limit=0 ../server HEAD && # Ensure that object is not inadvertently fetched commit=$(git -C server rev-parse HEAD) && blob=$(git hash-object server/one.t) && git -C client rev-list --objects --missing=allow-any "$commit" >oids && - ! grep "$blob" oids + ! grep "$blob" oids && + + grep \"fetch-info\".*\"filter\":\"blob:limit\" client/trace2_event ' test_expect_success 'filtering by size has no effect if support for it is not advertised' ' diff --git a/upload-pack.c b/upload-pack.c index 83f3d2651ab..165c1c6350a 100644 --- a/upload-pack.c +++ b/upload-pack.c @@ -33,6 +33,7 @@ #include "commit-reach.h" #include "shallow.h" #include "write-or-die.h" +#include "json-writer.h" /* Remember to update object flag allocation in object.h */ #define THEY_HAVE (1u << 11) @@ -1552,6 +1553,32 @@ static int parse_have(const char *line, struct oid_array *haves) return 0; } +static void trace2_fetch_info(struct upload_pack_data *data) +{ + struct json_writer jw = JSON_WRITER_INIT; + + jw_object_begin(&jw, 0); + { + jw_object_intmax(&jw, "haves", data->haves.nr); + jw_object_intmax(&jw, "wants", data->want_obj.nr); + jw_object_intmax(&jw, "want-refs", data->wanted_refs.nr); + jw_object_intmax(&jw, "depth", data->depth); + jw_object_intmax(&jw, "shallows", data->shallows.nr); + jw_object_bool(&jw, "deepen-since", data->deepen_since); + jw_object_intmax(&jw, "deepen-not", data->deepen_not.nr); + jw_object_bool(&jw, "deepen-relative", data->deepen_relative); + if (data->filter_options.choice) + jw_object_string(&jw, "filter", list_object_filter_config_name(data->filter_options.choice)); + else + jw_object_null(&jw, "filter"); + } + jw_end(&jw); + + trace2_data_json("upload-pack", the_repository, "fetch-info", &jw); + + jw_release(&jw); +} + static void process_args(struct packet_reader *request, struct upload_pack_data *data) { @@ -1640,6 +1667,8 @@ static void process_args(struct packet_reader *request, if (request->status != PACKET_READ_FLUSH) die(_("expected flush after fetch arguments")); + + trace2_fetch_info(data); } static int process_haves(struct upload_pack_data *data, struct oid_array *common)