diff options
Diffstat (limited to 'Documentation/technical/api-trace2.txt')
| -rw-r--r-- | Documentation/technical/api-trace2.txt | 284 |
1 files changed, 38 insertions, 246 deletions
diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt index fd1e628944..4f07ceadcb 100644 --- a/Documentation/technical/api-trace2.txt +++ b/Documentation/technical/api-trace2.txt @@ -35,7 +35,7 @@ Format details are given in a later section. === The Normal Format Target The normal format target is a tradition printf format and similar -to GIT_TRACE format. This format is enabled with the `GIT_TR` +to GIT_TRACE format. This format is enabled with the `GIT_TRACE2` environment variable or the `trace2.normalTarget` system or global config setting. @@ -128,7 +128,7 @@ yields ------------ $ cat ~/log.event -{"event":"version","sid":"sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"1","exe":"2.20.1.155.g426c96fcdb"} +{"event":"version","sid":"sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.620713Z","file":"common-main.c","line":38,"evt":"2","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} @@ -142,10 +142,9 @@ system or global config value to one of the following: include::../trace2-target-values.txt[] -If the target already exists and is a directory, the traces will be -written to files (one per process) underneath the given directory. They -will be named according to the last component of the SID (optionally -followed by a counter to avoid filename collisions). +When trace files are written to a target directory, they will be named according +to the last component of the SID (optionally followed by a counter to avoid +filename collisions). == Trace2 API @@ -179,7 +178,7 @@ describe the simplified forms. == Public API -All Trace2 API functions send a messsage to all of the active +All Trace2 API functions send a message to all of the active Trace2 Targets. This section describes the set of available messages. @@ -189,261 +188,36 @@ purposes. === Basic Command Messages These are concerned with the lifetime of the overall git process. - -`void trace2_initialize_clock()`:: - - Initialize the Trace2 start clock and nothing else. This should - be called at the very top of main() to capture the process start - time and reduce startup order dependencies. - -`void trace2_initialize()`:: - - Determines if any Trace2 Targets should be enabled and - initializes the Trace2 facility. This includes setting up the - Trace2 thread local storage (TLS). -+ -This function emits a "version" message containing the version of git -and the Trace2 protocol. -+ -This function should be called from `main()` as early as possible in -the life of the process after essential process initialization. - -`int trace2_is_enabled()`:: - - Returns 1 if Trace2 is enabled (at least one target is - active). - -`void trace2_cmd_start(int argc, const char **argv)`:: - - Emits a "start" message containing the process command line - arguments. - -`int trace2_cmd_exit(int exit_code)`:: - - Emits an "exit" message containing the process exit-code and - elapsed time. -+ -Returns the exit-code. - -`void trace2_cmd_error(const char *fmt, va_list ap)`:: - - Emits an "error" message containing a formatted error message. - -`void trace2_cmd_path(const char *pathname)`:: - - Emits a "cmd_path" message with the full pathname of the - current process. +e.g: `void trace2_initialize_clock()`, `void trace2_initialize()`, +`int trace2_is_enabled()`, `void trace2_cmd_start(int argc, const char **argv)`. === Command Detail Messages These are concerned with describing the specific Git command after the command line, config, and environment are inspected. - -`void trace2_cmd_name(const char *name)`:: - - Emits a "cmd_name" message with the canonical name of the - command, for example "status" or "checkout". - -`void trace2_cmd_mode(const char *mode)`:: - - Emits a "cmd_mode" message with a qualifier name to further - describe the current git command. -+ -This message is intended to be used with git commands having multiple -major modes. For example, a "checkout" command can checkout a new -branch or it can checkout a single file, so the checkout code could -emit a cmd_mode message of "branch" or "file". - -`void trace2_cmd_alias(const char *alias, const char **argv_expansion)`:: - - Emits an "alias" message containing the alias used and the - argument expansion. - -`void trace2_def_param(const char *parameter, const char *value)`:: - - Emits a "def_param" message containing a key/value pair. -+ -This message is intended to report some global aspect of the current -command, such as a configuration setting or command line switch that -significantly affects program performance or behavior, such as -`core.abbrev`, `status.showUntrackedFiles`, or `--no-ahead-behind`. - -`void trace2_cmd_list_config()`:: - - Emits a "def_param" messages for "important" configuration - settings. -+ -The environment variable `GIT_TRACE2_CONFIG_PARAMS` or the `trace2.configParams` -config value can be set to a -list of patterns of important configuration settings, for example: -`core.*,remote.*.url`. This function will iterate over all config -settings and emit a "def_param" message for each match. - -`void trace2_cmd_set_config(const char *key, const char *value)`:: - - Emits a "def_param" message for a new or updated key/value - pair IF `key` is considered important. -+ -This is used to hook into `git_config_set()` and catch any -configuration changes and update a value previously reported by -`trace2_cmd_list_config()`. - -`void trace2_def_repo(struct repository *repo)`:: - - Registers a repository with the Trace2 layer. Assigns a - unique "repo-id" to `repo->trace2_repo_id`. -+ -Emits a "worktree" messages containing the repo-id and the worktree -pathname. -+ -Region and data messages (described later) may refer to this repo-id. -+ -The main/top-level repository will have repo-id value 1 (aka "r1"). -+ -The repo-id field is in anticipation of future in-proc submodule -repositories. +e.g: `void trace2_cmd_name(const char *name)`, +`void trace2_cmd_mode(const char *mode)`. === Child Process Messages These are concerned with the various spawned child processes, including shell scripts, git commands, editors, pagers, and hooks. -`void trace2_child_start(struct child_process *cmd)`:: - - Emits a "child_start" message containing the "child-id", - "child-argv", and "child-classification". -+ -Before calling this, set `cmd->trace2_child_class` to a name -describing the type of child process, for example "editor". -+ -This function assigns a unique "child-id" to `cmd->trace2_child_id`. -This field is used later during the "child_exit" message to associate -it with the "child_start" message. -+ -This function should be called before spawning the child process. - -`void trace2_child_exit(struct child_proess *cmd, int child_exit_code)`:: - - Emits a "child_exit" message containing the "child-id", - the child's elapsed time and exit-code. -+ -The reported elapsed time includes the process creation overhead and -time spend waiting for it to exit, so it may be slightly longer than -the time reported by the child itself. -+ -This function should be called after reaping the child process. - -`int trace2_exec(const char *exe, const char **argv)`:: - - Emits a "exec" message containing the "exec-id" and the - argv of the new process. -+ -This function should be called before calling one of the `exec()` -variants, such as `execvp()`. -+ -This function returns a unique "exec-id". This value is used later -if the exec() fails and a "exec-result" message is necessary. - -`void trace2_exec_result(int exec_id, int error_code)`:: - - Emits a "exec_result" message containing the "exec-id" - and the error code. -+ -On Unix-based systems, `exec()` does not return if successful. -This message is used to indicate that the `exec()` failed and -that the current program is continuing. +e.g: `void trace2_child_start(struct child_process *cmd)`. === Git Thread Messages These messages are concerned with Git thread usage. -`void trace2_thread_start(const char *thread_name)`:: - - Emits a "thread_start" message. -+ -The `thread_name` field should be a descriptive name, such as the -unique name of the thread-proc. A unique "thread-id" will be added -to the name to uniquely identify thread instances. -+ -Region and data messages (described later) may refer to this thread -name. -+ -This function must be called by the thread-proc of the new thread -(so that TLS data is properly initialized) and not by the caller -of `pthread_create()`. - -`void trace2_thread_exit()`:: - - Emits a "thread_exit" message containing the thread name - and the thread elapsed time. -+ -This function must be called by the thread-proc before it returns -(so that the coorect TLS data is used and cleaned up. It should -not be called by the caller of `pthread_join()`. +e.g: `void trace2_thread_start(const char *thread_name)`. === Region and Data Messages These are concerned with recording performance data -over regions or spans of code. - -`void trace2_region_enter(const char *category, const char *label, const struct repository *repo)`:: - -`void trace2_region_enter_printf(const char *category, const char *label, const struct repository *repo, const char *fmt, ...)`:: - -`void trace2_region_enter_printf_va(const char *category, const char *label, const struct repository *repo, const char *fmt, va_list ap)`:: - - Emits a thread-relative "region_enter" message with optional - printf string. -+ -This function pushes a new region nesting stack level on the current -thread and starts a clock for the new stack frame. -+ -The `category` field is an arbitrary category name used to classify -regions by feature area, such as "status" or "index". At this time -it is only just printed along with the rest of the message. It may -be used in the future to filter messages. -+ -The `label` field is an arbitrary label used to describe the activity -being started, such as "read_recursive" or "do_read_index". -+ -The `repo` field, if set, will be used to get the "repo-id", so that -recursive oerations can be attributed to the correct repository. - -`void trace2_region_leave(const char *category, const char *label, const struct repository *repo)`:: - -`void trace2_region_leave_printf(const char *category, const char *label, const struct repository *repo, const char *fmt, ...)`:: - -`void trace2_region_leave_printf_va(const char *category, const char *label, const struct repository *repo, const char *fmt, va_list ap)`:: - - Emits a thread-relative "region_leave" message with optional - printf string. -+ -This function pops the region nesting stack on the current thread -and reports the elapsed time of the stack frame. -+ -The `category`, `label`, and `repo` fields are the same as above. -The `category` and `label` do not need to match the correpsonding -"region_enter" message, but it makes the data stream easier to -understand. - -`void trace2_data_string(const char *category, const struct repository *repo, const char *key, const char * value)`:: - -`void trace2_data_intmax(const char *category, const struct repository *repo, const char *key, intmax value)`:: - -`void trace2_data_json(const char *category, const struct repository *repo, const char *key, const struct json_writer *jw)`:: +over regions or spans of code. e.g: +`void trace2_region_enter(const char *category, const char *label, const struct repository *repo)`. - Emits a region- and thread-relative "data" or "data_json" message. -+ -This is a key/value pair message containing information about the -current thread, region stack, and repository. This could be used -to print the number of files in a directory during a multi-threaded -recursive tree walk. - -`void trace2_printf(const char *fmt, ...)`:: - -`void trace2_printf_va(const char *fmt, va_list ap)`:: - - Emits a region- and thread-relative "printf" message. +Refer to trace2.h for details about all trace2 functions. == Trace2 Target Formats @@ -605,17 +379,35 @@ only present on the "start" and "atexit" events. ==== Event-Specific Key/Value Pairs `"version"`:: - This event gives the version of the executable and the EVENT format. + This event gives the version of the executable and the EVENT format. It + should always be the first event in a trace session. The EVENT format + version will be incremented if new event types are added, if existing + fields are removed, or if there are significant changes in + interpretation of existing events or fields. Smaller changes, such as + adding a new field to an existing event, will not require an increment + to the EVENT format version. + ------------ { "event":"version", ... - "evt":"1", # EVENT format version + "evt":"2", # EVENT format version "exe":"2.20.1.155.g426c96fcdb" # git version } ------------ +`"discard"`:: + This event is written to the git-trace2-discard sentinel file if there + are too many files in the target trace directory (see the + trace2.maxFiles config option). ++ +------------ +{ + "event":"discard", + ... +} +------------ + `"start"`:: This event contains the complete argv received by main(). + @@ -799,7 +591,7 @@ with "?". Note that the session-id of the child process is not available to the current/spawning process, so the child's PID is reported here as a hint for post-processing. (But it is only a hint because the child -proces may be a shell script which doesn't have a session-id.) +process may be a shell script which doesn't have a session-id.) + Note that the `t_rel` field contains the observed run time in seconds for the child process (starting before the fork/exec/spawn and @@ -1159,7 +951,7 @@ d0 | main | atexit | | 0.028809 | | + Regions may be nested. This causes messages to be indented in the PERF target, for example. -Elapsed times are relative to the start of the correpsonding nesting +Elapsed times are relative to the start of the corresponding nesting level as expected. For example, if we add region message to: + ---------------- @@ -1354,7 +1146,7 @@ d0 | main | atexit | | 0.030027 | | In this example, the preload region took 0.009122 seconds. The 7 threads took between 0.006069 and 0.008947 seconds to work on their portion of the index. Thread "th01" worked on 508 items at offset 0. Thread "th02" -worked on 508 items at offset 2032. Thread "th04" worked on 508 itemts +worked on 508 items at offset 2032. Thread "th04" worked on 508 items at offset 508. + This example also shows that thread names are assigned in a racy manner |