Merge branch 'jh/trace2-sid-fix'
Polishing of the new trace2 facility continues. The system-level
configuration can specify site-wide trace2 settings, which can be
overridden with per-user configuration and environment variables.
* jh/trace2-sid-fix:
trace2: fixup access problem on /etc/gitconfig in read_very_early_config
trace2: update docs to describe system/global config settings
trace2: make SIDs more unique
trace2: clarify UTC datetime formatting
trace2: report peak memory usage of the process
trace2: use system/global config for default trace2 settings
config: add read_very_early_config()
trace2: find exec-dir before trace2 initialization
trace2: add absolute elapsed time to start event
trace2: refactor setting process starting time
config: initialize opts structure in repo_read_config()
diff --git a/Documentation/config.txt b/Documentation/config.txt
index d87846f..7e2a6f6 100644
--- a/Documentation/config.txt
+++ b/Documentation/config.txt
@@ -422,6 +422,8 @@
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 0000000..a5f409c
--- /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 d0948ba..9e585b8 100644
--- a/Documentation/technical/api-trace2.txt
+++ b/Documentation/technical/api-trace2.txt
@@ -22,21 +22,41 @@
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
- a simple printf format like GIT_TRACE.
-+
+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
+
------------
$ 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 @@
12:28:42.621250 trace2/tr2_tgt_normal.c:124 atexit elapsed:0.001265 code:0
------------
-`GIT_TR2_PERF` (PERF)::
+=== The Performance Format Target
- a column-based format to replace GIT_TRACE_PERFORMANCE suitable for
- development and testing, possibly to complement tools like gprof.
-+
+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
+
------------
$ 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
- a JSON-based format of event data suitable for telemetry analysis.
-+
+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
+
------------
$ export GIT_TR2_EVENT=~/log.event
$ git version
git version 2.20.1.155.g426c96fcdb
------------
-+
+
+or
+
+------------
+$ git config --global trace2.eventTarget ~/log.event
+$ git version
+git version 2.20.1.155.g426c96fcdb
+------------
+
+yields
+
------------
$ 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}
+{"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}
------------
-== Enabling a Target
+=== 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.
+To enable a target, set the corresponding environment variable or
+system or global config value to one of the following:
-`0`::
-`false`::
+include::../trace2-target-values.txt[]
- 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.
-
- 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).
-
-`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.
+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 @@
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 @@
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 @@
=== 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 @@
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 @@
=== 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 @@
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 @@
=== 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 @@
------------
{
"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 @@
`"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 @@
{
"event":"start",
...
+ "t_abs":0.001227, # elapsed time in seconds
"argv":["git","version"]
}
------------
@@ -887,7 +911,7 @@
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 @@
$ 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 @@
...
$ 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 @@
...
$ 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 0000000..27d3c64
--- /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.
+--
diff --git a/Makefile b/Makefile
index 5143cab..af24787 100644
--- a/Makefile
+++ b/Makefile
@@ -999,6 +999,7 @@
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 d484aec..582a7b1 100644
--- a/common-main.c
+++ b/common-main.c
@@ -27,6 +27,8 @@
{
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 @@
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 6b04514..a2f74ac 100644
--- a/compat/mingw.c
+++ b/compat/mingw.c
@@ -2569,6 +2569,8 @@
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 52bd620..8ccbd1c 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 @@
"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);
+ }
}
diff --git a/config.c b/config.c
index c2846df..296a6d9 100644
--- a/config.c
+++ b/config.c
@@ -1676,7 +1676,9 @@
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 @@
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 @@
}
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 @@
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 @@
/* 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;
diff --git a/config.h b/config.h
index ee5d3fa..36bb23a 100644
--- a/config.h
+++ b/config.h
@@ -55,6 +55,10 @@
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 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 8194306..71194a3 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 @@
# 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_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 953e2f7..b501e86 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 @@
# 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 @@
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 @@
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 @@
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 @@
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_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 028b6c5..59adae8 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 @@
# 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_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
diff --git a/trace2.c b/trace2.c
index 8bbad56..eb759f3 100644
--- a/trace2.c
+++ b/trace2.c
@@ -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 @@
tr2_sid_release();
tr2_cmd_name_release();
tr2_cfg_free_patterns();
+ tr2_sysenv_release();
trace2_enabled = 0;
}
@@ -142,6 +144,11 @@
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 @@
if (trace2_enabled)
return;
+ tr2_sysenv_load();
+
if (!tr2_tgt_want_builtins())
return;
trace2_enabled = 1;
@@ -177,13 +186,19 @@
{
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 @@
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 @@
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)
diff --git a/trace2.h b/trace2.h
index b330a54..f189ef5 100644
--- a/trace2.h
+++ b/trace2.h
@@ -20,8 +20,26 @@
*/
/*
+ * 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 @@
* 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 @@
* 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 b329921..caa7f06 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 @@
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 c3d82ca..5dda0ca 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 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 @@
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 @@
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 @@
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 @@
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 @@
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 @@
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 @@
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 @@
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 9a64f05..3adf3ba 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 984524a..5047095 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 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 void tr2_sid_compute(void)
{
- uint64_t us_now;
const char *parent_sid;
if (tr2sid_buf.len)
@@ -38,9 +85,7 @@
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 0000000..9025b86
--- /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 0000000..369b20b
--- /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 0844910..2498482 100644
--- a/trace2/tr2_tbuf.c
+++ b/trace2/tr2_tbuf.c
@@ -15,7 +15,7 @@
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 @@
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 9cdefa3..fa853d8 100644
--- a/trace2/tr2_tbuf.h
+++ b/trace2/tr2_tbuf.h
@@ -16,8 +16,9 @@
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 297bb8f..7b90469 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -15,6 +15,7 @@
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 1cf4f62..c2852d1 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 @@
* 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 @@
/*
* 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 @@
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 @@
{
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 @@
{
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 @@
{
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 @@
{
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 1a07d70..00b116d 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 @@
{
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 @@
{
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 @@
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 2a866d7..ea0cbbe 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 @@
{
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 @@
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 @@
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 8e65b03..e76d8c5 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)
{
- uint64_t us_now = getnanotime() / 1000;
+ 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)
+{
struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx));
/*
@@ -29,7 +43,7 @@
*/
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 @@
* here and silently continue.
*/
if (!ctx)
- ctx = tr2tls_create_self("unknown");
+ ctx = tr2tls_create_self("unknown", getnanotime() / 1000);
return ctx;
}
@@ -124,22 +138,18 @@
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 bb80e3f..b1e327a 100644
--- a/trace2/tr2_tls.h
+++ b/trace2/tr2_tls.h
@@ -31,7 +31,8 @@
* 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 @@
*/
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 */
