Add global counters mechanism to Trace2.
The Trace2 counters mechanism adds the ability to create a set of
global counter variables and an API to increment them efficiently.
Counters can optionally report per-thread usage in addition to the sum
across all threads.
Counter events are emitted to the Trace2 logs when a thread exits and
at process exit.
Counters are an alternative to `data` and `data_json` events.
Counters are useful when you want to measure something across the life
of the process, when you don't want per-measurement events for
performance reasons, when the data does not fit conveniently within a
region, or when your control flow does not easily let you write the
final total. For example, you might use this to report the number of
calls to unzip() or the number of de-delta steps during a checkout.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Add stopwatch timer mechanism to Trace2.
Timers are an alternative to Trace2 Regions. Regions are useful for
measuring the time spent in various computation phases, such as the
time to read the index, time to scan for unstaged files, time to scan
for untracked files, and etc.
However, regions are not appropriate in all places. For example,
during a checkout, it would be very inefficient to use regions to
measure the total time spent inflating objects from the ODB from
across the entire lifetime of the process; a per-unzip() region would
flood the output and significantly slow the command; and some form of
post-processing would be requried to compute the time spent in unzip().
Timers can be used to measure a series of timer intervals and emit
a single summary event (at thread and/or process exit).
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Convert the `tr2tls_thread_ctx.thread_name` field from a `strbuf`
to a "const char*" pointer.
The `thread_name` field is a constant string that is constructed when
the context is created. Using a (non-const) `strbuf` structure for it
caused some confusion in the past because it implied that someone
could rename a thread after it was created. That usage was not
intended. Change it to a const pointer to make the intent more clear.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Improve the documentation of the tr2tls_thread_ctx.thread_name field
and its relation to the tr2tls_thread_ctx.thread_id field.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Rename the `thread_name` argument in `tr2tls_create_self()` and
`trace2_thread_start()` to be `thread_base_name` to make it clearer
that the passed argument is a component used in the construction of
the actual `struct tr2tls_thread_ctx.thread_name` variable.
The base name will be used along with the thread id to create a
unique thread name.
This commit does not change how the `thread_name` field is
allocated or stored within the `tr2tls_thread_ctx` structure.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Reduce or eliminate use of the term "TLS" in the Trace2 code.
The term "TLS" has two popular meanings: "thread-local storage" and
"transport layer security". In the Trace2 source, the term is associated
with the former. There was concern on the mailing list about it refering
to the latter.
Update the source and documentation to eliminate the use of the "TLS" term
or replace it with the phrase "thread-local storage" to reduce ambiguity.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Use "size_t" rather than "int" for the "alloc" and "nr_open_regions"
fields in the "tr2tls_thread_ctx". These are used by ALLOC_GROW().
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
When we specify GIT_TRACE2_CONFIG_PARAMS or trace2.configparams,
trace2 will prints "interesting" config values to log. Sometimes,
when a config set in multiple scope files, the following output
looks like (the irrelevant fields are omitted here as "..."):
...| def_param | ... | core.multipackindex:false
...| def_param | ... | core.multipackindex:false
...| def_param | ... | core.multipackindex:false
As the log shows, even each config in different scope is dumped, but
we don't know which scope it comes from. Therefore, it's better to
add the scope names as well to make them be more recognizable. For
example, when execute:
$ GIT_TRACE2_PERF=1 \
> GIT_TRACE2_CONFIG_PARAMS=core.multipackIndex \
> git rev-list --test-bitmap HEAD"
The following is the ouput (the irrelevant fields are omitted here
as "..."):
Format normal:
... git.c:461 ... def_param scope:system core.multipackindex=false
... git.c:461 ... def_param scope:global core.multipackindex=false
... git.c:461 ... def_param scope:local core.multipackindex=false
Format perf:
... | def_param | ... | scope:system | core.multipackindex:false
... | def_param | ... | scope:global | core.multipackindex:false
... | def_param | ... | scope:local | core.multipackindex:false
Format event:
{"event":"def_param", ... ,"scope":"system","param":"core.multipackindex","value":"false"}
{"event":"def_param", ... ,"scope":"global","param":"core.multipackindex","value":"false"}
{"event":"def_param", ... ,"scope":"local","param":"core.multipackindex","value":"false"}
Signed-off-by: Teng Long <dyroneteng@gmail.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Convert the "static struct tr2_dst" assignments in trace2/* to use
designated initializers. I don't think it improves readability to
include the explicit 0-ing out of the
fd/initialized/need_close/too_many_files members, so let's have those
be initialized implicitly by the compiler.
Signed-off-by: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
As with the preceding commit, change another set of file-level struct
assignments to use designated initializers.
As before the "= NULL" assignments are redundant, but we're keeping
them for self-documentation purposes. The comments left to explain the
pre-image can now be removed in favor of working code that relays the
same information to the reader.
Signed-off-by: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
API clean-up.
* ab/run-command:
run-command API: remove "env" member, always use "env_array"
difftool: use "env_array" to simplify memory management
run-command API: remove "argv" member, always use "args"
run-command API users: use strvec_push(), not argv construction
run-command API users: use strvec_pushl(), not argv construction
run-command tests: use strvec_pushv(), not argv assignment
run-command API users: use strvec_pushv(), not argv assignment
upload-archive: use regular "struct child_process" pattern
worktree: stop being overly intimate with run_command() internals
Remove the "argv" member from the run-command API, ever since "args"
was added in c460c0ecdc (run-command: store an optional argv_array,
2014-05-15) being able to provide either "argv" or "args" has led to
some confusion and bugs.
If we hadn't gone in that direction and only had an "argv" our
problems wouldn't have been solved either, as noted in [1] (and in the
documentation amended here) it comes with inherent memory management
issues: The caller would have to hang on to the "argv" until the
run-command API was finished. If the "argv" was an argument to main()
this wasn't an issue, but if it it was manually constructed using the
API might be painful.
We also have a recent report[2] of a user of the API segfaulting,
which is a direct result of it being complex to use. This commit
addresses the root cause of that bug.
This change is larger than I'd like, but there's no easy way to avoid
it that wouldn't involve even more verbose intermediate steps. We use
the "argv" as the source of truth over the "args", so we need to
change all parts of run-command.[ch] itself, as well as the trace2
logging at the same time.
The resulting Windows-specific code in start_command() is a bit nasty,
as we're now assigning to a strvec's "v" member, instead of to our own
"argv". There was a suggestion of some alternate approaches in reply
to an earlier version of this commit[3], but let's leave larger a
larger and needless refactoring of this code for now.
1. http://lore.kernel.org/git/YT6BnnXeAWn8BycF@coredump.intra.peff.net
2. https://lore.kernel.org/git/20211120194048.12125-1-ematsumiya@suse.de/
3. https://lore.kernel.org/git/patch-5.5-ea1011f7473-20211122T153605Z-avarab@gmail.com/
Signed-off-by: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
If writing a trace2 message fails, we optionally warn the user of this
fact. However, in 0ee10fd (usage: add trace2 entry upon warning(),
2020-11-23), we added a trace entry to the warning() function. This
means that we can enter an infinite loop of failing trace2 writes and
warnings. Fix this by disabling the failing trace2 destination before
issuing the warning.
Additionally, trace2 sets a default SIGPIPE handler
(tr2main_signal_handler) when it is initialized. This handler generates
its own trace2 messages when a signal is received. If a trace2 write
fails due to a broken pipe, this handler will run and then cause another
failed write. Fix this by temporarily ignoring SIGPIPE while writing
trace2 messages. This is safe because the write will still fail, and we
will disable the failing destination.
Signed-off-by: Josh Steadmon <steadmon@google.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
When we added a new event type to trace2 event stream, we forgot to
raise the format version number, which has been corrected.
* js/trace2-raise-format-version:
trace2: increment event format version
In 64bc752 (trace2: add trace2_child_ready() to report on background
children, 2021-09-20), we added a new "child_ready" event. In
Documentation/technical/api-trace2.txt, we promise that adding a new
event type will result in incrementing the trace2 event format version
number, but this was not done. Correct this in code & docs.
Signed-off-by: Josh Steadmon <steadmon@google.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Built-in fsmonitor (part 1).
* jh/builtin-fsmonitor-part1:
t/helper/simple-ipc: convert test-simple-ipc to use start_bg_command
run-command: create start_bg_command
simple-ipc/ipc-win32: add Windows ACL to named pipe
simple-ipc/ipc-win32: add trace2 debugging
simple-ipc: move definition of ipc_active_state outside of ifdef
simple-ipc: preparations for supporting binary messages.
trace2: add trace2_child_ready() to report on background children
Create "child_ready" event to capture the state of a child process
created in the background.
When a child command is started a "child_start" event is generated in
the Trace2 log. For normal synchronous children, a "child_exit" event
is later generated when the child exits or is terminated. The two events
include information, such as the "child_id" and "pid", to allow post
analysis to match-up the command line and exit status.
When a child is started in the background (and may outlive the parent
process), it is not possible for the parent to emit a "child_exit"
event. Create a new "child_ready" event to indicate whether the
child was successfully started. Also include the "child_id" and "pid"
to allow similar post processing.
This will be used in a later commit with the new "start_bg_command()".
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Fix a memory leak introduced in ee4512ed48 (trace2: create new
combined trace facility, 2019-02-22), we were doing a free() of other
memory allocated in tr2tls_create_self(), but not the "thread_name"
"struct strbuf".
Signed-off-by: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
Acked-by: Taylor Blau <me@ttaylorr.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
trace2 logs learned to show parent process name to see in what
context Git was invoked.
* es/trace2-log-parent-process-name:
tr2: log parent process name
tr2: make process info collection platform-generic
It can be useful to tell who invoked Git - was it invoked manually by a
user via CLI or script? By an IDE? In some cases - like 'repo' tool -
we can influence the source code and set the GIT_TRACE2_PARENT_SID
environment variable from the caller process. In 'repo''s case, that
parent SID is manipulated to include the string "repo", which means we
can positively identify when Git was invoked by 'repo' tool. However,
identifying parents that way requires both that we know which tools
invoke Git and that we have the ability to modify the source code of
those tools. It cannot scale to keep up with the various IDEs and
wrappers which use Git, most of which we don't know about. Learning
which tools and wrappers invoke Git, and how, would give us insight to
decide where to improve Git's usability and performance.
Unfortunately, there's no cross-platform reliable way to gather the name
of the parent process. If procfs is present, we can use that; otherwise
we will need to discover the name another way. However, the process ID
should be sufficient to look up the process name on most platforms, so
that code may be shareable.
Git for Windows gathers similar information and logs it as a "data_json"
event. However, since "data_json" has a variable format, it is difficult
to parse effectively in some languages; instead, let's pursue a
dedicated "cmd_ancestry" event to record information about the ancestry
of the current process and a consistent, parseable way.
Git for Windows also gathers information about more than one generation
of parent. In Linux further ancestry info can be gathered with procfs,
but it's unwieldy to do so. In the interest of later moving Git for
Windows ancestry logging to the 'cmd_ancestry' event, and in the
interest of later adding more ancestry to the Linux implementation - or
of adding this functionality to other platforms which have an easier
time walking the process tree - let's make 'cmd_ancestry' accept an
array of parentage.
Signed-off-by: Emily Shaffer <emilyshaffer@google.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Refactor tr2_dst_try_uds_connect() to avoid a gcc warning[1] that
appears under -O3 (but not -O2). This makes the build pass under
DEVELOPER=1 without needing a DEVOPTS=no-error.
This can be reproduced with GCC Debian 8.3.0-6, but not e.g. with
clang 7.0.1-8+deb10u2. We've had this warning since
ee4512ed48 (trace2: create new combined trace facility, 2019-02-22).
As noted in [2] this warning happens because the compiler doesn't
assume that errno must be non-zero after a failed syscall.
Let's work around by using the well-established "saved_errno" pattern,
along with returning -1 ourselves instead of "errno". The caller can
thus rely on our "errno" on failure.
See https://gcc.gnu.org/bugzilla/show_bug.cgi?id=61846 for a related
bug report against GCC.
1.
trace2/tr2_dst.c: In function ‘tr2_dst_get_trace_fd.part.5’:
trace2/tr2_dst.c:296:10: warning: ‘fd’ may be used uninitialized in this function [-Wmaybe-uninitialized]
dst->fd = fd;
~~~~~~~~^~~~
trace2/tr2_dst.c:229:6: note: ‘fd’ was declared here
int fd;
^~
2. https://lore.kernel.org/git/20200404142131.GA679473@coredump.intra.peff.net/
Signed-off-by: Ævar Arnfjörð Bjarmason <avarab@gmail.com>
Signed-off-by: Jeff King <peff@peff.net>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Via trace2, Git can already log interesting config parameters (see the
trace2_cmd_list_config() function). However, this can grant an
incomplete picture because many config parameters also allow overrides
via environment variables.
To allow for more complete logs, we add a new trace2_cmd_list_env_vars()
function and supporting implementation, modeled after the pre-existing
config param logging implementation.
Signed-off-by: Josh Steadmon <steadmon@google.com>
Acked-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Docfix.
* en/doc-typofix:
Fix spelling errors in no-longer-updated-from-upstream modules
multimail: fix a few simple spelling errors
sha1dc: fix trivial comment spelling error
Fix spelling errors in test commands
Fix spelling errors in messages shown to users
Fix spelling errors in names of tests
Fix spelling errors in comments of testcases
Fix spelling errors in code comments
Fix spelling errors in documentation outside of Documentation/
Documentation: fix a bunch of typos, both old and new
The initialization function of the Trace2 performance format target sets
aside a stash of dots for indenting output. Get rid of it and use
strbuf_addchars() to provide dots on demand instead. This shortens the
code, gets rid of a small heap allocation and is a bit more efficient.
Signed-off-by: René Scharfe <l.s.r@web.de>
Acked-by: Jeff King <peff@peff.net>
Acked-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Add a new "discard" event type for trace2 event destinations. When the
trace2 file count check creates a sentinel file, it will include the
normal trace2 output in the sentinel, along with this new discard
event.
Writing this message into the sentinel file is useful for tracking how
often the file count check triggers in practice.
Bump up the event format version since we've added a new event type.
Signed-off-by: Josh Steadmon <steadmon@google.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
trace2 can write files into a target directory. With heavy usage, this
directory can fill up with files, causing difficulty for
trace-processing systems.
This patch adds a config option (trace2.maxFiles) to set a maximum
number of files that trace2 will write to a target directory. The
following behavior is enabled when the maxFiles is set to a positive
integer:
When trace2 would write a file to a target directory, first check
whether or not the traces should be discarded. Traces should be
discarded if:
* there is a sentinel file declaring that there are too many files
* OR, the number of files exceeds trace2.maxFiles.
In the latter case, we create a sentinel file named git-trace2-discard
to speed up future checks.
The assumption is that a separate trace-processing system is dealing
with the generated traces; once it processes and removes the sentinel
file, it should be safe to generate new trace files again.
The default value for trace2.maxFiles is zero, which disables the file
count check.
The config can also be overridden with a new environment variable:
GIT_TRACE2_MAX_FILES.
Signed-off-by: Josh Steadmon <steadmon@google.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Output from trace2 subsystem is formatted more prettily now.
* jh/trace2-pretty-output:
trace2: cleanup whitespace in perf format
trace2: cleanup whitespace in normal format
quote: add sq_append_quote_argv_pretty()
trace2: trim trailing whitespace in normal format error message
trace2: remove dead code in maybe_add_string_va()
trace2: trim whitespace in region messages in perf target format
trace2: cleanup column alignment in perf target format
Let warning() format the message instead of using an intermediate strbuf
for that. This is shorter, easier to read and avoids an allocation.
Signed-off-by: René Scharfe <l.s.r@web.de>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Make use of new sq_append_quote_argv_pretty() to normalize
how we handle leading whitespace in perf format messages.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Make use of new sq_append_quote_argv_pretty() to normalize
how we handle leading whitespace in normal format messages.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Avoid creating unnecessary trailing whitespace in normal
target format error messages when the message is omitted.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Remove an unnecessary "if" block in maybe_add_string_va().
Commit "ad006fe419e trace2: NULL is not allowed for va_list"
changed "if (fmt && *fmt && ap)" to just "if (fmt && *fmt)"
because it isn't safe to treat 'ap' as a pointer. This made
the "if" block following it unnecessary.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Avoid unecessary trailing whitespace in "region_enter" and "region_leave"
messages in perf target format.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Truncate/elide very long "filename:linenumber" field.
Truncate region and data "category" field if necessary.
Adjust overall column widths.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Rename environment variables that are used to control the "trace2"
mechanism to a more readable name.
* sg/trace2-rename:
trace2: document the supported values of GIT_TRACE2* env variables
trace2: rename environment variables to GIT_TRACE2*
Teach trace2 TLS code to not rely on pthread_getspecific() when NO_PTHREADS
is defined. Instead, always assume the context data of the main thread.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
For an environment variable that is supposed to be set by users, the
GIT_TR2* env vars are just too unclear, inconsistent, and ugly.
Most of the established GIT_* environment variables don't use
abbreviations, and in case of the few that do (GIT_DIR,
GIT_COMMON_DIR, GIT_DIFF_OPTS) it's quite obvious what the
abbreviations (DIR and OPTS) stand for. But what does TR stand for?
Track, traditional, trailer, transaction, transfer, transformation,
transition, translation, transplant, transport, traversal, tree,
trigger, truncate, trust, or ...?!
The trace2 facility, as the '2' suffix in its name suggests, is
supposed to eventually supercede Git's original trace facility. It's
reasonable to expect that the corresponding environment variables
follow suit, and after the original GIT_TRACE variables they are
called GIT_TRACE2; there is no such thing is 'GIT_TR'.
All trace2-specific config variables are, very sensibly, in the
'trace2' section, not in 'tr2'.
OTOH, we don't gain anything at all by omitting the last three
characters of "trace" from the names of these environment variables.
So let's rename all GIT_TR2* environment variables to GIT_TRACE2*,
before they make their way into a stable release.
Signed-off-by: SZEDER Gábor <szeder.dev@gmail.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
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()
The trace2 tracing facility learned to auto-generate a filename
when told to log to a directory.
* js/trace2-to-directory:
trace2: write to directory targets
Update SID component construction to use the current UTC datetime
and a portion of the SHA1 of the hostname.
Use an simplified date/time format to make it easier to use the
SID component as a logfile filename.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Update tr2_tbuf_utc_datetime to generate extended UTC format.
Update tr2_tgt_event target to use extended format in 'time' columns.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Teach git to read the system and global config files for
default Trace2 settings. This allows system-wide Trace2 settings to
be installed and inherited to make it easier to manage a collection of
systems.
The original GIT_TR2* environment variables are loaded afterwards and
can be used to override the system settings.
Only the system and global config files are used. Repo and worktree
local config files are ignored. Likewise, the "-c" command line
arguments are also ignored. These limits are for performance reasons.
(1) For users not using Trace2, there should be minimal overhead to
detect that Trace2 is not enabled. In particular, Trace2 should not
allocate lots of otherwise unused data strucutres.
(2) For accurate performance measurements, Trace2 should be initialized
as early in the git process as possible, and before most of the normal
git process initialization (which involves discovering the .git directory
and reading a hierarchy of config files).
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Add elapsed process time to "start" event to measure
the performance of early process startup.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
Create trace2_initialize_clock() and call from main() to capture
process start time in isolation and before other sub-systems are
ready.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
When the value of a trace2 environment variable is an absolute path
referring to an existing directory, write output to files (one per
process) underneath the given directory. Files will be named according
to the final component of the trace2 SID, followed by a counter to avoid
potential collisions.
This makes it more convenient to collect traces for every git invocation
by unconditionally setting the relevant trace2 envvar to a constant
directory name.
Signed-off-by: Josh Steadmon <steadmon@google.com>
Reviewed-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
