Merge branch 'js/fetch-push-trace2-annotation'

More trace2 events at key points on push and fetch code paths have
been added.

* js/fetch-push-trace2-annotation:
  send-pack: add new tracing regions for push
  fetch: add top-level trace2 regions
  trace2: implement trace2_printf() for event target
This commit is contained in:
Junio C Hamano
2024-09-03 09:15:01 -07:00
5 changed files with 67 additions and 8 deletions

View File

@ -128,7 +128,7 @@ yields
------------
$ cat ~/log.event
{"event":"version","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"3","exe":"2.20.1.155.g426c96fcdb"}
{"event":"version","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"4","exe":"2.20.1.155.g426c96fcdb"}
{"event":"start","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621027Z","file":"common-main.c","line":39,"t_abs":0.001173,"argv":["git","version"]}
{"event":"cmd_name","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621122Z","file":"git.c","line":432,"name":"version","hierarchy":"version"}
{"event":"exit","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621236Z","file":"git.c","line":662,"t_abs":0.001227,"code":0}
@ -344,7 +344,7 @@ only present on the "start" and "atexit" events.
{
"event":"version",
...
"evt":"3", # EVENT format version
"evt":"4", # EVENT format version
"exe":"2.20.1.155.g426c96fcdb" # git version
}
------------
@ -835,6 +835,19 @@ The "value" field may be an integer or a string.
}
------------
`"printf"`::
This event logs a human-readable message with no particular formatting
guidelines.
+
------------
{
"event":"printf",
...
"t_abs":0.015905, # elapsed time in seconds
"msg":"Hello world" # optional
}
------------
== Example Trace2 API Usage

View File

@ -2408,6 +2408,7 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
struct oidset_iter iter;
const struct object_id *oid;
trace2_region_enter("fetch", "negotiate-only", the_repository);
if (!remote)
die(_("must supply remote when using --negotiate-only"));
gtransport = prepare_transport(remote, 1);
@ -2416,6 +2417,7 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
} else {
warning(_("protocol does not support --negotiate-only, exiting"));
result = 1;
trace2_region_leave("fetch", "negotiate-only", the_repository);
goto cleanup;
}
if (server_options.nr)
@ -2426,11 +2428,17 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
while ((oid = oidset_iter_next(&iter)))
printf("%s\n", oid_to_hex(oid));
oidset_clear(&acked_commits);
trace2_region_leave("fetch", "negotiate-only", the_repository);
} else if (remote) {
if (filter_options.choice || repo_has_promisor_remote(the_repository))
if (filter_options.choice || repo_has_promisor_remote(the_repository)) {
trace2_region_enter("fetch", "setup-partial", the_repository);
fetch_one_setup_partial(remote);
trace2_region_leave("fetch", "setup-partial", the_repository);
}
trace2_region_enter("fetch", "fetch-one", the_repository);
result = fetch_one(remote, argc, argv, prune_tags_ok, stdin_refspecs,
&config);
trace2_region_leave("fetch", "fetch-one", the_repository);
} else {
int max_children = max_jobs;
@ -2450,7 +2458,9 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
max_children = config.parallel;
/* TODO should this also die if we have a previous partial-clone? */
trace2_region_enter("fetch", "fetch-multiple", the_repository);
result = fetch_multiple(&list, max_children, &config);
trace2_region_leave("fetch", "fetch-multiple", the_repository);
}
/*
@ -2472,6 +2482,7 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
max_children = config.parallel;
add_options_to_argv(&options, &config);
trace2_region_enter_printf("fetch", "recurse-submodule", the_repository, "%s", submodule_prefix);
result = fetch_submodules(the_repository,
&options,
submodule_prefix,
@ -2479,6 +2490,7 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
recurse_submodules_default,
verbosity < 0,
max_children);
trace2_region_leave_printf("fetch", "recurse-submodule", the_repository, "%s", submodule_prefix);
strvec_clear(&options);
}
@ -2502,9 +2514,11 @@ int cmd_fetch(int argc, const char **argv, const char *prefix)
if (progress)
commit_graph_flags |= COMMIT_GRAPH_WRITE_PROGRESS;
trace2_region_enter("fetch", "write-commit-graph", the_repository);
write_commit_graph_reachable(the_repository->objects->odb,
commit_graph_flags,
NULL);
trace2_region_leave("fetch", "write-commit-graph", the_repository);
}
if (enable_auto_gc) {

View File

@ -13,6 +13,7 @@
#include "config.h"
#include "fetch-pack.h"
#include "remote.h"
#include "trace2.h"
static struct {
enum bundle_list_heuristic heuristic;
@ -799,6 +800,8 @@ int fetch_bundle_uri(struct repository *r, const char *uri,
.id = xstrdup(""),
};
trace2_region_enter("fetch", "fetch-bundle-uri", the_repository);
init_bundle_list(&list);
/*
@ -824,6 +827,7 @@ cleanup:
for_all_bundles_in_list(&list, unlink_bundle, NULL);
clear_bundle_list(&list);
clear_remote_bundle_info(&bundle, NULL);
trace2_region_leave("fetch", "fetch-bundle-uri", the_repository);
return result;
}

View File

@ -75,6 +75,7 @@ static int pack_objects(int fd, struct ref *refs, struct oid_array *advertised,
int i;
int rc;
trace2_region_enter("send_pack", "pack_objects", the_repository);
strvec_push(&po.args, "pack-objects");
strvec_push(&po.args, "--all-progress-implied");
strvec_push(&po.args, "--revs");
@ -146,8 +147,10 @@ static int pack_objects(int fd, struct ref *refs, struct oid_array *advertised,
*/
if (rc > 128 && rc != 141)
error("pack-objects died of signal %d", rc - 128);
trace2_region_leave("send_pack", "pack_objects", the_repository);
return -1;
}
trace2_region_leave("send_pack", "pack_objects", the_repository);
return 0;
}
@ -170,6 +173,7 @@ static int receive_status(struct packet_reader *reader, struct ref *refs)
int new_report = 0;
int once = 0;
trace2_region_enter("send_pack", "receive_status", the_repository);
hint = NULL;
ret = receive_unpack_status(reader);
while (1) {
@ -268,6 +272,7 @@ static int receive_status(struct packet_reader *reader, struct ref *refs)
new_report = 1;
}
}
trace2_region_leave("send_pack", "receive_status", the_repository);
return ret;
}
@ -512,8 +517,11 @@ int send_pack(struct send_pack_args *args,
}
git_config_get_bool("push.negotiate", &push_negotiate);
if (push_negotiate)
if (push_negotiate) {
trace2_region_enter("send_pack", "push_negotiate", the_repository);
get_commons_through_negotiation(args->url, remote_refs, &commons);
trace2_region_leave("send_pack", "push_negotiate", the_repository);
}
if (!git_config_get_bool("push.usebitmaps", &use_bitmaps))
args->disable_bitmaps = !use_bitmaps;
@ -641,10 +649,11 @@ int send_pack(struct send_pack_args *args,
/*
* Finally, tell the other end!
*/
if (!args->dry_run && push_cert_nonce)
if (!args->dry_run && push_cert_nonce) {
cmds_sent = generate_push_cert(&req_buf, remote_refs, args,
cap_buf.buf, push_cert_nonce);
else if (!args->dry_run)
trace2_printf("Generated push certificate");
} else if (!args->dry_run) {
for (ref = remote_refs; ref; ref = ref->next) {
char *old_hex, *new_hex;
@ -664,6 +673,7 @@ int send_pack(struct send_pack_args *args,
old_hex, new_hex, ref->name);
}
}
}
if (use_push_options) {
struct string_list_item *item;

View File

@ -24,7 +24,7 @@ static struct tr2_dst tr2dst_event = {
* a new field to an existing event, do not require an increment to the EVENT
* format version.
*/
#define TR2_EVENT_VERSION "3"
#define TR2_EVENT_VERSION "4"
/*
* Region nesting limit for messages written to the event target.
@ -622,6 +622,24 @@ static void fn_data_json_fl(const char *file, int line,
}
}
static void fn_printf_va_fl(const char *file, int line,
uint64_t us_elapsed_absolute,
const char *fmt, va_list ap)
{
const char *event_name = "printf";
struct json_writer jw = JSON_WRITER_INIT;
double t_abs = (double)us_elapsed_absolute / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_double(&jw, "t_abs", 6, t_abs);
maybe_add_string_va(&jw, "msg", fmt, ap);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_timer(const struct tr2_timer_metadata *meta,
const struct tr2_timer *timer,
int is_final_data)
@ -694,7 +712,7 @@ struct tr2_tgt tr2_tgt_event = {
.pfn_region_leave_printf_va_fl = fn_region_leave_printf_va_fl,
.pfn_data_fl = fn_data_fl,
.pfn_data_json_fl = fn_data_json_fl,
.pfn_printf_va_fl = NULL,
.pfn_printf_va_fl = fn_printf_va_fl,
.pfn_timer = fn_timer,
.pfn_counter = fn_counter,
};