summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorLibravatar Junio C Hamano <gitster@pobox.com>2019-03-07 09:59:56 +0900
committerLibravatar Junio C Hamano <gitster@pobox.com>2019-03-07 09:59:56 +0900
commit32038fef00b02fb52f362d1d0cf1c25c6c382abb (patch)
tree45b41a51c59dc7fbaae9a0414ef6b0e9b4579b31
parentMerge branch 'js/doc-symref-in-proto-v1' (diff)
parenttrace2: add for_each macros to clang-format (diff)
downloadtgif-32038fef00b02fb52f362d1d0cf1c25c6c382abb.tar.xz
Merge branch 'jh/trace2'
A more structured way to obtain execution trace has been added. * jh/trace2: trace2: add for_each macros to clang-format trace2: t/helper/test-trace2, t0210.sh, t0211.sh, t0212.sh trace2:data: add subverb for rebase trace2:data: add subverb to reset command trace2:data: add subverb to checkout command trace2:data: pack-objects: add trace2 regions trace2:data: add trace2 instrumentation to index read/write trace2:data: add trace2 hook classification trace2:data: add trace2 transport child classification trace2:data: add trace2 sub-process classification trace2:data: add editor/pager child classification trace2:data: add trace2 regions to wt-status trace2: collect Windows-specific process information trace2: create new combined trace facility trace2: Documentation/technical/api-trace2.txt
-rw-r--r--.clang-format2
-rw-r--r--Documentation/technical/api-trace2.txt1349
-rw-r--r--Makefile15
-rw-r--r--builtin/am.c1
-rw-r--r--builtin/checkout.c7
-rw-r--r--builtin/pack-objects.c16
-rw-r--r--builtin/rebase.c17
-rw-r--r--builtin/receive-pack.c4
-rw-r--r--builtin/reset.c6
-rw-r--r--builtin/submodule--helper.c9
-rw-r--r--builtin/worktree.c1
-rw-r--r--cache.h1
-rw-r--r--common-main.c13
-rw-r--r--compat/mingw.c11
-rw-r--r--compat/mingw.h3
-rw-r--r--compat/win32/trace2_win32_process_info.c147
-rw-r--r--config.c2
-rw-r--r--config.mak.uname2
-rw-r--r--connect.c3
-rw-r--r--editor.c1
-rw-r--r--exec-cmd.c2
-rw-r--r--git-compat-util.h7
-rw-r--r--git.c65
-rw-r--r--pager.c1
-rw-r--r--read-cache.c51
-rw-r--r--remote-curl.c7
-rw-r--r--repository.c2
-rw-r--r--repository.h3
-rw-r--r--run-command.c59
-rw-r--r--run-command.h13
-rw-r--r--sequencer.c2
-rw-r--r--sh-i18n--envsubst.c3
-rw-r--r--sub-process.c1
-rw-r--r--submodule.c11
-rw-r--r--t/helper/test-parse-options.c3
-rw-r--r--t/helper/test-tool.c4
-rw-r--r--t/helper/test-tool.h1
-rw-r--r--t/helper/test-trace2.c273
-rwxr-xr-xt/t0001-init.sh1
-rwxr-xr-xt/t0210-trace2-normal.sh135
-rw-r--r--t/t0210/scrub_normal.perl48
-rwxr-xr-xt/t0211-trace2-perf.sh153
-rw-r--r--t/t0211/scrub_perf.perl76
-rwxr-xr-xt/t0212-trace2-event.sh236
-rw-r--r--t/t0212/parse_events.perl251
-rw-r--r--trace2.c761
-rw-r--r--trace2.h385
-rw-r--r--trace2/tr2_cfg.c90
-rw-r--r--trace2/tr2_cfg.h19
-rw-r--r--trace2/tr2_cmd_name.c30
-rw-r--r--trace2/tr2_cmd_name.h24
-rw-r--r--trace2/tr2_dst.c252
-rw-r--r--trace2/tr2_dst.h36
-rw-r--r--trace2/tr2_sid.c67
-rw-r--r--trace2/tr2_sid.h18
-rw-r--r--trace2/tr2_tbuf.c32
-rw-r--r--trace2/tr2_tbuf.h23
-rw-r--r--trace2/tr2_tgt.h133
-rw-r--r--trace2/tr2_tgt_event.c588
-rw-r--r--trace2/tr2_tgt_normal.c323
-rw-r--r--trace2/tr2_tgt_perf.c534
-rw-r--r--trace2/tr2_tls.c164
-rw-r--r--trace2/tr2_tls.h97
-rw-r--r--transport-helper.c2
-rw-r--r--transport.c1
-rw-r--r--usage.c31
-rw-r--r--wt-status.c24
67 files changed, 6629 insertions, 23 deletions
diff --git a/.clang-format b/.clang-format
index de1c8b5c77..41d4cd23fd 100644
--- a/.clang-format
+++ b/.clang-format
@@ -149,7 +149,7 @@ Cpp11BracedListStyle: false
# A list of macros that should be interpreted as foreach loops instead of as
# function calls.
-ForEachMacros: ['for_each_string_list_item']
+ForEachMacros: ['for_each_string_list_item', 'for_each_wanted_builtin', 'for_each_builtin', 'for_each_ut']
# The maximum number of consecutive empty lines to keep.
MaxEmptyLinesToKeep: 1
diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt
new file mode 100644
index 0000000000..2de565fa3d
--- /dev/null
+++ b/Documentation/technical/api-trace2.txt
@@ -0,0 +1,1349 @@
+= Trace2 API
+
+The Trace2 API can be used to print debug, performance, and telemetry
+information to stderr or a file. The Trace2 feature is inactive unless
+explicitly enabled by enabling one or more Trace2 Targets.
+
+The Trace2 API is intended to replace the existing (Trace1)
+printf-style tracing provided by the existing `GIT_TRACE` and
+`GIT_TRACE_PERFORMANCE` facilities. During initial implementation,
+Trace2 and Trace1 may operate in parallel.
+
+The Trace2 API defines a set of high-level messages with known fields,
+such as (`start`: `argv`) and (`exit`: {`exit-code`, `elapsed-time`}).
+
+Trace2 instrumentation throughout the Git code base sends Trace2
+messages to the enabled Trace2 Targets. Targets transform these
+messages content into purpose-specific formats and write events to
+their data streams. In this manner, the Trace2 API can drive
+many different types of analysis.
+
+Targets are defined using a VTable allowing easy extension to other
+formats in the future. This might be used to define a binary format,
+for example.
+
+== Trace2 Targets
+
+Trace2 defines the following set of Trace2 Targets.
+Format details are given in a later section.
+
+`GIT_TR2` (NORMAL)::
+
+ a simple printf format like GIT_TRACE.
++
+------------
+$ export GIT_TR2=~/log.normal
+$ git version
+git version 2.20.1.155.g426c96fcdb
+------------
++
+------------
+$ cat ~/log.normal
+12:28:42.620009 common-main.c:38 version 2.20.1.155.g426c96fcdb
+12:28:42.620989 common-main.c:39 start git version
+12:28:42.621101 git.c:432 cmd_name version (version)
+12:28:42.621215 git.c:662 exit elapsed:0.001227 code:0
+12:28:42.621250 trace2/tr2_tgt_normal.c:124 atexit elapsed:0.001265 code:0
+------------
+
+`GIT_TR2_PERF` (PERF)::
+
+ a column-based format to replace GIT_TRACE_PERFORMANCE suitable for
+ development and testing, possibly to complement tools like gprof.
++
+------------
+$ export GIT_TR2_PERF=~/log.perf
+$ git version
+git version 2.20.1.155.g426c96fcdb
+------------
++
+------------
+$ cat ~/log.perf
+12:28:42.620675 common-main.c:38 | d0 | main | version | | | | | 2.20.1.155.g426c96fcdb
+12:28:42.621001 common-main.c:39 | d0 | main | start | | | | | git version
+12:28:42.621111 git.c:432 | d0 | main | cmd_name | | | | | version (version)
+12:28:42.621225 git.c:662 | d0 | main | exit | | 0.001227 | | | code:0
+12:28:42.621259 trace2/tr2_tgt_perf.c:211 | d0 | main | atexit | | 0.001265 | | | code:0
+------------
+
+`GIT_TR2_EVENT` (EVENT)::
+
+ a JSON-based format of event data suitable for telemetry analysis.
++
+------------
+$ export GIT_TR2_EVENT=~/log.event
+$ git version
+git version 2.20.1.155.g426c96fcdb
+------------
++
+------------
+$ cat ~/log.event
+{"event":"version","sid":"1547659722619736-11614","thread":"main","time":"2019-01-16 17:28:42.620713","file":"common-main.c","line":38,"evt":"1","exe":"2.20.1.155.g426c96fcdb"}
+{"event":"start","sid":"1547659722619736-11614","thread":"main","time":"2019-01-16 17:28:42.621027","file":"common-main.c","line":39,"argv":["git","version"]}
+{"event":"cmd_name","sid":"1547659722619736-11614","thread":"main","time":"2019-01-16 17:28:42.621122","file":"git.c","line":432,"name":"version","hierarchy":"version"}
+{"event":"exit","sid":"1547659722619736-11614","thread":"main","time":"2019-01-16 17:28:42.621236","file":"git.c","line":662,"t_abs":0.001227,"code":0}
+{"event":"atexit","sid":"1547659722619736-11614","thread":"main","time":"2019-01-16 17:28:42.621268","file":"trace2/tr2_tgt_event.c","line":163,"t_abs":0.001265,"code":0}
+------------
+
+== Enabling a Target
+
+A Trace2 Target is enabled when the corresponding environment variable
+(`GIT_TR2`, `GIT_TR2_PERF`, or `GIT_TR2_EVENT`) is set. The following
+values are recognized.
+
+`0`::
+`false`::
+
+ Disables the target.
+
+`1`::
+`true`::
+
+ Enables the target and writes stream to `STDERR`.
+
+`[2-9]`::
+
+ Enables the target and writes to the already opened file descriptor.
+
+`<absolute-pathname>`::
+
+ Enables the target, opens and writes to the file in append mode.
+
+`af_unix:[<socket_type>:]<absolute-pathname>`::
+
+ Enables the target, opens and writes to a Unix Domain Socket
+ (on platforms that support them).
++
+Socket type can be either `stream` or `dgram`. If the socket type is
+omitted, Git will try both.
+
+== Trace2 API
+
+All public Trace2 functions and macros are defined in `trace2.h` and
+`trace2.c`. All public symbols are prefixed with `trace2_`.
+
+There are no public Trace2 data structures.
+
+The Trace2 code also defines a set of private functions and data types
+in the `trace2/` directory. These symbols are prefixed with `tr2_`
+and should only be used by functions in `trace2.c`.
+
+== Conventions for Public Functions and Macros
+
+The functions defined by the Trace2 API are declared and documented
+in `trace2.h`. It defines the API functions and wrapper macros for
+Trace2.
+
+Some functions have a `_fl()` suffix to indicate that they take `file`
+and `line-number` arguments.
+
+Some functions have a `_va_fl()` suffix to indicate that they also
+take a `va_list` argument.
+
+Some functions have a `_printf_fl()` suffix to indicate that they also
+take a varargs argument.
+
+There are CPP wrapper macros and ifdefs to hide most of these details.
+See `trace2.h` for more details. The following discussion will only
+describe the simplified forms.
+
+== Public API
+
+All Trace2 API functions send a messsage to all of the active
+Trace2 Targets. This section describes the set of available
+messages.
+
+It helps to divide these functions into groups for discussion
+purposes.
+
+=== Basic Command Messages
+
+These are concerned with the lifetime of the overall git process.
+
+`void trace2_initialize()`::
+
+ Determines if any Trace2 Targets should be enabled and
+ initializes the Trace2 facility. This includes starting the
+ elapsed time clocks and 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.
+
+`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.
+
+=== 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_TR2_CONFIG_PARAMS` 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 specific configuration
+ setting IFF it matches the `GIT_TR2_CONFIG_PARAMS` pattern.
++
+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.
+
+=== 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.
+
+=== 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()`.
+
+=== 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)`::
+
+ 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.
+
+== Trace2 Target Formats
+
+=== NORMAL Format
+
+NORMAL format is enabled when the `GIT_TR2` environment variable is
+set.
+
+Events are written as lines of the form:
+
+------------
+[<time> SP <filename>:<line> SP+] <event-name> [[SP] <event-message>] LF
+------------
+
+`<event-name>`::
+
+ is the event name.
+
+`<event-message>`::
+ is a free-form printf message intended for human consumption.
++
+Note that this may contain embedded LF or CRLF characters that are
+not escaped, so the event may spill across multiple lines.
+
+If `GIT_TR2_BRIEF` is true, the `time`, `filename`, and `line` fields
+are omitted.
+
+This target is intended to be more of a summary (like GIT_TRACE) and
+less detailed than the other targets. It ignores thread, region, and
+data messages, for example.
+
+=== PERF Format
+
+PERF format is enabled when the `GIT_TR2_PERF` environment variable
+is set.
+
+Events are written as lines of the form:
+
+------------
+[<time> SP <filename>:<line> SP+
+ BAR SP] d<depth> SP
+ BAR SP <thread-name> SP+
+ BAR SP <event-name> SP+
+ BAR SP [r<repo-id>] SP+
+ BAR SP [<t_abs>] SP+
+ BAR SP [<t_rel>] SP+
+ BAR SP [<category>] SP+
+ BAR SP DOTS* <perf-event-message>
+ LF
+------------
+
+`<depth>`::
+ is the git process depth. This is the number of parent
+ git processes. A top-level git command has depth value "d0".
+ A child of it has depth value "d1". A second level child
+ has depth value "d2" and so on.
+
+`<thread-name>`::
+ is a unique name for the thread. The primary thread
+ is called "main". Other thread names are of the form "th%d:%s"
+ and include a unique number and the name of the thread-proc.
+
+`<event-name>`::
+ is the event name.
+
+`<repo-id>`::
+ when present, is a number indicating the repository
+ in use. A `def_repo` event is emitted when a repository is
+ opened. This defines the repo-id and associated worktree.
+ Subsequent repo-specific events will reference this repo-id.
++
+Currently, this is always "r1" for the main repository.
+This field is in anticipation of in-proc submodules in the future.
+
+`<t_abs>`::
+ when present, is the absolute time in seconds since the
+ program started.
+
+`<t_rel>`::
+ when present, is time in seconds relative to the start of
+ the current region. For a thread-exit event, it is the elapsed
+ time of the thread.
+
+`<category>`::
+ is present on region and data events and is used to
+ indicate a broad category, such as "index" or "status".
+
+`<perf-event-message>`::
+ is a free-form printf message intended for human consumption.
+
+------------
+15:33:33.532712 wt-status.c:2310 | d0 | main | region_enter | r1 | 0.126064 | | status | label:print
+15:33:33.532712 wt-status.c:2331 | d0 | main | region_leave | r1 | 0.127568 | 0.001504 | status | label:print
+------------
+
+If `GIT_TR2_PERF_BRIEF` is true, the `time`, `file`, and `line`
+fields are omitted.
+
+------------
+d0 | main | region_leave | r1 | 0.011717 | 0.009122 | index | label:preload
+------------
+
+The PERF target is intended for interactive performance analysis
+during development and is quite noisy.