diff options
| -rw-r--r-- | Documentation/config.txt | 2 | ||||
| -rw-r--r-- | Documentation/config/trace2.txt | 56 | ||||
| -rw-r--r-- | Documentation/technical/api-trace2.txt | 184 | ||||
| -rw-r--r-- | Documentation/trace2-target-values.txt | 10 | ||||
| -rw-r--r-- | Makefile | 1 | ||||
| -rw-r--r-- | common-main.c | 8 | ||||
| -rw-r--r-- | compat/mingw.c | 2 | ||||
| -rw-r--r-- | compat/win32/trace2_win32_process_info.c | 50 | ||||
| -rw-r--r-- | config.c | 30 | ||||
| -rw-r--r-- | config.h | 5 | ||||
| -rwxr-xr-x | t/t0210-trace2-normal.sh | 49 | ||||
| -rwxr-xr-x | t/t0211-trace2-perf.sh | 43 | ||||
| -rwxr-xr-x | t/t0212-trace2-event.sh | 42 | ||||
| -rw-r--r-- | trace2.c | 21 | ||||
| -rw-r--r-- | trace2.h | 43 | ||||
| -rw-r--r-- | trace2/tr2_cfg.c | 7 | ||||
| -rw-r--r-- | trace2/tr2_dst.c | 36 | ||||
| -rw-r--r-- | trace2/tr2_dst.h | 3 | ||||
| -rw-r--r-- | trace2/tr2_sid.c | 53 | ||||
| -rw-r--r-- | trace2/tr2_sysenv.c | 127 | ||||
| -rw-r--r-- | trace2/tr2_sysenv.h | 36 | ||||
| -rw-r--r-- | trace2/tr2_tbuf.c | 19 | ||||
| -rw-r--r-- | trace2/tr2_tbuf.h | 5 | ||||
| -rw-r--r-- | trace2/tr2_tgt.h | 1 | ||||
| -rw-r--r-- | trace2/tr2_tgt_event.c | 53 | ||||
| -rw-r--r-- | trace2/tr2_tgt_normal.c | 19 | ||||
| -rw-r--r-- | trace2/tr2_tgt_perf.c | 23 | ||||
| -rw-r--r-- | trace2/tr2_tls.c | 38 | ||||
| -rw-r--r-- | trace2/tr2_tls.h | 8 |
29 files changed, 758 insertions, 216 deletions
diff --git a/Documentation/config.txt b/Documentation/config.txt index d87846faa6..7e2a6f61f5 100644 --- a/Documentation/config.txt +++ b/Documentation/config.txt @@ -422,6 +422,8 @@ include::config/submodule.txt[] include::config/tag.txt[] +include::config/trace2.txt[] + include::config/transfer.txt[] include::config/uploadarchive.txt[] diff --git a/Documentation/config/trace2.txt b/Documentation/config/trace2.txt new file mode 100644 index 0000000000..a5f409c1c1 --- /dev/null +++ b/Documentation/config/trace2.txt @@ -0,0 +1,56 @@ +Trace2 config settings are only read from the system and global +config files; repository local and worktree config files and `-c` +command line arguments are not respected. + +trace2.normalTarget:: + This variable controls the normal target destination. + It may be overridden by the `GIT_TR2` environment variable. + The following table shows possible values. + +trace2.perfTarget:: + This variable controls the performance target destination. + It may be overridden by the `GIT_TR2_PERF` environment variable. + The following table shows possible values. + +trace2.eventTarget:: + This variable controls the event target destination. + It may be overridden by the `GIT_TR2_EVENT` environment variable. + The following table shows possible values. ++ +include::../trace2-target-values.txt[] + +trace2.normalBrief:: + Boolean. When true `time`, `filename`, and `line` fields are + omitted from normal output. May be overridden by the + `GIT_TR2_BRIEF` environment variable. Defaults to false. + +trace2.perfBrief:: + Boolean. When true `time`, `filename`, and `line` fields are + omitted from PERF output. May be overridden by the + `GIT_TR2_PERF_BRIEF` environment variable. Defaults to false. + +trace2.eventBrief:: + Boolean. When true `time`, `filename`, and `line` fields are + omitted from event output. May be overridden by the + `GIT_TR2_EVENT_BRIEF` environment variable. Defaults to false. + +trace2.eventNesting:: + Integer. Specifies desired depth of nested regions in the + event output. Regions deeper than this value will be + omitted. May be overridden by the `GIT_TR2_EVENT_NESTING` + environment variable. Defaults to 2. + +trace2.configParams:: + A comma-separated list of patterns of "important" config + settings that should be recorded in the trace2 output. + For example, `core.*,remote.*.url` would cause the trace2 + output to contain events listing each configured remote. + May be overridden by the `GIT_TR2_CONFIG_PARAMS` environment + variable. Unset by default. + +trace2.destinationDebug:: + Boolean. When true Git will print error messages when a + trace target destination cannot be opened for writing. + By default, these errors are suppressed and tracing is + silently disabled. May be overridden by the + `GIT_TR2_DST_DEBUG` environment variable. diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt index d0948ba250..9e585b8e79 100644 --- a/Documentation/technical/api-trace2.txt +++ b/Documentation/technical/api-trace2.txt @@ -22,21 +22,41 @@ 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 is controlled using `trace2.*` config values in the system and +global config files and `GIT_TR2*` environment variables. Trace2 does +not read from repo local or worktree config files or respect `-c` +command line config settings. + == Trace2 Targets Trace2 defines the following set of Trace2 Targets. Format details are given in a later section. -`GIT_TR2` (NORMAL):: +=== 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` +environment variable or the `trace2.normalTarget` system or global +config setting. + +For example - a simple printf format like GIT_TRACE. -+ ------------ $ export GIT_TR2=~/log.normal $ git version git version 2.20.1.155.g426c96fcdb ------------ -+ + +or + +------------ +$ git config --global trace2.normalTarget ~/log.normal +$ git version +git version 2.20.1.155.g426c96fcdb +------------ + +yields + ------------ $ cat ~/log.normal 12:28:42.620009 common-main.c:38 version 2.20.1.155.g426c96fcdb @@ -46,81 +66,86 @@ $ cat ~/log.normal 12:28:42.621250 trace2/tr2_tgt_normal.c:124 atexit elapsed:0.001265 code:0 ------------ -`GIT_TR2_PERF` (PERF):: +=== The Performance Format Target + +The performance format target (PERF) is a column-based format to +replace GIT_TRACE_PERFORMANCE and is suitable for development and +testing, possibly to complement tools like gprof. This format is +enabled with the `GIT_TR2_PERF` environment variable or the +`trace2.perfTarget` system or global config setting. + +For example - 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 ------------ -+ + +or + +------------ +$ git config --global trace2.perfTarget ~/log.perf +$ git version +git version 2.20.1.155.g426c96fcdb +------------ + +yields + ------------ $ 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.621001 common-main.c:39 | d0 | main | start | | 0.001173 | | | 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):: +=== The Event Format Target + +The event format target is a JSON-based format of event data suitable +for telemetry analysis. This format is enabled with the `GIT_TR2_EVENT` +environment variable or the `trace2.eventTarget` system or global config +setting. + +For example - 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. +or -`0`:: -`false`:: - - Disables the target. - -`1`:: -`true`:: - - Enables the target and writes stream to `STDERR`. - -`[2-9]`:: +------------ +$ git config --global trace2.eventTarget ~/log.event +$ git version +git version 2.20.1.155.g426c96fcdb +------------ - Enables the target and writes to the already opened file descriptor. +yields -`<absolute-pathname>`:: +------------ +$ 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":"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} +{"event":"atexit","sid":"20190408T191610.507018Z-H9b68c35f-P000059a8","thread":"main","time":"2019-01-16T17:28:42.621268Z","file":"trace2/tr2_tgt_event.c","line":163,"t_abs":0.001265,"code":0} +------------ - Enables the target, opens and writes to the file in append mode. +=== Enabling a Target - 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). +To enable a target, set the corresponding environment variable or +system or global config value to one of the following: -`af_unix:[<socket_type>:]<absolute-pathname>`:: +include::../trace2-target-values.txt[] - 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. +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). == Trace2 API @@ -165,17 +190,23 @@ purposes. 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 starting the - elapsed time clocks and thread local storage (TLS). + 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. +the life of the process after essential process initialization. `int trace2_is_enabled()`:: @@ -242,15 +273,16 @@ significantly affects program performance or behavior, such as Emits a "def_param" messages for "important" configuration settings. + -The environment variable `GIT_TR2_CONFIG_PARAMS` can be set to a +The environment variable `GIT_TR2_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 specific configuration - setting IFF it matches the `GIT_TR2_CONFIG_PARAMS` pattern. + 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 @@ -417,9 +449,6 @@ recursive tree walk. === NORMAL Format -NORMAL format is enabled when the `GIT_TR2` environment variable is -set. - Events are written as lines of the form: ------------ @@ -436,8 +465,8 @@ Events are written as lines of the form: 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. +If `GIT_TR2_BRIEF` or `trace2.normalBrief` 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 @@ -445,9 +474,6 @@ 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: ------------ @@ -507,8 +533,8 @@ This field is in anticipation of in-proc submodules in the future. 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. +If `GIT_TR2_PERF_BRIEF` or `trace2.perfBrief` is true, the `time`, `file`, +and `line` fields are omitted. ------------ d0 | main | region_leave | r1 | 0.011717 | 0.009122 | index | label:preload @@ -519,9 +545,6 @@ during development and is quite noisy. === EVENT Format -EVENT format is enabled when the `GIT_TR2_EVENT` environment -variable is set. - Each event is a JSON-object containing multiple key/value pairs written as a single line and followed by a LF. @@ -539,11 +562,11 @@ The following key/value pairs are common to all events: ------------ { "event":"version", - "sid":"1547659722619736-11614", + "sid":"20190408T191827.272759Z-H9b68c35f-P00003510", "thread":"main", - "time":"2019-01-16 17:28:42.620713", + "time":"2019-04-08T19:18:27.282761Z", "file":"common-main.c", - "line":38, + "line":42, ... } ------------ @@ -575,9 +598,9 @@ The following key/value pairs are common to all events: `"repo":<repo-id>`:: when present, is the integer repo-id as described previously. -If `GIT_TR2_EVENT_BRIEF` is true, the `file` and `line` fields are omitted -from all events and the `time` field is only present on the "start" and -"atexit" events. +If `GIT_TR2_EVENT_BRIEF` or `trace2.eventBrief` is true, the `file` +and `line` fields are omitted from all events and the `time` field is +only present on the "start" and "atexit" events. ==== Event-Specific Key/Value Pairs @@ -600,6 +623,7 @@ from all events and the `time` field is only present on the "start" and { "event":"start", ... + "t_abs":0.001227, # elapsed time in seconds "argv":["git","version"] } ------------ @@ -887,7 +911,7 @@ visited. The `category` field may be used in a future enhancement to do category-based filtering. + -The `GIT_TR2_EVENT_NESTING` environment variable can be used to +`GIT_TR2_EVENT_NESTING` or `trace2.eventNesting` can be used to filter deeply nested regions and data events. It defaults to "2". `"region_leave"`:: @@ -1117,7 +1141,7 @@ $ git status $ cat ~/log.perf d0 | main | version | | | | | 2.20.1.160.g5676107ecd.dirty -d0 | main | start | | | | | git status +d0 | main | start | | 0.001173 | | | git status d0 | main | def_repo | r1 | | | | worktree:/Users/jeffhost/work/gfw d0 | main | cmd_name | | | | | status (status) ... @@ -1162,7 +1186,7 @@ $ git status ... $ cat ~/log.perf d0 | main | version | | | | | 2.20.1.162.gb4ccea44db.dirty -d0 | main | start | | | | | git status +d0 | main | start | | 0.001173 | | | git status d0 | main | def_repo | r1 | | | | worktree:/Users/jeffhost/work/gfw d0 | main | cmd_name | | | | | status (status) ... @@ -1218,7 +1242,7 @@ $ git status ... $ cat ~/log.perf d0 | main | version | | | | | 2.20.1.156.gf9916ae094.dirty -d0 | main | start | | | | | git status +d0 | main | start | | 0.001173 | | | git status d0 | main | def_repo | r1 | | | | worktree:/Users/jeffhost/work/gfw d0 | main | cmd_name | | | | | status (status) d0 | main | region_enter | r1 | 0.001791 | | index | label:do_read_index .git/index diff --git a/Documentation/trace2-target-values.txt b/Documentation/trace2-target-values.txt new file mode 100644 index 0000000000..27d3c64e66 --- /dev/null +++ b/Documentation/trace2-target-values.txt @@ -0,0 +1,10 @@ +-- +* `0` or `false` - Disables the target. +* `1` or `true` - Writes to `STDERR`. +* `[2-9]` - Writes to the already opened file descriptor. +* `<absolute-pathname>` - Writes to the file in append mode. +* `af_unix:[<socket_type>:]<absolute-pathname>` - Write to a +Unix DomainSocket (on platforms that support them). Socket +type can be either `stream` or `dgram`; if omitted Git will +try both. +-- @@ -999,6 +999,7 @@ LIB_OBJS += trace2/tr2_cfg.o LIB_OBJS += trace2/tr2_cmd_name.o LIB_OBJS += trace2/tr2_dst.o LIB_OBJS += trace2/tr2_sid.o +LIB_OBJS += trace2/tr2_sysenv.o LIB_OBJS += trace2/tr2_tbuf.o LIB_OBJS += trace2/tr2_tgt_event.o LIB_OBJS += trace2/tr2_tgt_normal.o diff --git a/common-main.c b/common-main.c index d484aec209..582a7b1886 100644 --- a/common-main.c +++ b/common-main.c @@ -27,6 +27,8 @@ int main(int argc, const char **argv) { int result; + trace2_initialize_clock(); + /* * Always open file descriptors 0/1/2 to avoid clobbering files * in die(). It also avoids messing up when the pipes are dup'ed @@ -35,11 +37,11 @@ int main(int argc, const char **argv) sanitize_stdfds(); restore_sigpipe_to_default(); + git_resolve_executable_dir(argv[0]); + trace2_initialize(); trace2_cmd_start(argv); - trace2_collect_process_info(); - - git_resolve_executable_dir(argv[0]); + trace2_collect_process_info(TRACE2_PROCESS_INFO_STARTUP); git_setup_gettext(); diff --git a/compat/mingw.c b/compat/mingw.c index 6b04514cdc..a2f74aca6a 100644 --- a/compat/mingw.c +++ b/compat/mingw.c @@ -2569,6 +2569,8 @@ void mingw_startup(void) wchar_t **wenv, **wargv; _startupinfo si; + trace2_initialize_clock(); + maybe_redirect_std_handles(); /* get wide char arguments and environment */ diff --git a/compat/win32/trace2_win32_process_info.c b/compat/win32/trace2_win32_process_info.c index 52bd62034b..8ccbd1c2c6 100644 --- a/compat/win32/trace2_win32_process_info.c +++ b/compat/win32/trace2_win32_process_info.c @@ -1,5 +1,6 @@ #include "../../cache.h" #include "../../json-writer.h" +#include "lazyload.h" #include <Psapi.h> #include <tlHelp32.h> @@ -137,11 +138,54 @@ static void get_is_being_debugged(void) "windows/debugger_present", 1); } -void trace2_collect_process_info(void) +/* + * Emit JSON data with the peak memory usage of the current process. + */ +static void get_peak_memory_info(void) +{ + DECLARE_PROC_ADDR(psapi.dll, BOOL, GetProcessMemoryInfo, HANDLE, + PPROCESS_MEMORY_COUNTERS, DWORD); + + if (INIT_PROC_ADDR(GetProcessMemoryInfo)) { + PROCESS_MEMORY_COUNTERS pmc; + + if (GetProcessMemoryInfo(GetCurrentProcess(), &pmc, + sizeof(pmc))) { + struct json_writer jw = JSON_WRITER_INIT; + + jw_object_begin(&jw, 0); + +#define KV(kv) #kv, (intmax_t)pmc.kv + + jw_object_intmax(&jw, KV(PageFaultCount)); + jw_object_intmax(&jw, KV(PeakWorkingSetSize)); + jw_object_intmax(&jw, KV(PeakPagefileUsage)); + + jw_end(&jw); + + trace2_data_json("process", the_repository, + "windows/memory", &jw); + jw_release(&jw); + } + } +} + +void trace2_collect_process_info(enum trace2_process_info_reason reason) { if (!trace2_is_enabled()) return; - get_is_being_debugged(); - get_ancestry(); + switch (reason) { + case TRACE2_PROCESS_INFO_STARTUP: + get_is_being_debugged(); + get_ancestry(); + return; + + case TRACE2_PROCESS_INFO_EXIT: + get_peak_memory_info(); + return; + + default: + BUG("trace2_collect_process_info: unknown reason '%d'", reason); + } } @@ -1676,7 +1676,9 @@ static int do_git_config_sequence(const struct config_options *opts, repo_config = NULL; current_parsing_scope = CONFIG_SCOPE_SYSTEM; - if (git_config_system() && !access_or_die(git_etc_gitconfig(), R_OK, 0)) + if (git_config_system() && !access_or_die(git_etc_gitconfig(), R_OK, + opts->system_gently ? + ACCESS_EACCES_OK : 0)) ret += git_config_from_file(fn, git_etc_gitconfig(), data); @@ -1688,14 +1690,15 @@ static int do_git_config_sequence(const struct config_options *opts, ret += git_config_from_file(fn, user_config, data); current_parsing_scope = CONFIG_SCOPE_REPO; - if (repo_config && !access_or_die(repo_config, R_OK, 0)) + if (!opts->ignore_repo && repo_config && + !access_or_die(repo_config, R_OK, 0)) ret += git_config_from_file(fn, repo_config, data); /* * Note: this should have a new scope, CONFIG_SCOPE_WORKTREE. * But let's not complicate things before it's actually needed. */ - if (repository_format_worktree_config) { + if (!opts->ignore_worktree && repository_format_worktree_config) { char *path = git_pathdup("config.worktree"); if (!access_or_die(path, R_OK, 0)) ret += git_config_from_file(fn, path, data); @@ -1703,7 +1706,7 @@ static int do_git_config_sequence(const struct config_options *opts, } current_parsing_scope = CONFIG_SCOPE_CMDLINE; - if (git_config_from_parameters(fn, data) < 0) + if (!opts->ignore_cmdline && git_config_from_parameters(fn, data) < 0) die(_("unable to parse command-line config")); current_parsing_scope = CONFIG_SCOPE_UNKNOWN; @@ -1794,6 +1797,23 @@ void read_early_config(config_fn_t cb, void *data) strbuf_release(&gitdir); } +/* + * Read config but only enumerate system and global settings. + * Omit any repo-local, worktree-local, or command-line settings. + */ +void read_very_early_config(config_fn_t cb, void *data) +{ + struct config_options opts = { 0 }; + + opts.respect_includes = 1; + opts.ignore_repo = 1; + opts.ignore_worktree = 1; + opts.ignore_cmdline = 1; + opts.system_gently = 1; + + config_with_options(cb, data, NULL, &opts); +} + static struct config_set_element *configset_find_element(struct config_set *cs, const char *key) { struct config_set_element k; @@ -2011,7 +2031,7 @@ int git_configset_get_pathname(struct config_set *cs, const char *key, const cha /* Functions use to read configuration from a repository */ static void repo_read_config(struct repository *repo) { - struct config_options opts; + struct config_options opts = { 0 }; opts.respect_includes = 1; opts.commondir = repo->commondir; @@ -55,6 +55,10 @@ typedef int (*config_parser_event_fn_t)(enum config_event_t type, struct config_options { unsigned int respect_includes : 1; + unsigned int ignore_repo : 1; + unsigned int ignore_worktree : 1; + unsigned int ignore_cmdline : 1; + unsigned int system_gently : 1; const char *commondir; const char *git_dir; config_parser_event_fn_t event_fn; @@ -83,6 +87,7 @@ extern int git_config_from_blob_oid(config_fn_t fn, const char *name, extern void git_config_push_parameter(const char *text); extern int git_config_from_parameters(config_fn_t fn, void *data); extern void read_early_config(config_fn_t cb, void *data); +extern void read_very_early_config(config_fn_t cb, void *data); extern void git_config(config_fn_t fn, void *); extern int config_with_options(config_fn_t fn, void *, struct git_config_source *config_source, diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh index 819430658b..71194a3623 100755 --- a/t/t0210-trace2-normal.sh +++ b/t/t0210-trace2-normal.sh @@ -3,6 +3,11 @@ test_description='test trace2 facility (normal target)' . ./test-lib.sh +# Turn off any inherited trace2 settings for this test. +sane_unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT +sane_unset GIT_TR2_BRIEF +sane_unset GIT_TR2_CONFIG_PARAMS + # Add t/helper directory to PATH so that we can use a relative # path to run nested instances of test-tool.exe (see 004child). # This helps with HEREDOC comparisons later. @@ -15,11 +20,6 @@ PATH="$TTDIR:$PATH" && export PATH # Warning: So you may see extra lines in artifact files when # Warning: interactively debugging. -# Turn off any inherited trace2 settings for this test. -unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT -unset GIT_TR2_BRIEF -unset GIT_TR2_CONFIG_PARAMS - V=$(git version | sed -e 's/^git version //') && export V # There are multiple trace2 targets: normal, perf, and event. @@ -147,4 +147,43 @@ test_expect_success 'normal stream, error event' ' test_cmp expect actual ' +sane_unset GIT_TR2_BRIEF + +# Now test without environment variables and get all Trace2 settings +# from the global config. + +test_expect_success 'using global config, normal stream, return code 0' ' + test_when_finished "rm trace.normal actual expect" && + test_config_global trace2.normalBrief 1 && + test_config_global trace2.normalTarget "$(pwd)/trace.normal" && + test-tool trace2 001return 0 && + perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual && + cat >expect <<-EOF && + version $V + start _EXE_ trace2 001return 0 + cmd_name trace2 (trace2) + exit elapsed:_TIME_ code:0 + atexit elapsed:_TIME_ code:0 + EOF + test_cmp expect actual +' + +test_expect_success 'using global config with include' ' + test_when_finished "rm trace.normal actual expect real.gitconfig" && + test_config_global trace2.normalBrief 1 && + test_config_global trace2.normalTarget "$(pwd)/trace.normal" && + mv "$(pwd)/.gitconfig" "$(pwd)/real.gitconfig" && + test_config_global include.path "$(pwd)/real.gitconfig" && + test-tool trace2 001return 0 && + perl "$TEST_DIRECTORY/t0210/scrub_normal.perl" <trace.normal >actual && + cat >expect <<-EOF && + version $V + start _EXE_ trace2 001return 0 + cmd_name trace2 (trace2) + exit elapsed:_TIME_ code:0 + atexit elapsed:_TIME_ code:0 + EOF + test_cmp expect actual +' + test_done diff --git a/t/t0211-trace2-perf.sh b/t/t0211-trace2-perf.sh index 953e2f7847..b501e867af 100755 --- a/t/t0211-trace2-perf.sh +++ b/t/t0211-trace2-perf.sh @@ -3,6 +3,11 @@ test_description='test trace2 facility (perf target)' . ./test-lib.sh +# Turn off any inherited trace2 settings for this test. +sane_unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT +sane_unset GIT_TR2_PERF_BRIEF +sane_unset GIT_TR2_CONFIG_PARAMS + # Add t/helper directory to PATH so that we can use a relative # path to run nested instances of test-tool.exe (see 004child). # This helps with HEREDOC comparisons later. @@ -15,11 +20,6 @@ PATH="$TTDIR:$PATH" && export PATH # Warning: So you may see extra lines in artifact files when # Warning: interactively debugging. -# Turn off any inherited trace2 settings for this test. -unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT -unset GIT_TR2_PERF_BRIEF -unset GIT_TR2_CONFIG_PARAMS - V=$(git version | sed -e 's/^git version //') && export V # There are multiple trace2 targets: normal, perf, and event. @@ -50,7 +50,7 @@ test_expect_success 'perf stream, return code 0' ' perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && cat >expect <<-EOF && d0|main|version|||||$V - d0|main|start|||||_EXE_ trace2 001return 0 + d0|main|start||_T_ABS_|||_EXE_ trace2 001return 0 d0|main|cmd_name|||||trace2 (trace2) d0|main|exit||_T_ABS_|||code:0 d0|main|atexit||_T_ABS_|||code:0 @@ -64,7 +64,7 @@ test_expect_success 'perf stream, return code 1' ' perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && cat >expect <<-EOF && d0|main|version|||||$V - d0|main|start|||||_EXE_ trace2 001return 1 + d0|main|start||_T_ABS_|||_EXE_ trace2 001return 1 d0|main|cmd_name|||||trace2 (trace2) d0|main|exit||_T_ABS_|||code:1 d0|main|atexit||_T_ABS_|||code:1 @@ -82,7 +82,7 @@ test_expect_success 'perf stream, error event' ' perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && cat >expect <<-EOF && d0|main|version|||||$V - d0|main|start|||||_EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\'' + d0|main|start||_T_ABS_|||_EXE_ trace2 003error '\''hello world'\'' '\''this is a test'\'' d0|main|cmd_name|||||trace2 (trace2) d0|main|error|||||hello world d0|main|error|||||this is a test @@ -128,15 +128,15 @@ test_expect_success 'perf stream, child processes' ' perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && cat >expect <<-EOF && d0|main|version|||||$V - d0|main|start|||||_EXE_ trace2 004child test-tool trace2 004child test-tool trace2 001return 0 + d0|main|start||_T_ABS_|||_EXE_ trace2 004child test-tool trace2 004child test-tool trace2 001return 0 d0|main|cmd_name|||||trace2 (trace2) d0|main|child_start||_T_ABS_|||[ch0] class:? argv: test-tool trace2 004child test-tool trace2 001return 0 d1|main|version|||||$V - d1|main|start|||||_EXE_ trace2 004child test-tool trace2 001return 0 + d1|main|start||_T_ABS_|||_EXE_ trace2 004child test-tool trace2 001return 0 d1|main|cmd_name|||||trace2 (trace2/trace2) d1|main|child_start||_T_ABS_|||[ch0] class:? argv: test-tool trace2 001return 0 d2|main|version|||||$V - d2|main|start|||||_EXE_ trace2 001return 0 + d2|main|start||_T_ABS_|||_EXE_ trace2 001return 0 d2|main|cmd_name|||||trace2 (trace2/trace2/trace2) d2|main|exit||_T_ABS_|||code:0 d2|main|atexit||_T_ABS_|||code:0 @@ -150,4 +150,25 @@ test_expect_success 'perf stream, child processes' ' test_cmp expect actual ' +sane_unset GIT_TR2_PERF_BRIEF + +# Now test without environment variables and get all Trace2 settings +# from the global config. + +test_expect_success 'using global config, perf stream, return code 0' ' + test_when_finished "rm trace.perf actual expect" && + test_config_global trace2.perfBrief 1 && + test_config_global trace2.perfTarget "$(pwd)/trace.perf" && + test-tool trace2 001return 0 && + perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual && + cat >expect <<-EOF && + d0|main|version|||||$V + d0|main|start||_T_ABS_|||_EXE_ trace2 001return 0 + d0|main|cmd_name|||||trace2 (trace2) + d0|main|exit||_T_ABS_|||code:0 + d0|main|atexit||_T_ABS_|||code:0 + EOF + test_cmp expect actual +' + test_done diff --git a/t/t0212-trace2-event.sh b/t/t0212-trace2-event.sh index 028b6c5671..59adae8123 100755 --- a/t/t0212-trace2-event.sh +++ b/t/t0212-trace2-event.sh @@ -3,6 +3,11 @@ test_description='test trace2 facility' . ./test-lib.sh +# Turn off any inherited trace2 settings for this test. +sane_unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT +sane_unset GIT_TR2_BARE +sane_unset GIT_TR2_CONFIG_PARAMS + perl -MJSON::PP -e 0 >/dev/null 2>&1 && test_set_prereq JSON_PP # Add t/helper directory to PATH so that we can use a relative @@ -17,11 +22,6 @@ PATH="$TTDIR:$PATH" && export PATH # Warning: So you may see extra lines in artifact files when # Warning: interactively debugging. -# Turn off any inherited trace2 settings for this test. -unset GIT_TR2 GIT_TR2_PERF GIT_TR2_EVENT -unset GIT_TR2_BARE -unset GIT_TR2_CONFIG_PARAMS - V=$(git version | sed -e 's/^git version //') && export V # There are multiple trace2 targets: normal, perf, and event. @@ -233,4 +233,36 @@ test_expect_success JSON_PP 'basic trace2_data' ' test_cmp expect actual ' +# Now test without environment variables and get all Trace2 settings +# from the global config. + +test_expect_success JSON_PP 'using global config, event stream, error event' ' + test_when_finished "rm trace.event actual expect" && + test_config_global trace2.eventTarget "$(pwd)/trace.event" && + test-tool trace2 003error "hello world" "this is a test" && + perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual && + sed -e "s/^|//" >expect <<-EOF && + |VAR1 = { + | "_SID0_":{ + | "argv":[ + | "_EXE_", + | "trace2", + | "003error", + | "hello world", + | "this is a test" + | ], + | "errors":[ + | "%s", + | "%s" + | ], + | "exit_code":0, + | "hierarchy":"trace2", + | "name":"trace2", + | "version":"$V" + | } + |}; + EOF + test_cmp expect actual +' + test_done @@ -10,6 +10,7 @@ #include "trace2/tr2_cmd_name.h" #include "trace2/tr2_dst.h" #include "trace2/tr2_sid.h" +#include "trace2/tr2_sysenv.h" #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" @@ -120,6 +121,7 @@ static void tr2main_atexit_handler(void) tr2_sid_release(); tr2_cmd_name_release(); tr2_cfg_free_patterns(); + tr2_sysenv_release(); trace2_enabled = 0; } @@ -142,6 +144,11 @@ static void tr2main_signal_handler(int signo) raise(signo); } +void trace2_initialize_clock(void) +{ + tr2tls_start_process_clock(); +} + void trace2_initialize_fl(const char *file, int line) { struct tr2_tgt *tgt_j; @@ -150,6 +157,8 @@ void trace2_initialize_fl(const char *file, int line) if (trace2_enabled) return; + tr2_sysenv_load(); + if (!tr2_tgt_want_builtins()) return; trace2_enabled = 1; @@ -177,13 +186,19 @@ void trace2_cmd_start_fl(const char *file, int line, const char **argv) { struct tr2_tgt *tgt_j; int j; + uint64_t us_now; + uint64_t us_elapsed_absolute; if (!trace2_enabled) return; + us_now = getnanotime() / 1000; + us_elapsed_absolute = tr2tls_absolute_elapsed(us_now); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_start_fl) - tgt_j->pfn_start_fl(file, line, argv); + tgt_j->pfn_start_fl(file, line, us_elapsed_absolute, + argv); } int trace2_cmd_exit_fl(const char *file, int line, int code) @@ -198,6 +213,8 @@ int trace2_cmd_exit_fl(const char *file, int line, int code) if (!trace2_enabled) return code; + trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT); + tr2main_exit_code = code; us_now = getnanotime() / 1000; @@ -428,7 +445,7 @@ void trace2_thread_start_fl(const char *file, int line, const char *thread_name) us_now = getnanotime() / 1000; us_elapsed_absolute = tr2tls_absolute_elapsed(us_now); - tr2tls_create_self(thread_name); + tr2tls_create_self(thread_name, us_now); for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_thread_start_fl) @@ -20,8 +20,26 @@ struct json_writer; */ /* + * Initialize the TRACE2 clock and do nothing else, in particular + * no mallocs, no system inspection, and no environment inspection. + * + * This should be called at the very top of main() to capture the + * process start time. This is intended to reduce chicken-n-egg + * bootstrap pressure. + * + * It is safe to call this more than once. This allows capturing + * absolute startup costs on Windows which uses a little trickery + * to do setup work before common-main.c:main() is called. + * + * The main trace2_initialize_fl() may be called a little later + * after more infrastructure is established. + */ +void trace2_initialize_clock(void); + +/* * Initialize TRACE2 tracing facility if any of the builtin TRACE2 - * targets are enabled in the environment. Emits a 'version' event. + * targets are enabled in the system config or the environment. + * Emits a 'version' event. * * Cleanup/Termination is handled automatically by a registered * atexit() routine. @@ -108,10 +126,11 @@ void trace2_cmd_alias_fl(const char *file, int line, const char *alias, * Emit one or more 'def_param' events for "interesting" configuration * settings. * - * The environment variable "GIT_TR2_CONFIG_PARAMS" can be set to a - * list of patterns considered important. For example: - * - * GIT_TR2_CONFIG_PARAMS="core.*,remote.*.url" + * Use the TR2_SYSENV_CFG_PARAM setting to register a comma-separated + * list of patterns configured important. For example: + * git config --system trace2.configParams 'core.*,remote.*.url' + * or: + * GIT_TR2_CONFIG_PARAMS=core.*,remote.*.url" * * Note: this routine does a read-only iteration on the config data * (using read_early_config()), so it must not be called until enough @@ -372,13 +391,19 @@ void trace2_printf(const char *fmt, ...); * Optional platform-specific code to dump information about the * current and any parent process(es). This is intended to allow * post-processors to know who spawned this git instance and anything - * else the platform may be able to tell us about the current process. + * else that the platform may be able to tell us about the current process. */ + +enum trace2_process_info_reason { + TRACE2_PROCESS_INFO_STARTUP, + TRACE2_PROCESS_INFO_EXIT, +}; + #if defined(GIT_WINDOWS_NATIVE) -void trace2_collect_process_info(void); +void trace2_collect_process_info(enum trace2_process_info_reason reason); #else -#define trace2_collect_process_info() \ - do { \ +#define trace2_collect_process_info(reason) \ + do { \ } while (0) #endif diff --git a/trace2/tr2_cfg.c b/trace2/tr2_cfg.c index b329921ac5..caa7f06948 100644 --- a/trace2/tr2_cfg.c +++ b/trace2/tr2_cfg.c @@ -1,8 +1,7 @@ #include "cache.h" #include "config.h" -#include "tr2_cfg.h" - -#define TR2_ENVVAR_CFG_PARAM "GIT_TR2_CONFIG_PARAMS" +#include "trace2/tr2_cfg.h" +#include "trace2/tr2_sysenv.h" static struct strbuf **tr2_cfg_patterns; static int tr2_cfg_count_patterns; @@ -21,7 +20,7 @@ static int tr2_cfg_load_patterns(void) return tr2_cfg_count_patterns; tr2_cfg_loaded = 1; - envvar = getenv(TR2_ENVVAR_CFG_PARAM); + envvar = tr2_sysenv_get(TR2_SYSENV_CFG_PARAM); if (!envvar || !*envvar) return tr2_cfg_count_patterns; diff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c index c3d82ca6a4..5dda0ca1cd 100644 --- a/trace2/tr2_dst.c +++ b/trace2/tr2_dst.c @@ -1,17 +1,7 @@ #include "cache.h" #include "trace2/tr2_dst.h" #include "trace2/tr2_sid.h" - -/* - * If a Trace2 target cannot be opened for writing, we should issue a - * warning to stderr, but this is very annoying if the target is a pipe - * or socket and beyond the user's control -- especially since every - * git command (and sub-command) will print the message. So we silently - * eat these warnings and just discard the trace data. - * - * Enable the following environment variable to see these warnings. - */ -#define TR2_ENVVAR_DST_DEBUG "GIT_TR2_DST_DEBUG" +#include "trace2/tr2_sysenv.h" /* * How many attempts we will make at creating an automatically-named trace file. @@ -23,7 +13,7 @@ static int tr2_dst_want_warning(void) static int tr2env_dst_debug = -1; if (tr2env_dst_debug == -1) { - const char *env_value = getenv(TR2_ENVVAR_DST_DEBUG); + const char *env_value = tr2_sysenv_get(TR2_SYSENV_DST_DEBUG); if (!env_value || !*env_value) tr2env_dst_debug = 0; else @@ -75,7 +65,8 @@ static int tr2_dst_try_auto_path(struct tr2_dst *dst, const char *tgt_prefix) if (tr2_dst_want_warning()) warning("trace2: could not open '%.*s' for '%s' tracing: %s", (int) base_path_len, path.buf, - dst->env_var_name, strerror(errno)); + tr2_sysenv_display_name(dst->sysenv_var), + strerror(errno)); tr2_dst_trace_disable(dst); strbuf_release(&path); @@ -97,7 +88,9 @@ static int tr2_dst_try_path(struct tr2_dst *dst, const char *tgt_value) if (fd == -1) { if (tr2_dst_want_warning()) warning("trace2: could not open '%s' for '%s' tracing: %s", - tgt_value, dst->env_var_name, strerror(errno)); + tgt_value, + tr2_sysenv_display_name(dst->sysenv_var), + strerror(errno)); tr2_dst_trace_disable(dst); return 0; @@ -171,7 +164,8 @@ static int tr2_dst_try_unix_domain_socket(struct tr2_dst *dst, if (!path || !*path) { if (tr2_dst_want_warning()) warning("trace2: invalid AF_UNIX value '%s' for '%s' tracing", - tgt_value, dst->env_var_name); + tgt_value, + tr2_sysenv_display_name(dst->sysenv_var)); tr2_dst_trace_disable(dst); return 0; @@ -181,7 +175,7 @@ static int tr2_dst_try_unix_domain_socket(struct tr2_dst *dst, strlen(path) >= sizeof(((struct sockaddr_un *)0)->sun_path)) { if (tr2_dst_want_warning()) warning("trace2: invalid AF_UNIX path '%s' for '%s' tracing", - path, dst->env_var_name); + path, tr2_sysenv_display_name(dst->sysenv_var)); tr2_dst_trace_disable(dst); return 0; @@ -203,7 +197,8 @@ static int tr2_dst_try_unix_domain_socket(struct tr2_dst *dst, error: if (tr2_dst_want_warning()) warning("trace2: could not connect to socket '%s' for '%s' tracing: %s", - path, dst->env_var_name, strerror(e)); + path, tr2_sysenv_display_name(dst->sysenv_var), + strerror(e)); tr2_dst_trace_disable(dst); return 0; @@ -223,7 +218,7 @@ static void tr2_dst_malformed_warning(struct tr2_dst *dst, struct strbuf buf = STRBUF_INIT; strbuf_addf(&buf, "trace2: unknown value for '%s': '%s'", - dst->env_var_name, tgt_value); + tr2_sysenv_display_name(dst->sysenv_var), tgt_value); warning("%s", buf.buf); strbuf_release(&buf); @@ -239,7 +234,7 @@ int tr2_dst_get_trace_fd(struct tr2_dst *dst) dst->initialized = 1; - tgt_value = getenv(dst->env_var_name); + tgt_value = tr2_sysenv_get(dst->sysenv_var); if (!tgt_value || !strcmp(tgt_value, "") || !strcmp(tgt_value, "0") || !strcasecmp(tgt_value, "false")) { @@ -305,7 +300,8 @@ void tr2_dst_write_line(struct tr2_dst *dst, struct strbuf *buf_line) return; if (tr2_dst_want_warning()) - warning("unable to write trace to '%s': %s", dst->env_var_name, + warning("unable to write trace to '%s': %s", + tr2_sysenv_display_name(dst->sysenv_var), strerror(errno)); tr2_dst_trace_disable(dst); } diff --git a/trace2/tr2_dst.h b/trace2/tr2_dst.h index 9a64f05b02..3adf3bac13 100644 --- a/trace2/tr2_dst.h +++ b/trace2/tr2_dst.h @@ -2,9 +2,10 @@ #define TR2_DST_H struct strbuf; +#include "trace2/tr2_sysenv.h" struct tr2_dst { - const char *const env_var_name; + enum tr2_sysenv_variable sysenv_var; int fd; unsigned int initialized : 1; unsigned int need_close : 1; diff --git a/trace2/tr2_sid.c b/trace2/tr2_sid.c index 984524a43c..5047095478 100644 --- a/trace2/tr2_sid.c +++ b/trace2/tr2_sid.c @@ -1,4 +1,5 @@ #include "cache.h" +#include "trace2/tr2_tbuf.h" #include "trace2/tr2_sid.h" #define TR2_ENVVAR_PARENT_SID "GIT_TR2_PARENT_SID" @@ -7,6 +8,53 @@ static struct strbuf tr2sid_buf = STRBUF_INIT; static int tr2sid_nr_git_parents; /* + * Compute the final component of the SID representing the current process. + * This should uniquely identify the process and be a valid filename (to + * allow writing trace2 data to per-process files). It should also be fixed + * length for possible use as a database key. + * + * "<yyyymmdd>T<hhmmss>.<fraction>Z-<host>-<process>" + * + * where <host> is a 9 character string: + * "H<first_8_chars_of_sha1_of_hostname>" + * "Localhost" when no hostname. + * + * where <process> is a 9 character string containing the least signifcant + * 32 bits in the process-id. + * "P<pid>" + * (This is an abribrary choice. On most systems pid_t is a 32 bit value, + * so limit doesn't matter. On larger systems, a truncated value is fine + * for our purposes here.) + */ +static void tr2_sid_append_my_sid_component(void) +{ + const struct git_hash_algo *algo = &hash_algos[GIT_HASH_SHA1]; + struct tr2_tbuf tb_now; + git_hash_ctx ctx; + pid_t pid = getpid(); + unsigned char hash[GIT_MAX_RAWSZ + 1]; + char hex[GIT_MAX_HEXSZ + 1]; + char hostname[HOST_NAME_MAX + 1]; + + tr2_tbuf_utc_datetime(&tb_now); + strbuf_addstr(&tr2sid_buf, tb_now.buf); + + strbuf_addch(&tr2sid_buf, '-'); + if (xgethostname(hostname, sizeof(hostname))) + strbuf_add(&tr2sid_buf, "Localhost", 9); + else { + algo->init_fn(&ctx); + algo->update_fn(&ctx, hostname, strlen(hostname)); + algo->final_fn(hash, &ctx); + hash_to_hex_algop_r(hex, hash, algo); + strbuf_addch(&tr2sid_buf, 'H'); + strbuf_add(&tr2sid_buf, hex, 8); + } + + strbuf_addf(&tr2sid_buf, "-P%08"PRIx32, (uint32_t)pid); +} + +/* * Compute a "unique" session id (SID) for the current process. This allows * all events from this process to have a single label (much like a PID). * @@ -20,7 +68,6 @@ static int tr2sid_nr_git_parents; */ static void tr2_sid_compute(void) { - uint64_t us_now; const char *parent_sid; if (tr2sid_buf.len) @@ -38,9 +85,7 @@ static void tr2_sid_compute(void) tr2sid_nr_git_parents++; } - us_now = getnanotime() / 1000; - strbuf_addf(&tr2sid_buf, "%" PRIuMAX "-%" PRIdMAX, (uintmax_t)us_now, - (intmax_t)getpid()); + tr2_sid_append_my_sid_component(); setenv(TR2_ENVVAR_PARENT_SID, tr2sid_buf.buf, 1); } diff --git a/trace2/tr2_sysenv.c b/trace2/tr2_sysenv.c new file mode 100644 index 0000000000..9025b86303 --- /dev/null +++ b/trace2/tr2_sysenv.c @@ -0,0 +1,127 @@ +#include "cache.h" +#include "config.h" +#include "dir.h" +#include "tr2_sysenv.h" + +/* + * Each entry represents a trace2 setting. + * See Documentation/technical/api-trace2.txt + */ +struct tr2_sysenv_entry { + const char *env_var_name; + const char *git_config_name; + + char *value; + unsigned int getenv_called : 1; +}; + +/* + * This table must match "enum tr2_sysenv_variable" in tr2_sysenv.h. + * + * The strings in this table are constant and must match the published + * config and environment variable names as described in the documentation. + * + * We do not define entries for the GIT_TR2_PARENT_* environment + * variables because they are transient and used to pass information + * from parent to child git processes, rather than settings. + */ +/* clang-format off */ +static struct tr2_sysenv_entry tr2_sysenv_settings[] = { + [TR2_SYSENV_CFG_PARAM] = { "GIT_TR2_CONFIG_PARAMS", + "trace2.configparams" }, + + [TR2_SYSENV_DST_DEBUG] = { "GIT_TR2_DST_DEBUG", + "trace2.destinationdebug" }, + + [TR2_SYSENV_NORMAL] = { "GIT_TR2", + "trace2.normaltarget" }, + [TR2_SYSENV_NORMAL_BRIEF] = { "GIT_TR2_BRIEF", + "trace2.normalbrief" }, + + [TR2_SYSENV_EVENT] = { "GIT_TR2_EVENT", + "trace2.eventtarget" }, + [TR2_SYSENV_EVENT_BRIEF] = { "GIT_TR2_EVENT_BRIEF", + "trace2.eventbrief" }, + [TR2_SYSENV_EVENT_NESTING] = { "GIT_TR2_EVENT_NESTING", + "trace2.eventnesting" }, + + [TR2_SYSENV_PERF] = { "GIT_TR2_PERF", + "trace2.perftarget" }, + [TR2_SYSENV_PERF_BRIEF] = { "GIT_TR2_PERF_BRIEF", + "trace2.perfbrief" }, +}; +/* clang-format on */ + +static int tr2_sysenv_cb(const char *key, const char *value, void *d) +{ + int k; + + if (!starts_with(key, "trace2.")) + return 0; + + for (k = 0; k < ARRAY_SIZE(tr2_sysenv_settings); k++) { + if (!strcmp(key, tr2_sysenv_settings[k].git_config_name)) { + free(tr2_sysenv_settings[k].value); + tr2_sysenv_settings[k].value = xstrdup(value); + return 0; + } + } + + return 0; +} + +/* + * Load Trace2 settings from the system config (usually "/etc/gitconfig" + * unless we were built with a runtime-prefix). These are intended to + * define the default values for Trace2 as requested by the administrator. + * + * Then override with the Trace2 settings from the global config. + */ +void tr2_sysenv_load(void) +{ + if (ARRAY_SIZE(tr2_sysenv_settings) != TR2_SYSENV_MUST_BE_LAST) + BUG("tr2_sysenv_settings size is wrong"); + + read_very_early_config(tr2_sysenv_cb, NULL); +} + +/* + * Return the value for the requested Trace2 setting from these sources: + * the system config, the global config, and the environment. + */ +const char *tr2_sysenv_get(enum tr2_sysenv_variable var) +{ + if (var >= TR2_SYSENV_MUST_BE_LAST) + BUG("tr2_sysenv_get invalid var '%d'", var); + + if (!tr2_sysenv_settings[var].getenv_called) { + const char *v = getenv(tr2_sysenv_settings[var].env_var_name); + if (v && *v) { + free(tr2_sysenv_settings[var].value); + tr2_sysenv_settings[var].value = xstrdup(v); + } + tr2_sysenv_settings[var].getenv_called = 1; + } + + return tr2_sysenv_settings[var].value; +} + +/* + * Return a friendly name for this setting that is suitable for printing + * in an error messages. + */ +const char *tr2_sysenv_display_name(enum tr2_sysenv_variable var) +{ + if (var >= TR2_SYSENV_MUST_BE_LAST) + BUG("tr2_sysenv_get invalid var '%d'", var); + + return tr2_sysenv_settings[var].env_var_name; +} + +void tr2_sysenv_release(void) +{ + int k; + + for (k = 0; k < ARRAY_SIZE(tr2_sysenv_settings); k++) + free(tr2_sysenv_settings[k].value); +} diff --git a/trace2/tr2_sysenv.h b/trace2/tr2_sysenv.h new file mode 100644 index 0000000000..369b20bd87 --- /dev/null +++ b/trace2/tr2_sysenv.h @@ -0,0 +1,36 @@ +#ifndef TR2_SYSENV_H +#define TR2_SYSENV_H + +/* + * The Trace2 settings that can be loaded from /etc/gitconfig + * and/or user environment variables. + * + * Note that this set does not contain any of the transient + * environment variables used to pass information from parent + * to child git processes, such "GIT_TR2_PARENT_SID". + */ +enum tr2_sysenv_variable { + TR2_SYSENV_CFG_PARAM = 0, + + TR2_SYSENV_DST_DEBUG, + + TR2_SYSENV_NORMAL, + TR2_SYSENV_NORMAL_BRIEF, + + TR2_SYSENV_EVENT, + TR2_SYSENV_EVENT_BRIEF, + TR2_SYSENV_EVENT_NESTING, + + TR2_SYSENV_PERF, + TR2_SYSENV_PERF_BRIEF, + + TR2_SYSENV_MUST_BE_LAST +}; + +void tr2_sysenv_load(void); + +const char *tr2_sysenv_get(enum tr2_sysenv_variable); +const char *tr2_sysenv_display_name(enum tr2_sysenv_variable var); +void tr2_sysenv_release(void); + +#endif /* TR2_SYSENV_H */ diff --git a/trace2/tr2_tbuf.c b/trace2/tr2_tbuf.c index 0844910423..2498482d9a 100644 --- a/trace2/tr2_tbuf.c +++ b/trace2/tr2_tbuf.c @@ -15,7 +15,7 @@ void tr2_tbuf_local_time(struct tr2_tbuf *tb) tm.tm_min, tm.tm_sec, (long)tv.tv_usec); } -void tr2_tbuf_utc_time(struct tr2_tbuf *tb) +void tr2_tbuf_utc_datetime_extended(struct tr2_tbuf *tb) { struct timeval tv; struct tm tm; @@ -26,7 +26,22 @@ void tr2_tbuf_utc_time(struct tr2_tbuf *tb) gmtime_r(&secs, &tm); xsnprintf(tb->buf, sizeof(tb->buf), - "%4d-%02d-%02d %02d:%02d:%02d.%06ld", tm.tm_year + 1900, + "%4d-%02d-%02dT%02d:%02d:%02d.%06ldZ", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec, (long)tv.tv_usec); } + +void tr2_tbuf_utc_datetime(struct tr2_tbuf *tb) +{ + struct timeval tv; + struct tm tm; + time_t secs; + + gettimeofday(&tv, NULL); + secs = tv.tv_sec; + gmtime_r(&secs, &tm); + + xsnprintf(tb->buf, sizeof(tb->buf), "%4d%02d%02dT%02d%02d%02d.%06ldZ", + tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, + tm.tm_min, tm.tm_sec, (long)tv.tv_usec); +} diff --git a/trace2/tr2_tbuf.h b/trace2/tr2_tbuf.h index 9cdefa3957..fa853d8f42 100644 --- a/trace2/tr2_tbuf.h +++ b/trace2/tr2_tbuf.h @@ -16,8 +16,9 @@ struct tr2_tbuf { void tr2_tbuf_local_time(struct tr2_tbuf *tb); /* - * Fill buffer with formatted UTC time string. + * Fill buffer with formatted UTC datatime string. */ -void tr2_tbuf_utc_time(struct tr2_tbuf *tb); +void tr2_tbuf_utc_datetime_extended(struct tr2_tbuf *tb); +void tr2_tbuf_utc_datetime(struct tr2_tbuf *tb); #endif /* TR2_TBUF_H */ diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h index 297bb8ffbe..7b90469212 100644 --- a/trace2/tr2_tgt.h +++ b/trace2/tr2_tgt.h @@ -15,6 +15,7 @@ typedef void(tr2_tgt_term_t)(void); typedef void(tr2_tgt_evt_version_fl_t)(const char *file, int line); typedef void(tr2_tgt_evt_start_fl_t)(const char *file, int line, + uint64_t us_elapsed_absolute, const char **argv); typedef void(tr2_tgt_evt_exit_fl_t)(const char *file, int line, uint64_t us_elapsed_absolute, int code); diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c index 1cf4f62441..c2852d1bd2 100644 --- a/trace2/tr2_tgt_event.c +++ b/trace2/tr2_tgt_event.c @@ -6,10 +6,11 @@ #include "trace2/tr2_dst.h" #include "trace2/tr2_tbuf.h" #include "trace2/tr2_sid.h" +#include "trace2/tr2_sysenv.h" #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" -static struct tr2_dst tr2dst_event = { "GIT_TR2_EVENT", 0, 0, 0 }; +static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0 }; /* * The version number of the JSON data generated by the EVENT target @@ -28,37 +29,36 @@ static struct tr2_dst tr2dst_event = { "GIT_TR2_EVENT", 0, 0, 0 }; * are primarily intended for the performance target during debugging. * * Some of the outer-most messages, however, may be of interest to the - * event target. Set this environment variable to a larger integer for - * more detail in the event target. + * event target. Use the TR2_SYSENV_EVENT_NESTING setting to increase + * region details in the event target. */ -#define TR2_ENVVAR_EVENT_NESTING "GIT_TR2_EVENT_NESTING" -static int tr2env_event_nesting_wanted = 2; +static int tr2env_event_max_nesting_levels = 2; /* - * Set this environment variable to true to omit the <time>, <file>, and + * Use the TR2_SYSENV_EVENT_BRIEF to omit the <time>, <file>, and * <line> fields from most events. */ -#define TR2_ENVVAR_EVENT_BRIEF "GIT_TR2_EVENT_BRIEF" -static int tr2env_event_brief; +static int tr2env_event_be_brief; static int fn_init(void) { int want = tr2_dst_trace_want(&tr2dst_event); - int want_nesting; + int max_nesting; int want_brief; - char *nesting; - char *brief; + const char *nesting; + const char *brief; if (!want) return want; - nesting = getenv(TR2_ENVVAR_EVENT_NESTING); - if (nesting && ((want_nesting = atoi(nesting)) > 0)) - tr2env_event_nesting_wanted = want_nesting; + nesting = tr2_sysenv_get(TR2_SYSENV_EVENT_NESTING); + if (nesting && *nesting && ((max_nesting = atoi(nesting)) > 0)) + tr2env_event_max_nesting_levels = max_nesting; - brief = getenv(TR2_ENVVAR_EVENT_BRIEF); - if (brief && ((want_brief = atoi(brief)) > 0)) - tr2env_event_brief = want_brief; + brief = tr2_sysenv_get(TR2_SYSENV_EVENT_BRIEF); + if (brief && *brief && + ((want_brief = git_parse_maybe_bool(brief)) != -1)) + tr2env_event_be_brief = want_brief; return want; } @@ -92,13 +92,13 @@ static void event_fmt_prepare(const char *event_name, const char *file, /* * In brief mode, only emit <time> on these 2 event types. */ - if (!tr2env_event_brief || !strcmp(event_name, "version") || + if (!tr2env_event_be_brief || !strcmp(event_name, "version") || !strcmp(event_name, "atexit")) { - tr2_tbuf_utc_time(&tb_now); + tr2_tbuf_utc_datetime_extended(&tb_now); jw_object_string(jw, "time", tb_now.buf); } - if (!tr2env_event_brief && file && *file) { + if (!tr2env_event_be_brief && file && *file) { jw_object_string(jw, "file", file); jw_object_intmax(jw, "line", line); } @@ -122,13 +122,16 @@ static void fn_version_fl(const char *file, int line) jw_release(&jw); } -static void fn_start_fl(const char *file, int line, const char **argv) +static void fn_start_fl(const char *file, int line, + uint64_t us_elapsed_absolute, const char **argv) { const char *event_name = "start"; 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); jw_object_inline_begin_array(&jw, "argv"); jw_array_argv(&jw, argv); jw_end(&jw); @@ -456,7 +459,7 @@ static void fn_region_enter_printf_va_fl(const char *file, int line, { const char *event_name = "region_enter"; struct tr2tls_thread_ctx *ctx = tr2tls_get_self(); - if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) { + if (ctx->nr_open_regions <= tr2env_event_max_nesting_levels) { struct json_writer jw = JSON_WRITER_INIT; jw_object_begin(&jw, 0); @@ -481,7 +484,7 @@ static void fn_region_leave_printf_va_fl( { const char *event_name = "region_leave"; struct tr2tls_thread_ctx *ctx = tr2tls_get_self(); - if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) { + if (ctx->nr_open_regions <= tr2env_event_max_nesting_levels) { struct json_writer jw = JSON_WRITER_INIT; double t_rel = (double)us_elapsed_region / 1000000.0; @@ -508,7 +511,7 @@ static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute, { const char *event_name = "data"; struct tr2tls_thread_ctx *ctx = tr2tls_get_self(); - if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) { + if (ctx->nr_open_regions <= tr2env_event_max_nesting_levels) { struct json_writer jw = JSON_WRITER_INIT; double t_abs = (double)us_elapsed_absolute / 1000000.0; double t_rel = (double)us_elapsed_region / 1000000.0; @@ -536,7 +539,7 @@ static void fn_data_json_fl(const char *file, int line, { const char *event_name = "data_json"; struct tr2tls_thread_ctx *ctx = tr2tls_get_self(); - if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) { + if (ctx->nr_open_regions <= tr2env_event_max_nesting_levels) { struct json_writer jw = JSON_WRITER_INIT; double t_abs = (double)us_elapsed_absolute / 1000000.0; double t_rel = (double)us_elapsed_region / 1000000.0; diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c index 1a07d70abd..00b116d797 100644 --- a/trace2/tr2_tgt_normal.c +++ b/trace2/tr2_tgt_normal.c @@ -4,20 +4,20 @@ #include "quote.h" #include "version.h" #include "trace2/tr2_dst.h" +#include "trace2/tr2_sysenv.h" #include "trace2/tr2_tbuf.h" #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" -static struct tr2_dst tr2dst_normal = { "GIT_TR2", 0, 0, 0 }; +static struct tr2_dst tr2dst_normal = { TR2_SYSENV_NORMAL, 0, 0, 0 }; /* - * Set this environment variable to true to omit the "<time> <file>:<line>" + * Use the TR2_SYSENV_NORMAL_BRIEF setting to omit the "<time> <file>:<line>" * fields from each line written to the builtin normal target. * * Unit tests may want to use this to help with testing. */ -#define TR2_ENVVAR_NORMAL_BRIEF "GIT_TR2_BRIEF" -static int tr2env_normal_brief; +static int tr2env_normal_be_brief; #define TR2FMT_NORMAL_FL_WIDTH (50) @@ -25,15 +25,15 @@ static int fn_init(void) { int want = tr2_dst_trace_want(&tr2dst_normal); int want_brief; - char *brief; + const char *brief; if (!want) return want; - brief = getenv(TR2_ENVVAR_NORMAL_BRIEF); + brief = tr2_sysenv_get(TR2_SYSENV_NORMAL_BRIEF); if (brief && *brief && ((want_brief = git_parse_maybe_bool(brief)) != -1)) - tr2env_normal_brief = want_brief; + tr2env_normal_be_brief = want_brief; return want; } @@ -47,7 +47,7 @@ static void normal_fmt_prepare(const char *file, int line, struct strbuf *buf) { strbuf_setlen(buf, 0); - if (!tr2env_normal_brief) { + if (!tr2env_normal_be_brief) { struct tr2_tbuf tb_now; tr2_tbuf_local_time(&tb_now); @@ -81,7 +81,8 @@ static void fn_version_fl(const char *file, int line) strbuf_release(&buf_payload); } -static void fn_start_fl(const char *file, int line, const char **argv) +static void fn_start_fl(const char *file, int line, + uint64_t us_elapsed_absolute, const char **argv) { struct strbuf buf_payload = STRBUF_INIT; diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c index 2a866d701b..ea0cbbe13e 100644 --- a/trace2/tr2_tgt_perf.c +++ b/trace2/tr2_tgt_perf.c @@ -6,20 +6,20 @@ #include "json-writer.h" #include "trace2/tr2_dst.h" #include "trace2/tr2_sid.h" +#include "trace2/tr2_sysenv.h" #include "trace2/tr2_tbuf.h" #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" -static struct tr2_dst tr2dst_perf = { "GIT_TR2_PERF", 0, 0, 0 }; +static struct tr2_dst tr2dst_perf = { TR2_SYSENV_PERF, 0, 0, 0 }; /* - * Set this environment variable to true to omit the "<time> <file>:<line>" + * Use TR2_SYSENV_PERF_BRIEF to omit the "<time> <file>:<line>" * fields from each line written to the builtin performance target. * * Unit tests may want to use this to help with testing. */ -#define TR2_ENVVAR_PERF_BRIEF "GIT_TR2_PERF_BRIEF" -static int tr2env_perf_brief; +static int tr2env_perf_be_brief; #define TR2FMT_PERF_FL_WIDTH (50) #define TR2FMT_PERF_MAX_EVENT_NAME (12) @@ -36,17 +36,17 @@ static int fn_init(void) { int want = tr2_dst_trace_want(&tr2dst_perf); int want_brief; - char *brief; + const char *brief; if (!want) return want; strbuf_addchars(&dots, '.', TR2_DOTS_BUFFER_SIZE); - brief = getenv(TR2_ENVVAR_PERF_BRIEF); + brief = tr2_sysenv_get(TR2_SYSENV_PERF_BRIEF); if (brief && *brief && ((want_brief = git_parse_maybe_bool(brief)) != -1)) - tr2env_perf_brief = want_brief; + tr2env_perf_be_brief = want_brief; return want; } @@ -77,7 +77,7 @@ static void perf_fmt_prepare(const char *event_name, strbuf_setlen(buf, 0); - if (!tr2env_perf_brief) { + if (!tr2env_perf_be_brief) { struct tr2_tbuf tb_now; tr2_tbuf_local_time(&tb_now); @@ -159,15 +159,16 @@ static void fn_version_fl(const char *file, int line) strbuf_release(&buf_payload); } -static void fn_start_fl(const char *file, int line, const char **argv) +static void fn_start_fl(const char *file, int line, + uint64_t us_elapsed_absolute, const char **argv) { const char *event_name = "start"; struct strbuf buf_payload = STRBUF_INIT; sq_quote_argv_pretty(&buf_payload, argv); - perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL, - &buf_payload); + perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute, + NULL, NULL, &buf_payload); strbuf_release(&buf_payload); } diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c index 8e65b0361d..e76d8c5d92 100644 --- a/trace2/tr2_tls.c +++ b/trace2/tr2_tls.c @@ -10,16 +10,30 @@ #define TR2_REGION_NESTING_INITIAL_SIZE (100) static struct tr2tls_thread_ctx *tr2tls_thread_main; -static uint64_t tr2tls_us_start_main; +static uint64_t tr2tls_us_start_process; static pthread_mutex_t tr2tls_mutex; static pthread_key_t tr2tls_key; static int tr2_next_thread_id; /* modify under lock */ -struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name) +void tr2tls_start_process_clock(void) +{ + if (tr2tls_us_start_process) + return; + + /* + * Keep the absolute start time of the process (i.e. the main + * process) in a fixed variable since other threads need to + * access it. This allows them to do that without a lock on + * main thread's array data (because of reallocs). + */ + tr2tls_us_start_process = getnanotime() / 1000; +} + +struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, + uint64_t us_thread_start) { - uint64_t us_now = getnanotime() / 1000; struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx)); /* @@ -29,7 +43,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name) */ ctx->alloc = TR2_REGION_NESTING_INITIAL_SIZE; ctx->array_us_start = (uint64_t *)xcalloc(ctx->alloc, sizeof(uint64_t)); - ctx->array_us_start[ctx->nr_open_regions++] = us_now; + ctx->array_us_start[ctx->nr_open_regions++] = us_thread_start; ctx->thread_id = tr2tls_locked_increment(&tr2_next_thread_id); @@ -55,7 +69,7 @@ struct tr2tls_thread_ctx *tr2tls_get_self(void) * here and silently continue. */ if (!ctx) - ctx = tr2tls_create_self("unknown"); + ctx = tr2tls_create_self("unknown", getnanotime() / 1000); return ctx; } @@ -124,22 +138,18 @@ uint64_t tr2tls_absolute_elapsed(uint64_t us) if (!tr2tls_thread_main) return 0; - return us - tr2tls_us_start_main; + return us - tr2tls_us_start_process; } void tr2tls_init(void) { + tr2tls_start_process_clock(); + pthread_key_create(&tr2tls_key, NULL); init_recursive_mutex(&tr2tls_mutex); - tr2tls_thread_main = tr2tls_create_self("main"); - /* - * Keep a copy of the absolute start time of the main thread - * in a fixed variable since other threads need to access it. - * This also eliminates the need to lock accesses to the main - * thread's array (because of reallocs). - */ - tr2tls_us_start_main = tr2tls_thread_main->array_us_start[0]; + tr2tls_thread_main = + tr2tls_create_self("main", tr2tls_us_start_process); } void tr2tls_release(void) diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h index bb80e3f8e7..b1e327a928 100644 --- a/trace2/tr2_tls.h +++ b/trace2/tr2_tls.h @@ -31,7 +31,8 @@ struct tr2tls_thread_ctx { * In this and all following functions the term "self" refers to the * current thread. */ -struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name); +struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, + uint64_t us_thread_start); /* * Get our TLS data. @@ -94,4 +95,9 @@ void tr2tls_release(void); */ int tr2tls_locked_increment(int *p); +/* + * Capture the process start time and do nothing else. + */ +void tr2tls_start_process_clock(void); + #endif /* TR2_TLS_H */ |