fetch: add trace2 instrumentation

From: Erik Chen <[email protected]>

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 <[email protected]>

---
 fetch-pack.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

fetch-pack.c +0 -0

index 0130b44112..f2f3365bbe 100644

fetch-pack.c +8 -1

 	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

From: Erik Chen <[email protected]>

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 <[email protected]>

---
 fetch-pack.c | 8 ++++++++
 1 file changed, 8 insertions(+)

fetch-pack.c +2 -0

index 0130b44112..5e3eee0477 100644
@@ -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;
 

fetch-pack.c +2 -0

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

Quoted 8 lines · Erik Chen via GitGitGadget

From: Erik Chen <[email protected]>

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)

Quoted 6 lines

Both of these stages can be slow for repositories with many refs.

Signed-off-by Erik Chen <[email protected]>

---
 fetch-pack.c | 8 ++++++++
 1 file changed, 8 insertions(+)

OK.

Quoted 14 lines

fetch-pack.c +2 -0

index 0130b44112..5e3eee0477 100644
@@ -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;
 

fetch-pack.c static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator, · line 697

Quoted 6 lines

fetch-pack.c +3 -0

@@ -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).

Quoted 13 lines

fetch-pack.c +2 -0

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

fetch-pack.c static void mark_complete_and_common_ref(struct fetch_negotiator *negotiator, · line 726

Quoted 4 lines

fetch-pack.c +1 -0

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

Quoted 20 lines · Junio C Hamano

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
}

Quoted 3 lines

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

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.

Quoted 21 lines · Derrick Stolee

Quoted 20 lines · Junio C Hamano

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
}

Quoted 7 lines

Quoted 3 lines

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.

Quoted 8 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.

Quoted 4 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 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.

/*
* 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).

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

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 [email protected] [[email protected]]

Quoted 9 lines · erik chen via GitGitGadget

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 [email protected] [[email protected]]

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.

From: Erik Chen <[email protected]>

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 <[email protected]>

---
 fetch-pack.c | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)