threads / patch / 52194

patchfetch: add trace2 instrumentation

Subject: [PATCH 0/1] fetch: add trace2 instrumentation

## tl;dr

22 messages between Nov 5, 2019 and Nov 20, 2019. Diffs are folded; open one to read it.

replies: 21people: 5as markdown or json

erik chen via GitGitGadget· Nov 5, 2019, 19:26 UTC · lore

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

* matching common remote and local refs
* marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]
Erik Chen (1):
  fetch: add trace2 instrumentation
 fetch-pack.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)
base-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-451%2Ferikchen%2Ftest12-v1
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-451/erikchen/test12-v1
Pull-Request: https://github.com/gitgitgadget/git/pull/451
-- 
gitgitgadget
Erik Chen via GitGitGadget· Nov 5, 2019, 19:26 UTC · re: erik chen via GitGitGadget · lore

[PATCH 1/1] fetch: add trace2 instrumentation

From: Erik Chen <erikchen@chromium.org>

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

    * matching common remote and local refs
    * marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen <erikchen@chromium.org>
---
 fetch-pack.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)
Show changes to fetch-pack.c +8 −1
diff --git a/fetch-pack.c b/fetch-pack.c
index 0130b44112..f2f3365bbe 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -666,9 +666,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 	struct ref *ref;
 	int old_save_commit_buffer = save_commit_buffer;
 	timestamp_t cutoff = 0;
-
 	save_commit_buffer = 0;
 
+	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
+
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o;
 
@@ -690,6 +691,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		}
 	}
 
+	/* This block marks all local refs as COMPLETE, and then recursively marks all
+	 * parents of those refs as COMPLETE.
+	 */
+	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
 	if (!args->deepen) {
 		for_each_ref(mark_complete_oid, NULL);
 		for_each_cached_alternate(NULL, mark_alternate_complete);
@@ -697,6 +702,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (cutoff)
 			mark_recent_complete_commits(args, cutoff);
 	}
+	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
 
 	/*
 	 * Mark all complete remote refs as common refs.
@@ -716,6 +722,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 	}
 
 	save_commit_buffer = old_save_commit_buffer;
+	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
 }
 
 /*
-- 
gitgitgadget
Johannes Schindelin· Nov 6, 2019, 12:30 UTC · re: Erik Chen via GitGitGadget · lore

Re: [PATCH 1/1] fetch: add trace2 instrumentation

Hi Erik,
On Tue, 5 Nov 2019, Erik Chen via GitGitGadget wrote:
Show 24 quoted lines
> From: Erik Chen <erikchen@chromium.org>
>
> Add trace2 regions to fetch-pack.c to better track time spent in the various
> phases of a fetch:
>
>     * matching common remote and local refs
>     * marking local refs as complete (part of the matching process)
>
> Both of these stages can be slow for repositories with many refs.
>
> Signed-off-by: Erik Chen <erikchen@chromium.org>
> ---
>  fetch-pack.c | 9 ++++++++-
>  1 file changed, 8 insertions(+), 1 deletion(-)
>
> diff --git a/fetch-pack.c b/fetch-pack.c
> index 0130b44112..f2f3365bbe 100644
> --- a/fetch-pack.c
> +++ b/fetch-pack.c
> @@ -666,9 +666,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  	struct ref *ref;
>  	int old_save_commit_buffer = save_commit_buffer;
>  	timestamp_t cutoff = 0;
> -

I would keep this empty line. Other than that, this patch looks good to me.

Thanks, Johannes

Show 37 quoted lines
>  	save_commit_buffer = 0;
>
> +	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
> +
>  	for (ref = *refs; ref; ref = ref->next) {
>  		struct object *o;
>
> @@ -690,6 +691,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  		}
>  	}
>
> +	/* This block marks all local refs as COMPLETE, and then recursively marks all
> +	 * parents of those refs as COMPLETE.
> +	 */
> +	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
>  	if (!args->deepen) {
>  		for_each_ref(mark_complete_oid, NULL);
>  		for_each_cached_alternate(NULL, mark_alternate_complete);
> @@ -697,6 +702,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  		if (cutoff)
>  			mark_recent_complete_commits(args, cutoff);
>  	}
> +	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
>
>  	/*
>  	 * Mark all complete remote refs as common refs.
> @@ -716,6 +722,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  	}
>
>  	save_commit_buffer = old_save_commit_buffer;
> +	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
>  }
>
>  /*
> --
> gitgitgadget
>
erik chen via GitGitGadget· Nov 6, 2019, 18:51 UTC · re: erik chen via GitGitGadget · lore

[PATCH v2 0/2] fetch: add trace2 instrumentation

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

* matching common remote and local refs
* marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]
Erik Chen (2):
  fetch: add trace2 instrumentation
  add whitespace
 fetch-pack.c | 8 ++++++++
 1 file changed, 8 insertions(+)
base-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-451%2Ferikchen%2Ftest12-v2
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-451/erikchen/test12-v2
Pull-Request: https://github.com/gitgitgadget/git/pull/451
Range-diff vs v1:
 1:  4fdbb9f504 = 1:  4fdbb9f504 fetch: add trace2 instrumentation
 -:  ---------- > 2:  606756d7db add whitespace
-- 
gitgitgadget
Erik Chen via GitGitGadget· Nov 6, 2019, 18:51 UTC · re: erik chen via GitGitGadget · lore

[PATCH v2 1/2] fetch: add trace2 instrumentation

From: Erik Chen <erikchen@chromium.org>

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

    * matching common remote and local refs
    * marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen <erikchen@chromium.org>
---
 fetch-pack.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)
Show changes to fetch-pack.c +8 −1
diff --git a/fetch-pack.c b/fetch-pack.c
index 0130b44112..f2f3365bbe 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -666,9 +666,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 	struct ref *ref;
 	int old_save_commit_buffer = save_commit_buffer;
 	timestamp_t cutoff = 0;
-
 	save_commit_buffer = 0;
 
+	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
+
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o;
 
@@ -690,6 +691,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		}
 	}
 
+	/* This block marks all local refs as COMPLETE, and then recursively marks all
+	 * parents of those refs as COMPLETE.
+	 */
+	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
 	if (!args->deepen) {
 		for_each_ref(mark_complete_oid, NULL);
 		for_each_cached_alternate(NULL, mark_alternate_complete);
@@ -697,6 +702,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (cutoff)
 			mark_recent_complete_commits(args, cutoff);
 	}
+	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
 
 	/*
 	 * Mark all complete remote refs as common refs.
@@ -716,6 +722,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 	}
 
 	save_commit_buffer = old_save_commit_buffer;
+	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
 }
 
 /*
-- 
gitgitgadget
Erik Chen via GitGitGadget· Nov 6, 2019, 18:51 UTC · re: erik chen via GitGitGadget · lore

[PATCH v2 2/2] add whitespace

From: Erik Chen <erikchen@chromium.org>
Signed-off-by: Erik Chen <erikchen@chromium.org>
---
 fetch-pack.c | 1 +
 1 file changed, 1 insertion(+)
Show changes to fetch-pack.c +1 −0
diff --git a/fetch-pack.c b/fetch-pack.c
index f2f3365bbe..5e3eee0477 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -666,6 +666,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 	struct ref *ref;
 	int old_save_commit_buffer = save_commit_buffer;
 	timestamp_t cutoff = 0;
+
 	save_commit_buffer = 0;
 
 	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
-- 
gitgitgadget
erik chen via GitGitGadget· Nov 6, 2019, 19:39 UTC · re: erik chen via GitGitGadget · lore

[PATCH v3 0/1] fetch: add trace2 instrumentation

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

* matching common remote and local refs
* marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]
Erik Chen (1):
  fetch: add trace2 instrumentation
 fetch-pack.c | 8 ++++++++
 1 file changed, 8 insertions(+)
base-commit: 566a1439f6f56c2171b8853ddbca0ad3f5098770
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-451%2Ferikchen%2Ftest12-v3
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-451/erikchen/test12-v3
Pull-Request: https://github.com/gitgitgadget/git/pull/451
Range-diff vs v2:
 1:  4fdbb9f504 ! 1:  364c526a5d fetch: add trace2 instrumentation
     @@ -16,10 +16,7 @@
       --- a/fetch-pack.c
       +++ b/fetch-pack.c
      @@
     - 	struct ref *ref;
     - 	int old_save_commit_buffer = save_commit_buffer;
     - 	timestamp_t cutoff = 0;
     --
     + 
       	save_commit_buffer = 0;
       
      +	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
 2:  606756d7db < -:  ---------- add whitespace
-- 
gitgitgadget
Erik Chen via GitGitGadget· Nov 6, 2019, 19:39 UTC · re: erik chen via GitGitGadget · lore

[PATCH v3 1/1] fetch: add trace2 instrumentation

From: Erik Chen <erikchen@chromium.org>

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

    * matching common remote and local refs
    * marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen <erikchen@chromium.org>
---
 fetch-pack.c | 8 ++++++++
 1 file changed, 8 insertions(+)
Show changes to fetch-pack.c +8 −0
diff --git a/fetch-pack.c b/fetch-pack.c
index 0130b44112..5e3eee0477 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -669,6 +669,8 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 
 	save_commit_buffer = 0;
 
+	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
+
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o;
 
@@ -690,6 +692,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		}
 	}
 
+	/* This block marks all local refs as COMPLETE, and then recursively marks all
+	 * parents of those refs as COMPLETE.
+	 */
+	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
 	if (!args->deepen) {
 		for_each_ref(mark_complete_oid, NULL);
 		for_each_cached_alternate(NULL, mark_alternate_complete);
@@ -697,6 +703,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (cutoff)
 			mark_recent_complete_commits(args, cutoff);
 	}
+	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
 
 	/*
 	 * Mark all complete remote refs as common refs.
@@ -716,6 +723,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 	}
 
 	save_commit_buffer = old_save_commit_buffer;
+	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
 }
 
 /*
-- 
gitgitgadget
Junio C Hamano· Nov 7, 2019, 05:32 UTC · re: Erik Chen via GitGitGadget · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

"Erik Chen via GitGitGadget" <gitgitgadget@gmail.com> writes:
Show 14 quoted lines
> From: Erik Chen <erikchen@chromium.org>
>
> Add trace2 regions to fetch-pack.c to better track time spent in the various
> phases of a fetch:
>
>     * matching common remote and local refs
>     * marking local refs as complete (part of the matching process)
>
> Both of these stages can be slow for repositories with many refs.
>
> Signed-off-by: Erik Chen <erikchen@chromium.org>
> ---
>  fetch-pack.c | 8 ++++++++
>  1 file changed, 8 insertions(+)
OK.
Show 20 quoted lines
> diff --git a/fetch-pack.c b/fetch-pack.c
> index 0130b44112..5e3eee0477 100644
> --- a/fetch-pack.c
> +++ b/fetch-pack.c
> @@ -669,6 +669,8 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  
>  	save_commit_buffer = 0;
>  
> +	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
> +
>  	for (ref = *refs; ref; ref = ref->next) {
>  		struct object *o;
>  
> @@ -690,6 +692,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  		}
>  	}
>  
> +	/* This block marks all local refs as COMPLETE, and then recursively marks all
> +	 * parents of those refs as COMPLETE.
> +	 */
        /*
         * We write our multi-line comments like this, with the
         * slash-asterisk at the beginning and the asterisk-slash
         * at the end on its own line.  Learn such local conventions
         * from the existing surrounding code and imitate, which
         * would reduce stylistic errors.
         */
Will fix-up while queuing (no need to reroll only to fix this).
Show 17 quoted lines
> +	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
>  	if (!args->deepen) {
>  		for_each_ref(mark_complete_oid, NULL);
>  		for_each_cached_alternate(NULL, mark_alternate_complete);
> @@ -697,6 +703,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  		if (cutoff)
>  			mark_recent_complete_commits(args, cutoff);
>  	}
> +	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
>  
>  	/*
>  	 * Mark all complete remote refs as common refs.
> @@ -716,6 +723,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>  	}
>  
>  	save_commit_buffer = old_save_commit_buffer;
> +	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);

So this introduces a single region around the entire function body of mark_complete_and_common_ref(), within which only one subpart is also enclosed in a nested region. Is that because the parts inside the outer region before and after the inner region are known to consume negligible time? IOW I would understand

        F () {
                <region 1 begin>
                    <region 1.1 begin>
                        code
                    <region 1.1 end>
                    <region 1.2 begin>
                        code
                    <region 1.2 end>
                    <region 1.3 begin>
                        code
                    <region 1.3 end>
                <region 1 end>
        }
or
        F () {
                        trivial code
                <region 1 begin>
                        heavy code
                <region 1 end>
                        trivial code
        }
but this appears to do
        F () {
                <region 1 begin>
                        code
                    <region 1.1 begin>
                        code
                    <region 1.1 end>
                        code
                <region 1 end>
        }
which is somewhat puzzling.
Thanks.
Derrick Stolee· Nov 18, 2019, 15:46 UTC · re: Junio C Hamano · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

On 11/7/2019 12:32 AM, Junio C Hamano wrote:
Show 113 quoted lines
> "Erik Chen via GitGitGadget" <gitgitgadget@gmail.com> writes:
> 
>> From: Erik Chen <erikchen@chromium.org>
>>
>> Add trace2 regions to fetch-pack.c to better track time spent in the various
>> phases of a fetch:
>>
>>     * matching common remote and local refs
>>     * marking local refs as complete (part of the matching process)
>>
>> Both of these stages can be slow for repositories with many refs.
>>
>> Signed-off-by: Erik Chen <erikchen@chromium.org>
>> ---
>>  fetch-pack.c | 8 ++++++++
>>  1 file changed, 8 insertions(+)
> 
> OK.
> 
>> diff --git a/fetch-pack.c b/fetch-pack.c
>> index 0130b44112..5e3eee0477 100644
>> --- a/fetch-pack.c
>> +++ b/fetch-pack.c
>> @@ -669,6 +669,8 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>>  
>>  	save_commit_buffer = 0;
>>  
>> +	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
>> +
>>  	for (ref = *refs; ref; ref = ref->next) {
>>  		struct object *o;
>>  
>> @@ -690,6 +692,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>>  		}
>>  	}
>>  
>> +	/* This block marks all local refs as COMPLETE, and then recursively marks all
>> +	 * parents of those refs as COMPLETE.
>> +	 */
> 
>         /*
>          * We write our multi-line comments like this, with the
>          * slash-asterisk at the beginning and the asterisk-slash
>          * at the end on its own line.  Learn such local conventions
>          * from the existing surrounding code and imitate, which
>          * would reduce stylistic errors.
>          */
> 
> Will fix-up while queuing (no need to reroll only to fix this).
> 
>> +	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
>>  	if (!args->deepen) {
>>  		for_each_ref(mark_complete_oid, NULL);
>>  		for_each_cached_alternate(NULL, mark_alternate_complete);
>> @@ -697,6 +703,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>>  		if (cutoff)
>>  			mark_recent_complete_commits(args, cutoff);
>>  	}
>> +	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
>>  
>>  	/*
>>  	 * Mark all complete remote refs as common refs.
>> @@ -716,6 +723,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
>>  	}
>>  
>>  	save_commit_buffer = old_save_commit_buffer;
>> +	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
> 
> 
> So this introduces a single region around the entire function body
> of mark_complete_and_common_ref(), within which only one subpart is
> also enclosed in a nested region.  Is that because the parts inside
> the outer region before and after the inner region are known to
> consume negligible time?  IOW I would understand
> 
>         F () {
>                 <region 1 begin>
>                     <region 1.1 begin>
>                         code
>                     <region 1.1 end>
>                     <region 1.2 begin>
>                         code
>                     <region 1.2 end>
>                     <region 1.3 begin>
>                         code
>                     <region 1.3 end>
>                 <region 1 end>
>         }
> 
> or
> 
>         F () {
>                         trivial code
>                 <region 1 begin>
>                         heavy code
>                 <region 1 end>
>                         trivial code
>         }
> 
> but this appears to do
> 
> 
>         F () {
>                 <region 1 begin>
>                         code
>                     <region 1.1 begin>
>                         code
>                     <region 1.1 end>
>                         code
>                 <region 1 end>
>         }
> 
> which is somewhat puzzling.

I notice that a v4 was sent that adds more sub-regions without actually responding to this request. (It is worth also pointing out that you ignored Junio's request you use the cover letter to explain your reasoning for changes between versions.)

There is a real downside to nesting regions like this. Specifically, we frequently limit the depth that we report nested regions to avoid overwhelming the logs.

In general, these sub-regions should be avoided when possible and instead create regions around important sections, such as the second option Junio lists above.

Thanks, -Stolee

Junio C Hamano· Nov 19, 2019, 01:55 UTC · re: Derrick Stolee · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

Derrick Stolee <stolee@gmail.com> writes:
Show 29 quoted lines
> On 11/7/2019 12:32 AM, Junio C Hamano wrote:
>> So this introduces a single region around the entire function body
>> of mark_complete_and_common_ref(), within which only one subpart is
>> also enclosed in a nested region.  Is that because the parts inside
>> the outer region before and after the inner region are known to
>> consume negligible time?  IOW I would understand
>> 
>>         F () {
>> ...
>>         }
>> 
>> or
>> 
>>         F () {
>>                         trivial code
>>                 <region 1 begin>
>>                         heavy code
>>                 <region 1 end>
>>                         trivial code
>>         }
>> 
>> but this appears to do
>> ...
>> which is somewhat puzzling.
>
> I notice that a v4 was sent that adds more sub-regions without actually
> responding to this request. (It is worth also pointing out that you
> ignored Junio's request you use the cover letter to explain your reasoning
> for changes between versions.)

Thanks for noticing. I wasn't requesting any change in particular (at least not yet), but was inquiring the reasoning behind what was done. From that point of view, the lack of answers was worse than yet another patch that does not explain why it was done that other way this time around.

Show 7 quoted lines
> There is a real downside to nesting regions like this. Specifically, we
> frequently limit the depth that we report nested regions to avoid
> overwhelming the logs.
>
> In general, these sub-regions should be avoided when possible and instead
> create regions around important sections, such as the second option Junio
> lists above.
Thanks for a clear direction as the area expert of trace2.
Erik Chen· Nov 19, 2019, 21:24 UTC · re: Junio C Hamano · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

On 11/18/19 5:55 PM, Junio C Hamano wrote:
Show 35 quoted lines
> Derrick Stolee <stolee@gmail.com> writes:
>
>> On 11/7/2019 12:32 AM, Junio C Hamano wrote:
>>> So this introduces a single region around the entire function body
>>> of mark_complete_and_common_ref(), within which only one subpart is
>>> also enclosed in a nested region.  Is that because the parts inside
>>> the outer region before and after the inner region are known to
>>> consume negligible time?  IOW I would understand
>>>
>>>          F () {
>>> ...
>>>          }
>>>
>>> or
>>>
>>>          F () {
>>>                          trivial code
>>>                  <region 1 begin>
>>>                          heavy code
>>>                  <region 1 end>
>>>                          trivial code
>>>          }
>>>
>>> but this appears to do
>>> ...
>>> which is somewhat puzzling.
>> I notice that a v4 was sent that adds more sub-regions without actually
>> responding to this request. (It is worth also pointing out that you
>> ignored Junio's request you use the cover letter to explain your reasoning
>> for changes between versions.)
> Thanks for noticing.  I wasn't requesting any change in particular
> (at least not yet), but was inquiring the reasoning behind what was
> done.  From that point of view, the lack of answers was worse than
> yet another patch that does not explain why it was done that other
> way this time around.
Sorry, I've been replying on the GitGitGadget pull request thread:
e.g. https://github.com/gitgitgadget/git/pull/451#issuecomment-555044068

But none of those replies have been making their way to this mailing list. I'll attempt to send these replies to the mailing list now.

Show 11 quoted lines
>
>> There is a real downside to nesting regions like this. Specifically, we
>> frequently limit the depth that we report nested regions to avoid
>> overwhelming the logs.
>>
>> In general, these sub-regions should be avoided when possible and instead
>> create regions around important sections, such as the second option Junio
>> lists above.
> Thanks for a clear direction as the area expert of trace2.
>
>
Erik Chen· Nov 19, 2019, 22:57 UTC · re: Junio C Hamano · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

Show 5 quoted lines
>> In general, these sub-regions should be avoided when possible and instead
>> create regions around important sections, such as the second option Junio
>> lists above.
> 
> Thanks for a clear direction as the area expert of trace2.
I'll upload a new patch set to do that.
Erik Chen· Nov 19, 2019, 21:51 UTC · re: Derrick Stolee · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

Importing response from https://github.com/gitgitgadget/git/pull/451#issuecomment-555077933

> I notice that a v4 was sent that adds more sub-regions without actually
> responding to this request. 

Sorry, did I misunderstand the request? I was trying to implement the suggestion: <Junio's first suggestion>

 > (It is worth also pointing out that you
 > ignored Junio's request you use the cover letter to explain your 
reasoning
 > for changes between versions.)
Sorry, this was not intentional. I'm using GitGitGadget, and it wasn't 
clear to me how to change this. See my comment here:
<https://github.com/gitgitgadget/git/pull/451#issuecomment-555044068>
Show 8 quoted lines
> 
> There is a real downside to nesting regions like this. Specifically, we
> frequently limit the depth that we report nested regions to avoid
> overwhelming the logs.
> 
> In general, these sub-regions should be avoided when possible and instead
> create regions around important sections, such as the second option Junio
> lists above.

I thought it would be nice to have an encapsulating region for the full function, but I can switch to Junio's second option if that's preferable. It wasn't clear to me that that was preferred over the first option?

Erik Chen· Nov 19, 2019, 21:47 UTC · re: Junio C Hamano · lore

Re: [PATCH v3 1/1] fetch: add trace2 instrumentation

Importing response from https://github.com/gitgitgadget/git/pull/451#issuecomment-555044068

Show 10 quoted lines
> 
>          /*
>           * We write our multi-line comments like this, with the
>           * slash-asterisk at the beginning and the asterisk-slash
>           * at the end on its own line.  Learn such local conventions
>           * from the existing surrounding code and imitate, which
>           * would reduce stylistic errors.
>           */
> 
> Will fix-up while queuing (no need to reroll only to fix this).

Sorry about that. I was copying from line 682, which looks like it was also using the wrong style. I've fixed that line as well.

Show 5 quoted lines
> So this introduces a single region around the entire function body
> of mark_complete_and_common_ref(), within which only one subpart is
> also enclosed in a nested region.  Is that because the parts inside
> the outer region before and after the inner region are known to
> consume negligible time?  IOW I would understand

Good point. I used this structure because I observed locally that the middle block was slow, but was concerned that the initial/ending block might be slow as well. I've gone ahead and adding tracing regions for each block.

Junio C Hamano· Nov 7, 2019, 05:21 UTC · re: erik chen via GitGitGadget · lore

Re: [PATCH v3 0/1] fetch: add trace2 instrumentation

"erik chen via GitGitGadget" <gitgitgadget@gmail.com> writes:
Show 9 quoted lines
> Add trace2 regions to fetch-pack.c to better track time spent in the various
> phases of a fetch:
>
> * matching common remote and local refs
> * marking local refs as complete (part of the matching process)
>
> Both of these stages can be slow for repositories with many refs.
>
> Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]

If the above is verbatim copy of what you wrote in 1/1, that is very much unappreciated X-<. A cover letter for a topic serves primarily just one purpose:

   It is a good place to present a birds-eye-view of a multi-patch
   topic; a high level description of the problem (e.g. how the
   issue manifests to the end users), an explanation of division of
   the problem into subproblems you made (if applicable), and
   interesting highlights of the solution would all be good things
   to have in there.
And as a topic goes through iterations, it gives you a good place to
summarize what changed since the previously reviewed iterations.  It
could be just a single liner "addressed all the review comments for
the previous iteration".  A well-written multi-patch topic also uses
the same after-three-dash technique used for a single-patch topic
(see below) to summarize what changed since the corresponding patch
in the series in the previous iteration (or just says "no changes
since the previous round"---that helps the reviewers a lot).
   
For a single-patch topic, there is no place for "here is an overall
birds-eyes-view picture because the changes described in the
proposed log message of individual patches are so big and complex".
A single-patch topic has one patch, that solves one problem and only
that problem well, so it should not need such a summary.  

When you want to summarize the changes since the previous iteration, you would write it between the three-dash-line (which appears after your sign-off) and the diffstat.

Thanks.
Erik Chen· Nov 19, 2019, 21:44 UTC · re: Junio C Hamano · lore

Re: [PATCH v3 0/1] fetch: add trace2 instrumentation

Importing response from https://github.com/gitgitgadget/git/pull/451#issuecomment-555044068

On 11/6/19 9:21 PM, Junio C Hamano wrote:
Show 45 quoted lines
> "erik chen via GitGitGadget" <gitgitgadget@gmail.com> writes:
> 
>> Add trace2 regions to fetch-pack.c to better track time spent in the various
>> phases of a fetch:
>>
>> * matching common remote and local refs
>> * marking local refs as complete (part of the matching process)
>>
>> Both of these stages can be slow for repositories with many refs.
>>
>> Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]
> 
> If the above is verbatim copy of what you wrote in 1/1, that is very
> much unappreciated X-<.  A cover letter for a topic serves primarily
> just one purpose:
> 
>     It is a good place to present a birds-eye-view of a multi-patch
>     topic; a high level description of the problem (e.g. how the
>     issue manifests to the end users), an explanation of division of
>     the problem into subproblems you made (if applicable), and
>     interesting highlights of the solution would all be good things
>     to have in there.
> 
> And as a topic goes through iterations, it gives you a good place to
> summarize what changed since the previously reviewed iterations.  It
> could be just a single liner "addressed all the review comments for
> the previous iteration".  A well-written multi-patch topic also uses
> the same after-three-dash technique used for a single-patch topic
> (see below) to summarize what changed since the corresponding patch
> in the series in the previous iteration (or just says "no changes
> since the previous round"---that helps the reviewers a lot).
>     
> For a single-patch topic, there is no place for "here is an overall
> birds-eyes-view picture because the changes described in the
> proposed log message of individual patches are so big and complex".
> A single-patch topic has one patch, that solves one problem and only
> that problem well, so it should not need such a summary.
> 
> When you want to summarize the changes since the previous iteration,
> you would write it between the three-dash-line (which appears after
> your sign-off) and the diffstat.
> 
> Thanks.
> 
> 

Sorry about that, this is my first time contributing to git, and I'm using GitGitGadget. I believe it's too late to fix this now (?)

erik chen via GitGitGadget· Nov 18, 2019, 14:52 UTC · re: erik chen via GitGitGadget · lore

[PATCH v4 0/1] fetch: add trace2 instrumentation

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

* matching common remote and local refs
* marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]
Erik Chen (1):
  fetch: add trace2 instrumentation
 fetch-pack.c | 16 +++++++++++++++-
 1 file changed, 15 insertions(+), 1 deletion(-)
base-commit: d9f6f3b6195a0ca35642561e530798ad1469bd41
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-451%2Ferikchen%2Ftest12-v4
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-451/erikchen/test12-v4
Pull-Request: https://github.com/gitgitgadget/git/pull/451
Range-diff vs v3:
 1:  364c526a5d ! 1:  508d07a3eb fetch: add trace2 instrumentation
     @@ -6,7 +6,9 @@
          phases of a fetch:
      
              * matching common remote and local refs
     -        * marking local refs as complete (part of the matching process)
     +        * parsing remote refs and finding a cutoff
     +        * marking local refs as complete
     +        * marking complete remote refs as common
      
          Both of these stages can be slow for repositories with many refs.
      
     @@ -21,14 +23,28 @@
       
      +	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
      +
     ++	trace2_region_enter("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
       	for (ref = *refs; ref; ref = ref->next) {
       		struct object *o;
       
      @@
     + 		if (!o)
     + 			continue;
     + 
     +-		/* We already have it -- which may mean that we were
     ++		/*
     ++		 * We already have it -- which may mean that we were
     + 		 * in sync with the other side at some time after
     + 		 * that (it is OK if we guess wrong here).
     + 		 */
     +@@
     + 				cutoff = commit->date;
       		}
       	}
     ++	trace2_region_leave("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
       
     -+	/* This block marks all local refs as COMPLETE, and then recursively marks all
     ++	/*
     ++	 * This block marks all local refs as COMPLETE, and then recursively marks all
      +	 * parents of those refs as COMPLETE.
      +	 */
      +	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
     @@ -43,8 +59,17 @@
       
       	/*
       	 * Mark all complete remote refs as common refs.
     + 	 * Don't mark them common yet; the server has to be told so first.
     + 	 */
     ++	trace2_region_enter("fetch-pack", "mark_common_remote_refs", NULL);
     + 	for (ref = *refs; ref; ref = ref->next) {
     + 		struct object *o = deref_tag(the_repository,
     + 					     lookup_object(the_repository,
      @@
     + 		negotiator->known_common(negotiator,
     + 					 (struct commit *)o);
       	}
     ++	trace2_region_leave("fetch-pack", "mark_common_remote_refs", NULL);
       
       	save_commit_buffer = old_save_commit_buffer;
      +	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
-- 
gitgitgadget
Erik Chen via GitGitGadget· Nov 18, 2019, 14:52 UTC · re: erik chen via GitGitGadget · lore

[PATCH v4 1/1] fetch: add trace2 instrumentation

From: Erik Chen <erikchen@chromium.org>

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

    * matching common remote and local refs
    * parsing remote refs and finding a cutoff
    * marking local refs as complete
    * marking complete remote refs as common
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen <erikchen@chromium.org>
---
 fetch-pack.c | 16 +++++++++++++++-
 1 file changed, 15 insertions(+), 1 deletion(-)
Show changes to fetch-pack.c +15 −1
diff --git a/fetch-pack.c b/fetch-pack.c
index f80e2d1149..bca70e65c8 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -669,6 +669,9 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 
 	save_commit_buffer = 0;
 
+	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
+
+	trace2_region_enter("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o;
 
@@ -679,7 +682,8 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (!o)
 			continue;
 
-		/* We already have it -- which may mean that we were
+		/*
+		 * We already have it -- which may mean that we were
 		 * in sync with the other side at some time after
 		 * that (it is OK if we guess wrong here).
 		 */
@@ -689,7 +693,13 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 				cutoff = commit->date;
 		}
 	}
+	trace2_region_leave("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
 
+	/*
+	 * This block marks all local refs as COMPLETE, and then recursively marks all
+	 * parents of those refs as COMPLETE.
+	 */
+	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
 	if (!args->deepen) {
 		for_each_ref(mark_complete_oid, NULL);
 		for_each_cached_alternate(NULL, mark_alternate_complete);
@@ -697,11 +707,13 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (cutoff)
 			mark_recent_complete_commits(args, cutoff);
 	}
+	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
 
 	/*
 	 * Mark all complete remote refs as common refs.
 	 * Don't mark them common yet; the server has to be told so first.
 	 */
+	trace2_region_enter("fetch-pack", "mark_common_remote_refs", NULL);
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o = deref_tag(the_repository,
 					     lookup_object(the_repository,
@@ -714,8 +726,10 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		negotiator->known_common(negotiator,
 					 (struct commit *)o);
 	}
+	trace2_region_leave("fetch-pack", "mark_common_remote_refs", NULL);
 
 	save_commit_buffer = old_save_commit_buffer;
+	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
 }
 
 /*
-- 
gitgitgadget
erik chen via GitGitGadget· Nov 19, 2019, 23:02 UTC · re: erik chen via GitGitGadget · lore

[PATCH v5 0/1] fetch: add trace2 instrumentation

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

* matching common remote and local refs
* marking local refs as complete (part of the matching process)
Both of these stages can be slow for repositories with many refs.
Signed-off-by: Erik Chen erikchen@chromium.org [erikchen@chromium.org]
Erik Chen (1):
  fetch: add trace2 instrumentation
 fetch-pack.c | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)
base-commit: d9f6f3b6195a0ca35642561e530798ad1469bd41
Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-451%2Ferikchen%2Ftest12-v5
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-451/erikchen/test12-v5
Pull-Request: https://github.com/gitgitgadget/git/pull/451
Range-diff vs v4:
 1:  508d07a3eb ! 1:  d7bf1849ce fetch: add trace2 instrumentation
     @@ -5,12 +5,11 @@
          Add trace2 regions to fetch-pack.c to better track time spent in the various
          phases of a fetch:
      
     -        * matching common remote and local refs
              * parsing remote refs and finding a cutoff
              * marking local refs as complete
              * marking complete remote refs as common
      
     -    Both of these stages can be slow for repositories with many refs.
     +    All stages could potentially be slow for repositories with many refs.
      
          Signed-off-by: Erik Chen <erikchen@chromium.org>
      
     @@ -21,8 +20,6 @@
       
       	save_commit_buffer = 0;
       
     -+	trace2_region_enter("fetch-pack", "mark_complete_and_common_ref", NULL);
     -+
      +	trace2_region_enter("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
       	for (ref = *refs; ref; ref = ref->next) {
       		struct object *o;
     @@ -72,7 +69,4 @@
      +	trace2_region_leave("fetch-pack", "mark_common_remote_refs", NULL);
       
       	save_commit_buffer = old_save_commit_buffer;
     -+	trace2_region_leave("fetch-pack", "mark_complete_and_common_ref", NULL);
       }
     - 
     - /*
-- 
gitgitgadget
Erik Chen via GitGitGadget· Nov 19, 2019, 23:02 UTC · re: erik chen via GitGitGadget · lore

[PATCH v5 1/1] fetch: add trace2 instrumentation

From: Erik Chen <erikchen@chromium.org>

Add trace2 regions to fetch-pack.c to better track time spent in the various phases of a fetch:

    * parsing remote refs and finding a cutoff
    * marking local refs as complete
    * marking complete remote refs as common
All stages could potentially be slow for repositories with many refs.
Signed-off-by: Erik Chen <erikchen@chromium.org>
---
 fetch-pack.c | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)
Show changes to fetch-pack.c +12 −1
diff --git a/fetch-pack.c b/fetch-pack.c
index f80e2d1149..a4a5e6cf9c 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -669,6 +669,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 
 	save_commit_buffer = 0;
 
+	trace2_region_enter("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o;
 
@@ -679,7 +680,8 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (!o)
 			continue;
 
-		/* We already have it -- which may mean that we were
+		/*
+		 * We already have it -- which may mean that we were
 		 * in sync with the other side at some time after
 		 * that (it is OK if we guess wrong here).
 		 */
@@ -689,7 +691,13 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 				cutoff = commit->date;
 		}
 	}
+	trace2_region_leave("fetch-pack", "parse_remote_refs_and_find_cutoff", NULL);
 
+	/*
+	 * This block marks all local refs as COMPLETE, and then recursively marks all
+	 * parents of those refs as COMPLETE.
+	 */
+	trace2_region_enter("fetch-pack", "mark_complete_local_refs", NULL);
 	if (!args->deepen) {
 		for_each_ref(mark_complete_oid, NULL);
 		for_each_cached_alternate(NULL, mark_alternate_complete);
@@ -697,11 +705,13 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		if (cutoff)
 			mark_recent_complete_commits(args, cutoff);
 	}
+	trace2_region_leave("fetch-pack", "mark_complete_local_refs", NULL);
 
 	/*
 	 * Mark all complete remote refs as common refs.
 	 * Don't mark them common yet; the server has to be told so first.
 	 */
+	trace2_region_enter("fetch-pack", "mark_common_remote_refs", NULL);
 	for (ref = *refs; ref; ref = ref->next) {
 		struct object *o = deref_tag(the_repository,
 					     lookup_object(the_repository,
@@ -714,6 +724,7 @@ static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator,
 		negotiator->known_common(negotiator,
 					 (struct commit *)o);
 	}
+	trace2_region_leave("fetch-pack", "mark_common_remote_refs", NULL);
 
 	save_commit_buffer = old_save_commit_buffer;
 }
-- 
gitgitgadget
Junio C Hamano· Nov 20, 2019, 01:07 UTC · re: Erik Chen via GitGitGadget · lore

Re: [PATCH v5 1/1] fetch: add trace2 instrumentation

"Erik Chen via GitGitGadget" <gitgitgadget@gmail.com> writes:
Show 15 quoted lines
> From: Erik Chen <erikchen@chromium.org>
>
> Add trace2 regions to fetch-pack.c to better track time spent in the various
> phases of a fetch:
>
>     * parsing remote refs and finding a cutoff
>     * marking local refs as complete
>     * marking complete remote refs as common
>
> All stages could potentially be slow for repositories with many refs.
>
> Signed-off-by: Erik Chen <erikchen@chromium.org>
> ---
>  fetch-pack.c | 13 ++++++++++++-
>  1 file changed, 12 insertions(+), 1 deletion(-)
Thanks, will queue.

← back to recent threads