threads / patch / 58171

patchfetch-pack: write effective filter to trace2

Subject: [PATCH] fetch-pack: write effective filter to trace2

## tl;dr

15 messages between Jul 15, 2022 and Jul 26, 2022. Diffs are folded; open one to read it.

replies: 14people: 3as markdown or json

Jonathan Tan· Jul 15, 2022, 17:29 UTC · lore

Administrators of a managed Git environment (like the one at $DAYJOB) might want to quantify the performance change of fetches with and without partial clone from the client's point of view. Therefore, log the effective filter being sent to the server whenever a fetch (or clone) occurs. Note that this is not necessarily the same as what's specified on the CLI, because during a fetch, the configured filter is used whenever a filter is not specified on the CLI.

This is implemented for protocol v0, v1, and v2.
Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
---
 fetch-pack.c | 10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)
Show changes to fetch-pack.c +8 −2
diff --git a/fetch-pack.c b/fetch-pack.c
index cb6647d657..dec8743bec 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -392,7 +392,10 @@ static int find_common(struct fetch_negotiator *negotiator,
 	if (server_supports_filtering && args->filter_options.choice) {
 		const char *spec =
 			expand_list_objects_filter_spec(&args->filter_options);
+		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
 		packet_buf_write(&req_buf, "filter %s", spec);
+	} else {
+		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
 	}
 	packet_buf_flush(&req_buf);
 	state_len = req_buf.len;
@@ -1328,9 +1331,12 @@ static int send_fetch_request(struct fetch_negotiator *negotiator, int fd_out,
 		const char *spec =
 			expand_list_objects_filter_spec(&args->filter_options);
 		print_verbose(args, _("Server supports filter"));
+		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
 		packet_buf_write(&req_buf, "filter %s", spec);
-	} else if (args->filter_options.choice) {
-		warning("filtering not recognized by server, ignoring");
+	} else {
+		if (args->filter_options.choice)
+			warning("filtering not recognized by server, ignoring");
+		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
 	}
 
 	if (server_supports_feature("fetch", "packfile-uris", 0)) {
-- 
2.37.0.170.g444d1eabd0-goog
Jeff Hostetler· Jul 15, 2022, 17:38 UTC · re: Jonathan Tan · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

On 7/15/22 1:29 PM, Jonathan Tan wrote:
Show 46 quoted lines
> Administrators of a managed Git environment (like the one at $DAYJOB)
> might want to quantify the performance change of fetches with and
> without partial clone from the client's point of view. Therefore, log
> the effective filter being sent to the server whenever a fetch (or
> clone) occurs. Note that this is not necessarily the same as what's
> specified on the CLI, because during a fetch, the configured filter is
> used whenever a filter is not specified on the CLI.
> 
> This is implemented for protocol v0, v1, and v2.
> 
> Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
> ---
>   fetch-pack.c | 10 ++++++++--
>   1 file changed, 8 insertions(+), 2 deletions(-)
> 
> diff --git a/fetch-pack.c b/fetch-pack.c
> index cb6647d657..dec8743bec 100644
> --- a/fetch-pack.c
> +++ b/fetch-pack.c
> @@ -392,7 +392,10 @@ static int find_common(struct fetch_negotiator *negotiator,
>   	if (server_supports_filtering && args->filter_options.choice) {
>   		const char *spec =
>   			expand_list_objects_filter_spec(&args->filter_options);
> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
>   		packet_buf_write(&req_buf, "filter %s", spec);
> +	} else {
> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
>   	}
>   	packet_buf_flush(&req_buf);
>   	state_len = req_buf.len;
> @@ -1328,9 +1331,12 @@ static int send_fetch_request(struct fetch_negotiator *negotiator, int fd_out,
>   		const char *spec =
>   			expand_list_objects_filter_spec(&args->filter_options);
>   		print_verbose(args, _("Server supports filter"));
> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
>   		packet_buf_write(&req_buf, "filter %s", spec);
> -	} else if (args->filter_options.choice) {
> -		warning("filtering not recognized by server, ignoring");
> +	} else {
> +		if (args->filter_options.choice)
> +			warning("filtering not recognized by server, ignoring");
> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
>   	}
>   
>   	if (server_supports_feature("fetch", "packfile-uris", 0)) {
> 

This looks nice. Thanks! Jeff

Junio C Hamano· Jul 15, 2022, 18:28 UTC · re: Jeff Hostetler · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Jeff Hostetler <git@jeffhostetler.com> writes:
Show 9 quoted lines
> On 7/15/22 1:29 PM, Jonathan Tan wrote:
>> Administrators of a managed Git environment (like the one at $DAYJOB)
>> might want to quantify the performance change of fetches with and
>> without partial clone from the client's point of view. Therefore, log
>> the effective filter being sent to the server whenever a fetch (or
>> clone) occurs. Note that this is not necessarily the same as what's
>> specified on the CLI, because during a fetch, the configured filter is
>> used whenever a filter is not specified on the CLI.
>> This is implemented for protocol v0, v1, and v2.

Is that different to say "for all protocols"? I am wondering if it is worth saying (unlike in a hypothetical case where we do not support v0 and v1 we may want to state why we only support v2).

Show 16 quoted lines
>> Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
>> ---
>>   fetch-pack.c | 10 ++++++++--
>>   1 file changed, 8 insertions(+), 2 deletions(-)
>> diff --git a/fetch-pack.c b/fetch-pack.c
>> index cb6647d657..dec8743bec 100644
>> --- a/fetch-pack.c
>> +++ b/fetch-pack.c
>> @@ -392,7 +392,10 @@ static int find_common(struct fetch_negotiator *negotiator,
>>   	if (server_supports_filtering && args->filter_options.choice) {
>>   		const char *spec =
>>   			expand_list_objects_filter_spec(&args->filter_options);
>> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
>>   		packet_buf_write(&req_buf, "filter %s", spec);
>> +	} else {
>> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");

Do we show "none" anywhere else where an expanded list objects filter spec is expected?

I am wondering two things: 
 - The lack of this line would be a cleaner implementation of a
   signal to say "this client did not ask any filtering".
 - It would be good if we keep what report here more-or-less the
   same as what we can pass "--filter=" on the command line of
   "git pack-objects".

If "--filter=none" meant "this --filter passes everything", then saying "none" here makes perfect sense wrt the latter, but I doubt it is the case.

Show 15 quoted lines
>>   	}
>>   	packet_buf_flush(&req_buf);
>>   	state_len = req_buf.len;
>> @@ -1328,9 +1331,12 @@ static int send_fetch_request(struct fetch_negotiator *negotiator, int fd_out,
>>   		const char *spec =
>>   			expand_list_objects_filter_spec(&args->filter_options);
>>   		print_verbose(args, _("Server supports filter"));
>> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
>>   		packet_buf_write(&req_buf, "filter %s", spec);
>> -	} else if (args->filter_options.choice) {
>> -		warning("filtering not recognized by server, ignoring");
>> +	} else {
>> +		if (args->filter_options.choice)
>> +			warning("filtering not recognized by server, ignoring");
>> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");

At the first glance, this seems to lose data, because you should be able to use expand_list_objects_filter_spec() to report the filter spec. But this is reporting the filter that was actually in effect, so it is OK.

But the same question about "none" remains.
Show 6 quoted lines
>>   	}
>>     	if (server_supports_feature("fetch", "packfile-uris", 0)) {
>> 
>
> This looks nice.  Thanks!
> Jeff
Will queue with your Acked-by, then?
Thanks, both.
Jonathan Tan· Jul 15, 2022, 19:09 UTC · re: Junio C Hamano · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Junio C Hamano <gitster@pobox.com> writes:
Show 15 quoted lines
> Jeff Hostetler <git@jeffhostetler.com> writes:
> 
> > On 7/15/22 1:29 PM, Jonathan Tan wrote:
> >> Administrators of a managed Git environment (like the one at $DAYJOB)
> >> might want to quantify the performance change of fetches with and
> >> without partial clone from the client's point of view. Therefore, log
> >> the effective filter being sent to the server whenever a fetch (or
> >> clone) occurs. Note that this is not necessarily the same as what's
> >> specified on the CLI, because during a fetch, the configured filter is
> >> used whenever a filter is not specified on the CLI.
> >> This is implemented for protocol v0, v1, and v2.
> 
> Is that different to say "for all protocols"?  I am wondering if it
> is worth saying (unlike in a hypothetical case where we do not
> support v0 and v1 we may want to state why we only support v2).

I wrote it that way to avoid confusion with things like HTTP (which is a protocol, at least in its name). Maybe better would be "This is implemented for all protocols (v0, v1, and v2)". I'll make that change in the commit message (after the other questions are discussed).

Show 15 quoted lines
> >> diff --git a/fetch-pack.c b/fetch-pack.c
> >> index cb6647d657..dec8743bec 100644
> >> --- a/fetch-pack.c
> >> +++ b/fetch-pack.c
> >> @@ -392,7 +392,10 @@ static int find_common(struct fetch_negotiator *negotiator,
> >>   	if (server_supports_filtering && args->filter_options.choice) {
> >>   		const char *spec =
> >>   			expand_list_objects_filter_spec(&args->filter_options);
> >> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
> >>   		packet_buf_write(&req_buf, "filter %s", spec);
> >> +	} else {
> >> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
> 
> Do we show "none" anywhere else where an expanded list objects
> filter spec is expected?
Hmm...no, we don't.
> I am wondering two things: 
> 
>  - The lack of this line would be a cleaner implementation of a
>    signal to say "this client did not ask any filtering".

I think the presence is important to distinguish "no filtering" versus someone using an old Git version that does not emit such traces, but I'm open to changing the "none" to "none-specified" or something like that.

>  - It would be good if we keep what report here more-or-less the
>    same as what we can pass "--filter=" on the command line of
>    "git pack-objects".

My intent is to report what is being sent to the server in the fetch request.

> If "--filter=none" meant "this --filter passes everything", then
> saying "none" here makes perfect sense wrt the latter, but I doubt
> it is the case.

--filter=none does not work (a user would have to specify --no-filter), although it conceptually makes sense. I just wanted to have something show up to indicate that we are using a Git version that would emit a trace.

Junio C Hamano· Jul 15, 2022, 20:10 UTC · re: Jonathan Tan · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Jonathan Tan <jonathantanmy@google.com> writes:
Show 9 quoted lines
>> >> This is implemented for protocol v0, v1, and v2.
>> 
>> Is that different to say "for all protocols"?  I am wondering if it
>> is worth saying (unlike in a hypothetical case where we do not
>> support v0 and v1 we may want to state why we only support v2).
>
> I wrote it that way to avoid confusion with things like HTTP (which is a
> protocol, at least in its name). Maybe better would be "This is
> implemented for all protocols (v0, v1, and v2)".

I still wonder if it is better left unsaid. When adding a new thing, it would not be noteworthy if the new thing is available no matter what protocol is being used, no?

Show 18 quoted lines
>> >> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", spec);
>> >>   		packet_buf_write(&req_buf, "filter %s", spec);
>> >> +	} else {
>> >> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
>> 
>> Do we show "none" anywhere else where an expanded list objects
>> filter spec is expected?
>
> Hmm...no, we don't.
>
>> I am wondering two things: 
>> 
>>  - The lack of this line would be a cleaner implementation of a
>>    signal to say "this client did not ask any filtering".
>
> I think the presence is important to distinguish "no filtering" versus
> someone using an old Git version that does not emit such traces, but I'm
> open to changing the "none" to "none-specified" or something like that.
OK.
Show 6 quoted lines
>>  - It would be good if we keep what report here more-or-less the
>>    same as what we can pass "--filter=" on the command line of
>>    "git pack-objects".
>
> My intent is to report what is being sent to the server in the fetch
> request.

Then I'd be OK with a design that reports "none", if we send "none" to the server in this case. If not, then I do not think we should.

Perhaps report an empty string or not reporting at all? After all, the reader knows the client version and capability in the log so it is easy to tell between 'no filter was used' and 'too old to report the filter', no? I dunno.

Jonathan Tan· Jul 15, 2022, 20:49 UTC · re: Junio C Hamano · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Junio C Hamano <gitster@pobox.com> writes:
Show 15 quoted lines
> Jonathan Tan <jonathantanmy@google.com> writes:
> 
> >> >> This is implemented for protocol v0, v1, and v2.
> >> 
> >> Is that different to say "for all protocols"?  I am wondering if it
> >> is worth saying (unlike in a hypothetical case where we do not
> >> support v0 and v1 we may want to state why we only support v2).
> >
> > I wrote it that way to avoid confusion with things like HTTP (which is a
> > protocol, at least in its name). Maybe better would be "This is
> > implemented for all protocols (v0, v1, and v2)".
> 
> I still wonder if it is better left unsaid.  When adding a new
> thing, it would not be noteworthy if the new thing is available no
> matter what protocol is being used, no?

I was thinking that a reviewer would think "why is this done twice" and wrote this comment to answer this issue in advance, but it makes sense to just remove it. OK - I'll do that.

Show 10 quoted lines
> > My intent is to report what is being sent to the server in the fetch
> > request.
> 
> Then I'd be OK with a design that reports "none", if we send "none"
> to the server in this case.  If not, then I do not think we should.
> 
> Perhaps report an empty string or not reporting at all?  After all,
> the reader knows the client version and capability in the log so it
> is easy to tell between 'no filter was used' and 'too old to report
> the filter', no?  I dunno.

We don't send "none" to the server. If an empty string is OK then I'll use that, since it will make it slightly easier for analysis since we do not have to check against the version (and also to know which version has support for this feature). But I'm OK either way.

Jeff Hostetler· Jul 18, 2022, 14:08 UTC · re: Junio C Hamano · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

On 7/15/22 2:28 PM, Junio C Hamano wrote:
> Jeff Hostetler <git@jeffhostetler.com> writes:
> 
>> On 7/15/22 1:29 PM, Jonathan Tan wrote:
...
Show 8 quoted lines
>>> +		trace2_data_string("fetch", the_repository, "fetch/effective-filter", "none");
> 
> At the first glance, this seems to lose data, because you should be
> able to use expand_list_objects_filter_spec() to report the filter
> spec.  But this is reporting the filter that was actually in effect,
> so it is OK.
> 
> But the same question about "none" remains.

Yeah, the use of "none" gave me pause, but I didn't have a better idea at the time. I guess we have: (a) requested, supported, used. (b) "none used because the server doesn't support it" and (c) "none used because the user didn't request it" cases, right?

Perhaps it would be better to do:
     if (server_supports_filtering && args->filter_options.choice)
         trace2_data_string("fetch", r, "filter/effective", spec);
     else
         trace2_data_string("fetch", r, "filter/unsupported", spec);
Using two different keywords.

So that the log only contains "filter/effective" when it was actually used. And there is no "filter/effective" event when (for whatever reason) it was not in effect.

Then the "filter/unsupported" event helps you with debugging. Did they hit a server that doesn't support filtering or did they have a typo in their filter spec?

Then don't emit a message at all for the "not requested" case. And you can use the Git version number to know how to interpret it. There are other places where we don't bother sending messages where the value is a zero or empty.

Jeff
Junio C Hamano· Jul 18, 2022, 15:53 UTC · re: Jeff Hostetler · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Jeff Hostetler <git@jeffhostetler.com> writes:
Show 6 quoted lines
> Yeah, the use of "none" gave me pause, but I didn't have a better idea
> at the time.  I guess we have:
> (a) requested, supported, used.
> (b) "none used because the server doesn't support it" and
> (c) "none used because the user didn't request it" cases,
> right?

At these sites where the new traces are added, we cannot detect the remaining case (d) "requested by the user, asked for the server, but the server dropped the ball", I think the above covers the possible cases that are interesting to us entirely.

Show 20 quoted lines
> Perhaps it would be better to do:
>     if (server_supports_filtering && args->filter_options.choice)
>         trace2_data_string("fetch", r, "filter/effective", spec);
>     else
>         trace2_data_string("fetch", r, "filter/unsupported", spec);
>
> Using two different keywords.
>
> So that the log only contains "filter/effective" when it was actually
> used.  And there is no "filter/effective" event when (for whatever
> reason) it was not in effect.
>
> Then the "filter/unsupported" event helps you with debugging.  Did they
> hit a server that doesn't support filtering or did they have a typo in
> their filter spec?
>
> Then don't emit a message at all for the "not requested" case.  And you
> can use the Git version number to know how to interpret it.  There are
> other places where we don't bother sending messages where the value is
> a zero or empty.

Sounds alright. We could standardize the other way, which might make the interpretation of individual trace entries independent of the context easier, though.

Thanks.
Jonathan Tan· Jul 18, 2022, 16:18 UTC · re: Junio C Hamano · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Junio C Hamano <gitster@pobox.com> writes:
Show 20 quoted lines
> > Using two different keywords.
> >
> > So that the log only contains "filter/effective" when it was actually
> > used.  And there is no "filter/effective" event when (for whatever
> > reason) it was not in effect.
> >
> > Then the "filter/unsupported" event helps you with debugging.  Did they
> > hit a server that doesn't support filtering or did they have a typo in
> > their filter spec?
> >
> > Then don't emit a message at all for the "not requested" case.  And you
> > can use the Git version number to know how to interpret it.  There are
> > other places where we don't bother sending messages where the value is
> > a zero or empty.
> 
> Sounds alright.  We could standardize the other way, which might
> make the interpretation of individual trace entries independent of
> the context easier, though.
> 
> Thanks.

Thanks for bringing up the use case of debugging a server that we expected to support filtering but doesn't. As for whether we should not send a message when the value is empty, I can see at least one reason for not sending it - to not waste I/O and clutter the trace because of a feature that the user is not using, but fetch is I/O-intensive enough and having the empty message is useful enough (not only do we not need to know which versions have this feature, but we also can be sure that the message wasn't excluded because of some unexpected log filtering or something like that) that I think we should have the empty message. I'll put it in v2 but we can easily remove it if we decide that we don't want it.

Junio C Hamano· Jul 18, 2022, 17:56 UTC · re: Jonathan Tan · lore

Re: [PATCH] fetch-pack: write effective filter to trace2

Jonathan Tan <jonathantanmy@google.com> writes:
Show 7 quoted lines
> ... that the user is not using, but fetch is I/O-intensive enough
> and having the empty message is useful enough (not only do we not need
> to know which versions have this feature, but we also can be sure that
> the message wasn't excluded because of some unexpected log filtering or
> something like that) that I think we should have the empty message. I'll
> put it in v2 but we can easily remove it if we decide that we don't want
> it.

As long as it is clearly documented that "none" is given explicitly when no filtering is requested (Jeff's point of making it possible to tell the reason why we are not requesting is still valid), I think it would be OK. If we are giving enough log entries for "fetch" operation, another "empty" message would not hurt (if the trace for "fetch" is otherwise very quiet, then an unused "empty" may become distracting, but I somehow do not think it is the case).

Thanks.
Jonathan Tan· Jul 18, 2022, 17:00 UTC · re: Jonathan Tan · lore

[PATCH v2] fetch-pack: write effective filter to trace2

Administrators of a managed Git environment (like the one at $DAYJOB) might want to quantify the performance change of fetches with and without filters from the client's point of view, and also detect if a server does not support it. Therefore, log the filter information being sent to the server whenever a fetch (or clone) occurs. Note that this is not necessarily the same as what's specified on the CLI, because during a fetch, the configured filter is used whenever a filter is not specified on the CLI.

Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
---
Thanks everyone for your comments. I've renamed the keys and
distinguished the case in which the server does not support filters
following Jeff's suggestions.
A few small discussion points:
 - whether we need the print_verbose now that we have traces
 - should we log if no filter is specified
 - if yes, what key should it be logged under (I used "filter/none" for
   now)
---
 fetch-pack.c | 40 ++++++++++++++++++++++++++--------------
 1 file changed, 26 insertions(+), 14 deletions(-)
Show changes to fetch-pack.c +26 −14
diff --git a/fetch-pack.c b/fetch-pack.c
index cb6647d657..68820f9a1a 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -292,6 +292,29 @@ static void mark_tips(struct fetch_negotiator *negotiator,
 	return;
 }
 
+static void write_and_trace_filter(struct fetch_pack_args *args,
+				   struct strbuf *req_buf,
+				   int server_supports_filter)
+{
+	if (args->filter_options.choice) {
+		const char *spec =
+			expand_list_objects_filter_spec(&args->filter_options);
+		if (server_supports_filter) {
+			print_verbose(args, _("Server supports filter"));
+			packet_buf_write(req_buf, "filter %s", spec);
+			trace2_data_string("fetch", the_repository,
+					   "filter/effective", spec);
+		} else {
+			warning("filtering not recognized by server, ignoring");
+			trace2_data_string("fetch", the_repository,
+					   "filter/unsupported", spec);
+		}
+	} else {
+		trace2_data_string("fetch", the_repository,
+				   "filter/none", "");
+	}
+}
+
 static int find_common(struct fetch_negotiator *negotiator,
 		       struct fetch_pack_args *args,
 		       int fd[2], struct object_id *result_oid,
@@ -389,11 +412,7 @@ static int find_common(struct fetch_negotiator *negotiator,
 			packet_buf_write(&req_buf, "deepen-not %s", s->string);
 		}
 	}
-	if (server_supports_filtering && args->filter_options.choice) {
-		const char *spec =
-			expand_list_objects_filter_spec(&args->filter_options);
-		packet_buf_write(&req_buf, "filter %s", spec);
-	}
+	write_and_trace_filter(args, &req_buf, server_supports_filtering);
 	packet_buf_flush(&req_buf);
 	state_len = req_buf.len;
 
@@ -1323,15 +1342,8 @@ static int send_fetch_request(struct fetch_negotiator *negotiator, int fd_out,
 		die(_("Server does not support shallow requests"));
 
 	/* Add filter */
-	if (server_supports_feature("fetch", "filter", 0) &&
-	    args->filter_options.choice) {
-		const char *spec =
-			expand_list_objects_filter_spec(&args->filter_options);
-		print_verbose(args, _("Server supports filter"));
-		packet_buf_write(&req_buf, "filter %s", spec);
-	} else if (args->filter_options.choice) {
-		warning("filtering not recognized by server, ignoring");
-	}
+	write_and_trace_filter(args, &req_buf,
+			       server_supports_feature("fetch", "filter", 0));
 
 	if (server_supports_feature("fetch", "packfile-uris", 0)) {
 		int i;
-- 
2.37.0.170.g444d1eabd0-goog
Junio C Hamano· Jul 18, 2022, 19:47 UTC · re: Jonathan Tan · lore

Re: [PATCH v2] fetch-pack: write effective filter to trace2

Jonathan Tan <jonathantanmy@google.com> writes:
Show 22 quoted lines
> +static void write_and_trace_filter(struct fetch_pack_args *args,
> +				   struct strbuf *req_buf,
> +				   int server_supports_filter)
> +{
> +	if (args->filter_options.choice) {
> +		const char *spec =
> +			expand_list_objects_filter_spec(&args->filter_options);
> +		if (server_supports_filter) {
> +			print_verbose(args, _("Server supports filter"));
> +			packet_buf_write(req_buf, "filter %s", spec);
> +			trace2_data_string("fetch", the_repository,
> +					   "filter/effective", spec);
> +		} else {
> +			warning("filtering not recognized by server, ignoring");
> +			trace2_data_string("fetch", the_repository,
> +					   "filter/unsupported", spec);
> +		}
> +	} else {
> +		trace2_data_string("fetch", the_repository,
> +				   "filter/none", "");
> +	}
> +}

The previous round already had the same issue, but this makes it even worse by introducing a function that makes it clear that it mixes quite unrelated two features (i.e. write the filter to the other end, which MUST be done for correct operation of the protocol, and write a log to trace2, which may not be even necessary when we are not logging at all).

Can we make the code a bit better structured, I have to wonder, by having two separate phases of processing, one for the operation proper, and the other for the logging/debugging?

In a sense, we can say that the only purpose this helper function is to tell the server end what the filter we use is by renaming it; it is OK to have debugging statements and logging code as part of the implementation of such a function.

I actually like that direction better. A helper function may exist *ONLY* to trace, in which case, having "trace" in its name would make perfect sense. A helper function may exist to perform the real work, but it may log what it did to perform the real work as well. I think the latter shouldn't have "trace" in its name at all, or our helpers will all be called do_FOO_and_trace(), do_BAR_and_debug(), etc., which is nonsense. Just calling do_FOO() and do_BAR(), and then having them log or trace as needed, is fine.

Will queue, anyway.
Thanks.
Junio C Hamano· Jul 25, 2022, 18:56 UTC · re: Junio C Hamano · lore

Re: [PATCH v2] fetch-pack: write effective filter to trace2

Junio C Hamano <gitster@pobox.com> writes:
Show 29 quoted lines
> Jonathan Tan <jonathantanmy@google.com> writes:
>
>> +static void write_and_trace_filter(struct fetch_pack_args *args,
>> +				   struct strbuf *req_buf,
>> +				   int server_supports_filter)
>> +{
>> +...
>> +}
>
> The previous round already had the same issue, but this makes it
> even worse by introducing a function that makes it clear that it
> mixes quite unrelated two features (i.e. write the filter to the
> other end, which MUST be done for correct operation of the protocol,
> and write a log to trace2, which may not be even necessary when we
> are not logging at all).
> ...
> In a sense, we can say that the only purpose this helper function is
> to tell the server end what the filter we use is by renaming it; it
> is OK to have debugging statements and logging code as part of the
> implementation of such a function.
>
> I actually like that direction better.  A helper function may exist
> *ONLY* to trace, in which case, having "trace" in its name would
> make perfect sense.  A helper function may exist to perform the real
> work, but it may log what it did to perform the real work as well.
> I think the latter shouldn't have "trace" in its name at all, or our
> helpers will all be called do_FOO_and_trace(), do_BAR_and_debug(),
> etc., which is nonsense.  Just calling do_FOO() and do_BAR(), and
> then having them log or trace as needed, is fine.

After waiting for a week, I still haven't seen any correction to this patch, but do you want to give the helper function a bit more sensible name in an updated patch, perhaps say "send_filter()" or something?

Otherwise the topic looked good.
Thanks.
Jonathan Tan· Jul 26, 2022, 16:28 UTC · re: Junio C Hamano · lore

Re: [PATCH v2] fetch-pack: write effective filter to trace2

Junio C Hamano <gitster@pobox.com> writes:
Show 8 quoted lines
> After waiting for a week, I still haven't seen any correction to
> this patch, but do you want to give the helper function a bit more
> sensible name in an updated patch, perhaps say "send_filter()" or
> something?
> 
> Otherwise the topic looked good.
> 
> Thanks.
Thanks. Your proposed name looks good. I've sent out a v3.
Jonathan Tan· Jul 26, 2022, 16:27 UTC · re: Jonathan Tan · lore

[PATCH v3] fetch-pack: write effective filter to trace2

Administrators of a managed Git environment (like the one at $DAYJOB) might want to quantify the performance change of fetches with and without filters from the client's point of view, and also detect if a server does not support it. Therefore, log the filter information being sent to the server whenever a fetch (or clone) occurs. Note that this is not necessarily the same as what's specified on the CLI, because during a fetch, the configured filter is used whenever a filter is not specified on the CLI.

Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
---
Here's v3, with an updated function name.
---
Range-diff against v2:
1:  d3ea7d3b95 ! 1:  17cef49fcc fetch-pack: write effective filter to trace2
    @@ Commit message
     
         Signed-off-by: Jonathan Tan <jonathantanmy@google.com>
         ---
    -    Thanks everyone for your comments. I've renamed the keys and
    -    distinguished the case in which the server does not support filters
    -    following Jeff's suggestions.
    -
    -    A few small discussion points:
    -     - whether we need the print_verbose now that we have traces
    -     - should we log if no filter is specified
    -     - if yes, what key should it be logged under (I used "filter/none" for
    -       now)
    +    Here's v3, with an updated function name.
     
      ## fetch-pack.c ##
     @@ fetch-pack.c: static void mark_tips(struct fetch_negotiator *negotiator,
      	return;
      }
      
    -+static void write_and_trace_filter(struct fetch_pack_args *args,
    -+				   struct strbuf *req_buf,
    -+				   int server_supports_filter)
    ++static void send_filter(struct fetch_pack_args *args,
    ++			struct strbuf *req_buf,
    ++			int server_supports_filter)
     +{
     +	if (args->filter_options.choice) {
     +		const char *spec =
    @@ fetch-pack.c: static int find_common(struct fetch_negotiator *negotiator,
     -			expand_list_objects_filter_spec(&args->filter_options);
     -		packet_buf_write(&req_buf, "filter %s", spec);
     -	}
    -+	write_and_trace_filter(args, &req_buf, server_supports_filtering);
    ++	send_filter(args, &req_buf, server_supports_filtering);
      	packet_buf_flush(&req_buf);
      	state_len = req_buf.len;
      
    @@ fetch-pack.c: static int send_fetch_request(struct fetch_negotiator *negotiator,
     -	} else if (args->filter_options.choice) {
     -		warning("filtering not recognized by server, ignoring");
     -	}
    -+	write_and_trace_filter(args, &req_buf,
    -+			       server_supports_feature("fetch", "filter", 0));
    ++	send_filter(args, &req_buf,
    ++		    server_supports_feature("fetch", "filter", 0));
      
      	if (server_supports_feature("fetch", "packfile-uris", 0)) {
      		int i;
 fetch-pack.c | 40 ++++++++++++++++++++++++++--------------
 1 file changed, 26 insertions(+), 14 deletions(-)
Show changes to fetch-pack.c +26 −14
diff --git a/fetch-pack.c b/fetch-pack.c
index cb6647d657..a44eb32a71 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -292,6 +292,29 @@ static void mark_tips(struct fetch_negotiator *negotiator,
 	return;
 }
 
+static void send_filter(struct fetch_pack_args *args,
+			struct strbuf *req_buf,
+			int server_supports_filter)
+{
+	if (args->filter_options.choice) {
+		const char *spec =
+			expand_list_objects_filter_spec(&args->filter_options);
+		if (server_supports_filter) {
+			print_verbose(args, _("Server supports filter"));
+			packet_buf_write(req_buf, "filter %s", spec);
+			trace2_data_string("fetch", the_repository,
+					   "filter/effective", spec);
+		} else {
+			warning("filtering not recognized by server, ignoring");
+			trace2_data_string("fetch", the_repository,
+					   "filter/unsupported", spec);
+		}
+	} else {
+		trace2_data_string("fetch", the_repository,
+				   "filter/none", "");
+	}
+}
+
 static int find_common(struct fetch_negotiator *negotiator,
 		       struct fetch_pack_args *args,
 		       int fd[2], struct object_id *result_oid,
@@ -389,11 +412,7 @@ static int find_common(struct fetch_negotiator *negotiator,
 			packet_buf_write(&req_buf, "deepen-not %s", s->string);
 		}
 	}
-	if (server_supports_filtering && args->filter_options.choice) {
-		const char *spec =
-			expand_list_objects_filter_spec(&args->filter_options);
-		packet_buf_write(&req_buf, "filter %s", spec);
-	}
+	send_filter(args, &req_buf, server_supports_filtering);
 	packet_buf_flush(&req_buf);
 	state_len = req_buf.len;
 
@@ -1323,15 +1342,8 @@ static int send_fetch_request(struct fetch_negotiator *negotiator, int fd_out,
 		die(_("Server does not support shallow requests"));
 
 	/* Add filter */
-	if (server_supports_feature("fetch", "filter", 0) &&
-	    args->filter_options.choice) {
-		const char *spec =
-			expand_list_objects_filter_spec(&args->filter_options);
-		print_verbose(args, _("Server supports filter"));
-		packet_buf_write(&req_buf, "filter %s", spec);
-	} else if (args->filter_options.choice) {
-		warning("filtering not recognized by server, ignoring");
-	}
+	send_filter(args, &req_buf,
+		    server_supports_feature("fetch", "filter", 0));
 
 	if (server_supports_feature("fetch", "packfile-uris", 0)) {
 		int i;
-- 
2.37.1.359.gd136c6c3e2-goog

← back to recent threads