[PATCH 0/2] add trace2 regions to fetch & push

[PATCH 0/2] add trace2 regions to fetch & push

[Josh Steadmon]

We'd like to collect better statistics about where the time is spent in
fetches and pushes so that we can hopefully identify some areas for
future optimization. So let's add some trace2 regions around some of the
fetch/push phases so we can break down their timing.

Josh Steadmon (2):
  fetch: add trace2 instrumentation
  push: add trace2 instrumentation

 builtin/fetch.c | 22 +++++++++++++++-------
 builtin/push.c  |  2 ++
 fetch-pack.c    | 13 ++++++++++++-
 transport.c     | 14 ++++++++++++--
 4 files changed, 41 insertions(+), 10 deletions(-)

-- 
2.23.0.444.g18eeb5a265-goog

[PATCH 1/2] fetch: add trace2 instrumentation

[Josh Steadmon]

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

* listing refs
* negotiation for protocol versions v0-v2
* fetching refs
* consuming refs

Signed-off-by: Josh Steadmon <steadmon@google.com>
---
 builtin/fetch.c | 22 +++++++++++++++-------
 fetch-pack.c    | 13 ++++++++++++-
 2 files changed, 27 insertions(+), 8 deletions(-)

diff --git a/builtin/fetch.c b/builtin/fetch.c
index 67c0eb88c6..ee3dc085bb 100644
--- a/builtin/fetch.c
+++ b/builtin/fetch.c
@@ -1071,8 +1071,11 @@ static int check_exist_and_connected(struct ref *ref_map)
 static int fetch_refs(struct transport *transport, struct ref *ref_map)
 {
 	int ret = check_exist_and_connected(ref_map);
-	if (ret)
+	if (ret) {
+		trace2_region_enter("fetch", "fetch_refs", the_repository);
 		ret = transport_fetch_refs(transport, ref_map);
+		trace2_region_leave("fetch", "fetch_refs", the_repository);
+	}
 	if (!ret)
 		/*
 		 * Keep the new pack's ".keep" file around to allow the caller
@@ -1088,11 +1091,14 @@ static int consume_refs(struct transport *transport, struct ref *ref_map)
 {
 	int connectivity_checked = transport->smart_options
 		? transport->smart_options->connectivity_checked : 0;
-	int ret = store_updated_refs(transport->url,
-				     transport->remote->name,
-				     connectivity_checked,
-				     ref_map);
+	int ret;
+	trace2_region_enter("fetch", "consume_refs", the_repository);
+	ret = store_updated_refs(transport->url,
+				 transport->remote->name,
+				 connectivity_checked,
+				 ref_map);
 	transport_unlock_pack(transport);
+	trace2_region_leave("fetch", "consume_refs", the_repository);
 	return ret;
 }
 
@@ -1337,9 +1343,11 @@ static int do_fetch(struct transport *transport,
 			argv_array_push(&ref_prefixes, "refs/tags/");
 	}
 
-	if (must_list_refs)
+	if (must_list_refs) {
+		trace2_region_enter("fetch", "remote_refs", the_repository);
 		remote_refs = transport_get_remote_refs(transport, &ref_prefixes);
-	else
+		trace2_region_leave("fetch", "remote_refs", the_repository);
+	} else
 		remote_refs = NULL;
 
 	argv_array_clear(&ref_prefixes);
diff --git a/fetch-pack.c b/fetch-pack.c
index 6ccc6294ea..c016eeab1d 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -382,6 +382,7 @@ static int find_common(struct fetch_negotiator *negotiator,
 		state_len = 0;
 	}
 
+	trace2_region_enter("fetch-pack", "negotiation_v0_v1", the_repository);
 	flushes = 0;
 	retval = -1;
 	if (args->no_dependents)
@@ -466,6 +467,7 @@ static int find_common(struct fetch_negotiator *negotiator,
 		}
 	}
 done:
+	trace2_region_leave("fetch-pack", "negotiation_v0_v1", the_repository);
 	if (!got_ready || !no_done) {
 		packet_buf_write(&req_buf, "done\n");
 		send_request(args, fd[1], &req_buf);
@@ -1378,7 +1380,7 @@ static struct ref *do_fetch_pack_v2(struct fetch_pack_args *args,
 	enum fetch_state state = FETCH_CHECK_LOCAL;
 	struct oidset common = OIDSET_INIT;
 	struct packet_reader reader;
-	int in_vain = 0;
+	int in_vain = 0, negotiation_started = 0;
 	int haves_to_send = INITIAL_FLUSH;
 	struct fetch_negotiator negotiator;
 	fetch_negotiator_init(r, &negotiator);
@@ -1421,6 +1423,12 @@ static struct ref *do_fetch_pack_v2(struct fetch_pack_args *args,
 			}
 			break;
 		case FETCH_SEND_REQUEST:
+			if (!negotiation_started) {
+				negotiation_started = 1;
+				trace2_region_enter("fetch-pack",
+						    "negotiation_v2",
+						    the_repository);
+			}
 			if (send_fetch_request(&negotiator, fd[1], args, ref,
 					       &common,
 					       &haves_to_send, &in_vain,
@@ -1444,6 +1452,9 @@ static struct ref *do_fetch_pack_v2(struct fetch_pack_args *args,
 			}
 			break;
 		case FETCH_GET_PACK:
+			trace2_region_leave("fetch-pack",
+					    "negotiation_v2",
+					    the_repository);
 			/* Check for shallow-info section */
 			if (process_section_header(&reader, "shallow-info", 1))
 				receive_shallow_info(args, &reader, shallows, si);
-- 
2.23.0.444.g18eeb5a265-goog

[PATCH 2/2] push: add trace2 instrumentation

[Josh Steadmon]

Add trace2 regions in transport.c and builtin/push.c to better track
time spent in various phases of pushing:

* Listing refs
* Checking submodules
* Pushing submodules
* Pushing refs

Signed-off-by: Josh Steadmon <steadmon@google.com>
---
 builtin/push.c |  2 ++
 transport.c    | 14 ++++++++++++--
 2 files changed, 14 insertions(+), 2 deletions(-)

diff --git a/builtin/push.c b/builtin/push.c
index 3742daf7b0..cc1292a566 100644
--- a/builtin/push.c
+++ b/builtin/push.c
@@ -357,8 +357,10 @@ static int push_with_options(struct transport *transport, struct refspec *rs,
 
 	if (verbosity > 0)
 		fprintf(stderr, _("Pushing to %s\n"), transport->url);
+	trace2_region_enter("push", "transport_push", the_repository);
 	err = transport_push(the_repository, transport,
 			     rs, flags, &reject_reasons);
+	trace2_region_leave("push", "transport_push", the_repository);
 	if (err != 0) {
 		fprintf(stderr, "%s", push_get_color(PUSH_COLOR_ERROR));
 		error(_("failed to push some refs to '%s'"), transport->url);
diff --git a/transport.c b/transport.c
index ae558af944..f313f288de 100644
--- a/transport.c
+++ b/transport.c
@@ -1145,8 +1145,10 @@ int transport_push(struct repository *r,
 
 		refspec_ref_prefixes(rs, &ref_prefixes);
 
+		trace2_region_enter("transport_push", "get_refs_list", the_repository);
 		remote_refs = transport->vtable->get_refs_list(transport, 1,
 							       &ref_prefixes);
+		trace2_region_leave("transport_push", "get_refs_list", the_repository);
 
 		argv_array_clear(&ref_prefixes);
 
@@ -1182,6 +1184,7 @@ int transport_push(struct repository *r,
 			struct ref *ref = remote_refs;
 			struct oid_array commits = OID_ARRAY_INIT;
 
+			trace2_region_enter("transport_push", "push_submodules", the_repository);
 			for (; ref; ref = ref->next)
 				if (!is_null_oid(&ref->new_oid))
 					oid_array_append(&commits,
@@ -1194,9 +1197,11 @@ int transport_push(struct repository *r,
 						      transport->push_options,
 						      pretend)) {
 				oid_array_clear(&commits);
+				trace2_region_leave("transport_push", "push_submodules", the_repository);
 				die(_("failed to push all needed submodules"));
 			}
 			oid_array_clear(&commits);
+			trace2_region_leave("transport_push", "push_submodules", the_repository);
 		}
 
 		if (((flags & TRANSPORT_RECURSE_SUBMODULES_CHECK) ||
@@ -1207,6 +1212,7 @@ int transport_push(struct repository *r,
 			struct string_list needs_pushing = STRING_LIST_INIT_DUP;
 			struct oid_array commits = OID_ARRAY_INIT;
 
+			trace2_region_enter("transport_push", "check_submodules", the_repository);
 			for (; ref; ref = ref->next)
 				if (!is_null_oid(&ref->new_oid))
 					oid_array_append(&commits,
@@ -1217,15 +1223,19 @@ int transport_push(struct repository *r,
 						     transport->remote->name,
 						     &needs_pushing)) {
 				oid_array_clear(&commits);
+				trace2_region_leave("transport_push", "check_submodules", the_repository);
 				die_with_unpushed_submodules(&needs_pushing);
 			}
 			string_list_clear(&needs_pushing, 0);
 			oid_array_clear(&commits);
+			trace2_region_leave("transport_push", "check_submodules", the_repository);
 		}
 
-		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY))
+		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY)) {
+			trace2_region_enter("transport_push", "push_refs", the_repository);
 			push_ret = transport->vtable->push_refs(transport, remote_refs, flags);
-		else
+			trace2_region_leave("transport_push", "push_refs", the_repository);
+		} else
 			push_ret = 0;
 		err = push_had_errors(remote_refs);
 		ret = push_ret | err;
-- 
2.23.0.444.g18eeb5a265-goog

Re: [PATCH 0/2] add trace2 regions to fetch & push

[Jonathan Tan]

> We'd like to collect better statistics about where the time is spent in
> fetches and pushes so that we can hopefully identify some areas for
> future optimization. So let's add some trace2 regions around some of the
> fetch/push phases so we can break down their timing.

Thanks.

Patch 1 looks good to me - different regions at the same level
(builtin/fetch.c, so it will be just for "git fetch") and one specific
one just for negotiation, which has to be in fetch-pack.c because only
that file operates at that level.

Patch 2 mostly looks good to me too - unlike fetch, a lot happens in
transport.c, so it's reasonable to put most of the regions there. One
comment: in transport_push(), should trace2_region_{enter,leave} take
"r" instead of "the_repository"?

Re: [PATCH 0/2] add trace2 regions to fetch & push

[Josh Steadmon]

On 2019.10.07 14:46, Jonathan Tan wrote:
> > We'd like to collect better statistics about where the time is spent in
> > fetches and pushes so that we can hopefully identify some areas for
> > future optimization. So let's add some trace2 regions around some of the
> > fetch/push phases so we can break down their timing.
> 
> Thanks.
> 
> Patch 1 looks good to me - different regions at the same level
> (builtin/fetch.c, so it will be just for "git fetch") and one specific
> one just for negotiation, which has to be in fetch-pack.c because only
> that file operates at that level.
> 
> Patch 2 mostly looks good to me too - unlike fetch, a lot happens in
> transport.c, so it's reasonable to put most of the regions there. One
> comment: in transport_push(), should trace2_region_{enter,leave} take
> "r" instead of "the_repository"?

Ah yeah, thanks for the catch. Fixed in V2.

Re: [PATCH 0/2] add trace2 regions to fetch & push

[Junio C Hamano]

Josh Steadmon <steadmon@google.com> writes:

> On 2019.10.07 14:46, Jonathan Tan wrote:
>> > We'd like to collect better statistics about where the time is spent in
>> > fetches and pushes so that we can hopefully identify some areas for
>> > future optimization. So let's add some trace2 regions around some of the
>> > fetch/push phases so we can break down their timing.
>> 
>> Thanks.
>> 
>> Patch 1 looks good to me - different regions at the same level
>> (builtin/fetch.c, so it will be just for "git fetch") and one specific
>> one just for negotiation, which has to be in fetch-pack.c because only
>> that file operates at that level.
>> 
>> Patch 2 mostly looks good to me too - unlike fetch, a lot happens in
>> transport.c, so it's reasonable to put most of the regions there. One
>> comment: in transport_push(), should trace2_region_{enter,leave} take
>> "r" instead of "the_repository"?
>
> Ah yeah, thanks for the catch. Fixed in V2.

Yuck.  It's already in 'next', isn't it?

Re: [PATCH 0/2] add trace2 regions to fetch & push

[Junio C Hamano]

Junio C Hamano <gitster@pobox.com> writes:

> Yuck.  It's already in 'next', isn't it?

Yuck, indeed.  Here is your v2 in an incremental form to be queued
on top.

Thanks.

-- >8 --
Subject: [PATCH 3/2] transport: push codepath can take arbitrary repository

The previous step added annotations with "the_repository" to various
functions in the push codepath in the transport layer, but they all
can take arbitrary repository pointer, and may be working on a
repository that is not the_repository.  Fix them.

Signed-off-by: Josh Steadmon <steadmon@google.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
---
 transport.c | 20 ++++++++++----------
 1 file changed, 10 insertions(+), 10 deletions(-)

diff --git a/transport.c b/transport.c
index f313f288de..83379a037d 100644
--- a/transport.c
+++ b/transport.c
@@ -1145,10 +1145,10 @@ int transport_push(struct repository *r,
 
 		refspec_ref_prefixes(rs, &ref_prefixes);
 
-		trace2_region_enter("transport_push", "get_refs_list", the_repository);
+		trace2_region_enter("transport_push", "get_refs_list", r);
 		remote_refs = transport->vtable->get_refs_list(transport, 1,
 							       &ref_prefixes);
-		trace2_region_leave("transport_push", "get_refs_list", the_repository);
+		trace2_region_leave("transport_push", "get_refs_list", r);
 
 		argv_array_clear(&ref_prefixes);
 
@@ -1184,7 +1184,7 @@ int transport_push(struct repository *r,
 			struct ref *ref = remote_refs;
 			struct oid_array commits = OID_ARRAY_INIT;
 
-			trace2_region_enter("transport_push", "push_submodules", the_repository);
+			trace2_region_enter("transport_push", "push_submodules", r);
 			for (; ref; ref = ref->next)
 				if (!is_null_oid(&ref->new_oid))
 					oid_array_append(&commits,
@@ -1197,11 +1197,11 @@ int transport_push(struct repository *r,
 						      transport->push_options,
 						      pretend)) {
 				oid_array_clear(&commits);
-				trace2_region_leave("transport_push", "push_submodules", the_repository);
+				trace2_region_leave("transport_push", "push_submodules", r);
 				die(_("failed to push all needed submodules"));
 			}
 			oid_array_clear(&commits);
-			trace2_region_leave("transport_push", "push_submodules", the_repository);
+			trace2_region_leave("transport_push", "push_submodules", r);
 		}
 
 		if (((flags & TRANSPORT_RECURSE_SUBMODULES_CHECK) ||
@@ -1212,7 +1212,7 @@ int transport_push(struct repository *r,
 			struct string_list needs_pushing = STRING_LIST_INIT_DUP;
 			struct oid_array commits = OID_ARRAY_INIT;
 
-			trace2_region_enter("transport_push", "check_submodules", the_repository);
+			trace2_region_enter("transport_push", "check_submodules", r);
 			for (; ref; ref = ref->next)
 				if (!is_null_oid(&ref->new_oid))
 					oid_array_append(&commits,
@@ -1223,18 +1223,18 @@ int transport_push(struct repository *r,
 						     transport->remote->name,
 						     &needs_pushing)) {
 				oid_array_clear(&commits);
-				trace2_region_leave("transport_push", "check_submodules", the_repository);
+				trace2_region_leave("transport_push", "check_submodules", r);
 				die_with_unpushed_submodules(&needs_pushing);
 			}
 			string_list_clear(&needs_pushing, 0);
 			oid_array_clear(&commits);
-			trace2_region_leave("transport_push", "check_submodules", the_repository);
+			trace2_region_leave("transport_push", "check_submodules", r);
 		}
 
 		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY)) {
-			trace2_region_enter("transport_push", "push_refs", the_repository);
+			trace2_region_enter("transport_push", "push_refs", r);
 			push_ret = transport->vtable->push_refs(transport, remote_refs, flags);
-			trace2_region_leave("transport_push", "push_refs", the_repository);
+			trace2_region_leave("transport_push", "push_refs", r);
 		} else
 			push_ret = 0;
 		err = push_had_errors(remote_refs);

[PATCH v2 0/2] add trace2 regions to fetch & push

[Josh Steadmon]

We'd like to collect better statistics about where the time is spent in
fetches and pushes so that we can hopefully identify some areas for
future optimization. So let's add some trace2 regions around some of the
fetch/push phases so we can break down their timing.

Changes since V1:
* Use the repository struct argument in transport_push(), rather than
  the global the_repository.

Josh Steadmon (2):
  fetch: add trace2 instrumentation
  push: add trace2 instrumentation

 builtin/fetch.c | 22 +++++++++++++++-------
 builtin/push.c  |  2 ++
 fetch-pack.c    | 13 ++++++++++++-
 transport.c     | 14 ++++++++++++--
 4 files changed, 41 insertions(+), 10 deletions(-)

Range-diff against v1:
1:  054936f40b ! 1:  fe6108b6f9 push: add trace2 instrumentation
    @@ transport.c: int transport_push(struct repository *r,
      
      		refspec_ref_prefixes(rs, &ref_prefixes);
      
    -+		trace2_region_enter("transport_push", "get_refs_list", the_repository);
    ++		trace2_region_enter("transport_push", "get_refs_list", r);
      		remote_refs = transport->vtable->get_refs_list(transport, 1,
      							       &ref_prefixes);
    -+		trace2_region_leave("transport_push", "get_refs_list", the_repository);
    ++		trace2_region_leave("transport_push", "get_refs_list", r);
      
      		argv_array_clear(&ref_prefixes);
      
    @@ transport.c: int transport_push(struct repository *r,
      			struct ref *ref = remote_refs;
      			struct oid_array commits = OID_ARRAY_INIT;
      
    -+			trace2_region_enter("transport_push", "push_submodules", the_repository);
    ++			trace2_region_enter("transport_push", "push_submodules", r);
      			for (; ref; ref = ref->next)
      				if (!is_null_oid(&ref->new_oid))
      					oid_array_append(&commits,
    @@ transport.c: int transport_push(struct repository *r,
      						      transport->push_options,
      						      pretend)) {
      				oid_array_clear(&commits);
    -+				trace2_region_leave("transport_push", "push_submodules", the_repository);
    ++				trace2_region_leave("transport_push", "push_submodules", r);
      				die(_("failed to push all needed submodules"));
      			}
      			oid_array_clear(&commits);
    -+			trace2_region_leave("transport_push", "push_submodules", the_repository);
    ++			trace2_region_leave("transport_push", "push_submodules", r);
      		}
      
      		if (((flags & TRANSPORT_RECURSE_SUBMODULES_CHECK) ||
    @@ transport.c: int transport_push(struct repository *r,
      			struct string_list needs_pushing = STRING_LIST_INIT_DUP;
      			struct oid_array commits = OID_ARRAY_INIT;
      
    -+			trace2_region_enter("transport_push", "check_submodules", the_repository);
    ++			trace2_region_enter("transport_push", "check_submodules", r);
      			for (; ref; ref = ref->next)
      				if (!is_null_oid(&ref->new_oid))
      					oid_array_append(&commits,
    @@ transport.c: int transport_push(struct repository *r,
      						     transport->remote->name,
      						     &needs_pushing)) {
      				oid_array_clear(&commits);
    -+				trace2_region_leave("transport_push", "check_submodules", the_repository);
    ++				trace2_region_leave("transport_push", "check_submodules", r);
      				die_with_unpushed_submodules(&needs_pushing);
      			}
      			string_list_clear(&needs_pushing, 0);
      			oid_array_clear(&commits);
    -+			trace2_region_leave("transport_push", "check_submodules", the_repository);
    ++			trace2_region_leave("transport_push", "check_submodules", r);
      		}
      
     -		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY))
     +		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY)) {
    -+			trace2_region_enter("transport_push", "push_refs", the_repository);
    ++			trace2_region_enter("transport_push", "push_refs", r);
      			push_ret = transport->vtable->push_refs(transport, remote_refs, flags);
     -		else
    -+			trace2_region_leave("transport_push", "push_refs", the_repository);
    ++			trace2_region_leave("transport_push", "push_refs", r);
     +		} else
      			push_ret = 0;
      		err = push_had_errors(remote_refs);
-- 
2.23.0.581.g78d2f28ef7-goog

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

[Josh Steadmon]

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

* listing refs
* negotiation for protocol versions v0-v2
* fetching refs
* consuming refs

Signed-off-by: Josh Steadmon <steadmon@google.com>
---
 builtin/fetch.c | 22 +++++++++++++++-------
 fetch-pack.c    | 13 ++++++++++++-
 2 files changed, 27 insertions(+), 8 deletions(-)

diff --git a/builtin/fetch.c b/builtin/fetch.c
index 67c0eb88c6..ee3dc085bb 100644
--- a/builtin/fetch.c
+++ b/builtin/fetch.c
@@ -1071,8 +1071,11 @@ static int check_exist_and_connected(struct ref *ref_map)
 static int fetch_refs(struct transport *transport, struct ref *ref_map)
 {
 	int ret = check_exist_and_connected(ref_map);
-	if (ret)
+	if (ret) {
+		trace2_region_enter("fetch", "fetch_refs", the_repository);
 		ret = transport_fetch_refs(transport, ref_map);
+		trace2_region_leave("fetch", "fetch_refs", the_repository);
+	}
 	if (!ret)
 		/*
 		 * Keep the new pack's ".keep" file around to allow the caller
@@ -1088,11 +1091,14 @@ static int consume_refs(struct transport *transport, struct ref *ref_map)
 {
 	int connectivity_checked = transport->smart_options
 		? transport->smart_options->connectivity_checked : 0;
-	int ret = store_updated_refs(transport->url,
-				     transport->remote->name,
-				     connectivity_checked,
-				     ref_map);
+	int ret;
+	trace2_region_enter("fetch", "consume_refs", the_repository);
+	ret = store_updated_refs(transport->url,
+				 transport->remote->name,
+				 connectivity_checked,
+				 ref_map);
 	transport_unlock_pack(transport);
+	trace2_region_leave("fetch", "consume_refs", the_repository);
 	return ret;
 }
 
@@ -1337,9 +1343,11 @@ static int do_fetch(struct transport *transport,
 			argv_array_push(&ref_prefixes, "refs/tags/");
 	}
 
-	if (must_list_refs)
+	if (must_list_refs) {
+		trace2_region_enter("fetch", "remote_refs", the_repository);
 		remote_refs = transport_get_remote_refs(transport, &ref_prefixes);
-	else
+		trace2_region_leave("fetch", "remote_refs", the_repository);
+	} else
 		remote_refs = NULL;
 
 	argv_array_clear(&ref_prefixes);
diff --git a/fetch-pack.c b/fetch-pack.c
index 6ccc6294ea..c016eeab1d 100644
--- a/fetch-pack.c
+++ b/fetch-pack.c
@@ -382,6 +382,7 @@ static int find_common(struct fetch_negotiator *negotiator,
 		state_len = 0;
 	}
 
+	trace2_region_enter("fetch-pack", "negotiation_v0_v1", the_repository);
 	flushes = 0;
 	retval = -1;
 	if (args->no_dependents)
@@ -466,6 +467,7 @@ static int find_common(struct fetch_negotiator *negotiator,
 		}
 	}
 done:
+	trace2_region_leave("fetch-pack", "negotiation_v0_v1", the_repository);
 	if (!got_ready || !no_done) {
 		packet_buf_write(&req_buf, "done\n");
 		send_request(args, fd[1], &req_buf);
@@ -1378,7 +1380,7 @@ static struct ref *do_fetch_pack_v2(struct fetch_pack_args *args,
 	enum fetch_state state = FETCH_CHECK_LOCAL;
 	struct oidset common = OIDSET_INIT;
 	struct packet_reader reader;
-	int in_vain = 0;
+	int in_vain = 0, negotiation_started = 0;
 	int haves_to_send = INITIAL_FLUSH;
 	struct fetch_negotiator negotiator;
 	fetch_negotiator_init(r, &negotiator);
@@ -1421,6 +1423,12 @@ static struct ref *do_fetch_pack_v2(struct fetch_pack_args *args,
 			}
 			break;
 		case FETCH_SEND_REQUEST:
+			if (!negotiation_started) {
+				negotiation_started = 1;
+				trace2_region_enter("fetch-pack",
+						    "negotiation_v2",
+						    the_repository);
+			}
 			if (send_fetch_request(&negotiator, fd[1], args, ref,
 					       &common,
 					       &haves_to_send, &in_vain,
@@ -1444,6 +1452,9 @@ static struct ref *do_fetch_pack_v2(struct fetch_pack_args *args,
 			}
 			break;
 		case FETCH_GET_PACK:
+			trace2_region_leave("fetch-pack",
+					    "negotiation_v2",
+					    the_repository);
 			/* Check for shallow-info section */
 			if (process_section_header(&reader, "shallow-info", 1))
 				receive_shallow_info(args, &reader, shallows, si);
-- 
2.23.0.581.g78d2f28ef7-goog

[PATCH v2 2/2] push: add trace2 instrumentation

[Josh Steadmon]

Add trace2 regions in transport.c and builtin/push.c to better track
time spent in various phases of pushing:

* Listing refs
* Checking submodules
* Pushing submodules
* Pushing refs

Signed-off-by: Josh Steadmon <steadmon@google.com>
---
 builtin/push.c |  2 ++
 transport.c    | 14 ++++++++++++--
 2 files changed, 14 insertions(+), 2 deletions(-)

diff --git a/builtin/push.c b/builtin/push.c
index 3742daf7b0..cc1292a566 100644
--- a/builtin/push.c
+++ b/builtin/push.c
@@ -357,8 +357,10 @@ static int push_with_options(struct transport *transport, struct refspec *rs,
 
 	if (verbosity > 0)
 		fprintf(stderr, _("Pushing to %s\n"), transport->url);
+	trace2_region_enter("push", "transport_push", the_repository);
 	err = transport_push(the_repository, transport,
 			     rs, flags, &reject_reasons);
+	trace2_region_leave("push", "transport_push", the_repository);
 	if (err != 0) {
 		fprintf(stderr, "%s", push_get_color(PUSH_COLOR_ERROR));
 		error(_("failed to push some refs to '%s'"), transport->url);
diff --git a/transport.c b/transport.c
index ae558af944..83379a037d 100644
--- a/transport.c
+++ b/transport.c
@@ -1145,8 +1145,10 @@ int transport_push(struct repository *r,
 
 		refspec_ref_prefixes(rs, &ref_prefixes);
 
+		trace2_region_enter("transport_push", "get_refs_list", r);
 		remote_refs = transport->vtable->get_refs_list(transport, 1,
 							       &ref_prefixes);
+		trace2_region_leave("transport_push", "get_refs_list", r);
 
 		argv_array_clear(&ref_prefixes);
 
@@ -1182,6 +1184,7 @@ int transport_push(struct repository *r,
 			struct ref *ref = remote_refs;
 			struct oid_array commits = OID_ARRAY_INIT;
 
+			trace2_region_enter("transport_push", "push_submodules", r);
 			for (; ref; ref = ref->next)
 				if (!is_null_oid(&ref->new_oid))
 					oid_array_append(&commits,
@@ -1194,9 +1197,11 @@ int transport_push(struct repository *r,
 						      transport->push_options,
 						      pretend)) {
 				oid_array_clear(&commits);
+				trace2_region_leave("transport_push", "push_submodules", r);
 				die(_("failed to push all needed submodules"));
 			}
 			oid_array_clear(&commits);
+			trace2_region_leave("transport_push", "push_submodules", r);
 		}
 
 		if (((flags & TRANSPORT_RECURSE_SUBMODULES_CHECK) ||
@@ -1207,6 +1212,7 @@ int transport_push(struct repository *r,
 			struct string_list needs_pushing = STRING_LIST_INIT_DUP;
 			struct oid_array commits = OID_ARRAY_INIT;
 
+			trace2_region_enter("transport_push", "check_submodules", r);
 			for (; ref; ref = ref->next)
 				if (!is_null_oid(&ref->new_oid))
 					oid_array_append(&commits,
@@ -1217,15 +1223,19 @@ int transport_push(struct repository *r,
 						     transport->remote->name,
 						     &needs_pushing)) {
 				oid_array_clear(&commits);
+				trace2_region_leave("transport_push", "check_submodules", r);
 				die_with_unpushed_submodules(&needs_pushing);
 			}
 			string_list_clear(&needs_pushing, 0);
 			oid_array_clear(&commits);
+			trace2_region_leave("transport_push", "check_submodules", r);
 		}
 
-		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY))
+		if (!(flags & TRANSPORT_RECURSE_SUBMODULES_ONLY)) {
+			trace2_region_enter("transport_push", "push_refs", r);
 			push_ret = transport->vtable->push_refs(transport, remote_refs, flags);
-		else
+			trace2_region_leave("transport_push", "push_refs", r);
+		} else
 			push_ret = 0;
 		err = push_had_errors(remote_refs);
 		ret = push_ret | err;
-- 
2.23.0.581.g78d2f28ef7-goog

Re: [PATCH v2 0/2] add trace2 regions to fetch & push

[Jonathan Tan]

> Changes since V1:
> * Use the repository struct argument in transport_push(), rather than
>   the global the_repository.

Thanks, the patches now look good to me. I verified that the repository
argument to the trace functions just cause a different repo ID to be
printed, which is what we want (e.g. fn_region_enter_printf_va_fl() in
tr2_tgt_event.c, which appears in the vtable defined at the bottom of
the file).

[PATCH 0/1] fetch: add trace2 instrumentation

[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 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

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

[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 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

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

[Erik Chen via GitGitGadget]

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;
-
 	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