How can I debug git/git-shell related problems?

Asked 30/5, 2011 at 15:58 Answered 19/12, 2023 at 9:23

251

How can I have some debug information regarding git/git-shell?

I had a problem, that user1 could clone a repository without problem, while user2 could clone only an empty one. I had set GIT_TRACE=1, but nothing useful was told.

Finally, after a long trial and error, it turned out that it was a permission problem on a file. An appropriate error message could short-circuit this problem.

Terryn answered 30/5, 2011 at 15:58 Comment(3)

Note: in addition of GIT_CURL_VERBOSE, you will have with Git 2.9.x/2.10 GIT_TRACE_CURL. See my answer below. – Bohi 9/7, 2016 at 20:2

And (Q2 2019, three years after GIT_TRACE_CURL), you now have trace2. Example: git config --global trace2.normalTarget ~/log.normal. See my (new) answer below. – Bohi 13/5, 2019 at 19:22

trace2 can even display git config values used at runtime, used during the execution of a git command! (Git 2.38, Q3 2022) – Bohi 11/9, 2022 at 16:45

319

For even more verbose output use following:

GIT_CURL_VERBOSE=1 GIT_TRACE=1 git pull origin master

Indwell answered 27/6, 2013 at 13:28 Comment(5)

There are a few GIT_TRACE options, beyond the core one. Here's the über-verbose option:

set -x; GIT_TRACE=2 GIT_CURL_VERBOSE=2 GIT_TRACE_PERFORMANCE=2 GIT_TRACE_PACK_ACCESS=2 GIT_TRACE_PACKET=2 GIT_TRACE_PACKFILE=2 GIT_TRACE_SETUP=2 GIT_TRACE_SHALLOW=2 git pull origin master -v -v; set +x

– Steger 9/1, 2016 at 21:22

That's just a whole line you can paste into your terminal. You should replace the git pull origin master part with the command you want to execute. – Shortcircuit 1/3, 2016 at 7:44

On Windows you can set these variables, one at a time (one per line), like this: set GIT_CURL_VERBOSE=1 set GIT_TRACE=1 git pull origin master – Benevolent 14/11, 2017 at 17:50

And on powershell you can set them like this: $Env:GIT_CURL_VERBOSE=1 – Allogamy 23/9, 2020 at 21:1

@PaulIrish's oneliner wrapped in parantheses (so that the set -x does not leak into the shell on abort/ Ctrl+c ) ... and making underlying ssh invocations extra-verbose ....:

(set -x; GIT_TRACE=2 GIT_CURL_VERBOSE=2 GIT_TRACE_PERFORMANCE=2 GIT_TRACE_PACK_ACCESS=2 GIT_TRACE_PACKET=2 GIT_TRACE_PACKFILE=2 GIT_TRACE_SETUP=2 GIT_TRACE_SHALLOW=2 GIT_SSH_COMMAND="ssh -vvv"

git <command> -vv ) – Attentive 12/9, 2023 at 9:25

147

Debugging

Git has a fairly complete set of traces embedded which you can use to debug your git problems.

To turn them on, you can define the following variables:

GIT_TRACE for general traces,
GIT_TRACE_PACK_ACCESS for tracing of packfile access,
GIT_TRACE_PACKET for packet-level tracing for network operations,
GIT_TRACE_PERFORMANCE for logging the performance data,
GIT_TRACE_SETUP for information about discovering the repository and environment it’s interacting with,
GIT_MERGE_VERBOSITY for debugging recursive merge strategy (values: 0-5),
GIT_CURL_VERBOSE for logging all curl messages (equivalent to curl -v),
GIT_TRACE_SHALLOW for debugging fetching/cloning of shallow repositories.

Possible values can include:

true, 1 or 2 to write to stderr,
an absolute path starting with / to trace output to the specified file.

For more details, see: Git Internals - Environment Variables

SSH

For SSH issues, try the following commands:

echo 'ssh -vvv "$*"' > ssh && chmod +x ssh
GIT_SSH="$PWD/ssh" git pull origin master

or use ssh to validate your credentials, e.g.

ssh -vvvT [email protected]

or over HTTPS port:

ssh -vvvT -p 443 [email protected]

^{Note: Reduce number of -v to reduce the verbosity level.}

Examples

$ GIT_TRACE=1 git status
20:11:39.565701 git.c:350               trace: built-in: git 'status'

$ GIT_TRACE_PERFORMANCE=$PWD/gc.log git gc
Counting objects: 143760, done.
...
$ head gc.log 
20:12:37.214410 trace.c:420             performance: 0.090286000 s: git command: 'git' 'pack-refs' '--all' '--prune'
20:12:37.378101 trace.c:420             performance: 0.156971000 s: git command: 'git' 'reflog' 'expire' '--all'
...

$ GIT_TRACE_PACKET=true git pull origin master
20:16:53.062183 pkt-line.c:80           packet:        fetch< 93eb028c6b2f8b1d694d1173a4ddf32b48e371ce HEAD\0multi_ack thin-pack side-band side-band-64k ofs-delta shallow no-progress include-tag multi_ack_detailed symref=HEAD:refs/heads/master agent=git/2:2.6.5~update-ref-initial-update-1494-g76b680d
...

Instantly answered 1/8, 2016 at 19:17 Comment(2)

Changing echo 'ssh -vvv $*' > ssh && chmod +x ssh to echo 'ssh -vvv "$@"' > ssh && chmod +x ssh should be safer in the edge case where a single parameter has a space in it. – Southey 10/4, 2019 at 20:10

@AlexanderBird, ...though not as safe as one would want, because when ssh is given several different arguments in the command-to-run-remotely position, it just concatenates them together with spaces into a single string the remote shell evals as code. One might end up with something like ssh -vvv "${*@Q}" in trying to do it right. – Socinus 5/10, 2022 at 22:18

If its over SSH, you can use the following:

For a higher debug level for type -vv or -vvv for debug level 2 and 3 respectively:

# Debug level 1
GIT_SSH_COMMAND="ssh -v" git clone <repositoryurl>

# Debug level 2
GIT_SSH_COMMAND="ssh -vv" git clone <repositoryurl>

# Debug level 3
GIT_SSH_COMMAND="ssh -vvv" git clone <repositoryurl>

This is mainly useful to handle public and private key problems with the server. You can use this command for any git command, not only 'git clone'.

Nighttime answered 26/1, 2016 at 15:17 Comment(5)

Yes, this works perfect. Better than others. Yes, this works perfect. Better than others. – Alloplasm 25/4, 2016 at 4:2

This would be most useful as I have to resolve a key problem now, but it doesn't work for me with git 1.8.3.1 and OpenSSH_6.6.1p1, OpenSSL 1.0.1e-fips 11 Feb 2013 on CentOS Linux release 7.2.1511 (Core). :( – Bohemianism 6/6, 2016 at 12:37

@GregDubicki Strange. Let me know what works for you so that I can update the answer. – Nighttime 6/6, 2016 at 21:1

On Windows use set GIT_SSH_COMMAND=ssh -v (no quotes). – Heckle 24/1, 2018 at 9:11

On Powershell you'd use $env:GIT_SSH_COMMAND="ssh -v" ... the above commenter didn't mean "Windows" but cmd.exe on Windows. – Lactation 12/7, 2023 at 10:4

try this one:

GIT_TRACE=1 git pull origin master

Quotable answered 10/12, 2012 at 17:8 Comment(0)

Git 2.9.x/2.10 (Q3 2016) adds another debug option: GIT_TRACE_CURL.

See commit 73e57aa, commit 74c682d (23 May 2016) by Elia Pinto (devzero2000).
Helped-by: Torsten Bögershausen (tboegi), Ramsay Jones [email protected], Junio C Hamano (gitster), Eric Sunshine (sunshineco), and Jeff King (peff).
^{(Merged by Junio C Hamano -- gitster -- in commit 2f84df2, 06 Jul 2016)}

http.c: implement the GIT_TRACE_CURL environment variable

Implement the GIT_TRACE_CURL environment variable to allow a greater degree of detail of GIT_CURL_VERBOSE, in particular the complete transport header and all the data payload exchanged.
It might be useful if a particular situation could require a more thorough debugging analysis.

The documentation will state:

GIT_TRACE_CURL
Enables a curl full trace dump of all incoming and outgoing data, including descriptive information, of the git transport protocol.
This is similar to doing curl --trace-ascii on the command line.

This option overrides setting the GIT_CURL_VERBOSE environment variable.

You can see that new option used in this answer, but also in the Git 2.11 (Q4 2016) tests:

See commit 14e2411, commit 81590bf, commit 4527aa1, commit 4eee6c6 (07 Sep 2016) by Elia Pinto (devzero2000).
^{(Merged by Junio C Hamano -- gitster -- in commit 930b67e, 12 Sep 2016)}

Use the new GIT_TRACE_CURL environment variable instead of the deprecated GIT_CURL_VERBOSE.

GIT_TRACE_CURL=true git clone --quiet $HTTPD_URL/smart/repo.git

Note that all command do not necessarily emit traces.
For instance: you would need Git 2.32 (Q2 2021) before the reflog expiry machinery has been taught to emit trace events.

See commit 34c3199 (23 Apr 2021) by Han-Wen Nienhuys (hanwen).
^{(Merged by Junio C Hamano -- gitster -- in commit a850356, 07 May 2021)}

refs/debug: trace into reflog expiry too

^{Signed-off-by: Han-Wen Nienhuys}

With Git 2.39 (Q4 2022), redact headers from cURL's h2h3 module in GIT_CURL_VERBOSE and others.

See commit b637a41 (11 Nov 2022) by Glen Choo (chooglen).
See commit 73c49a4 (11 Nov 2022) by Jeff King (peff).
^{(Merged by Junio C Hamano -- gitster -- in commit 6adf170, 23 Nov 2022)}

http: redact curl h2h3 headers in info

^{Helped-by: Jeff King}
^{Signed-off-by: Glen Choo}
^{Signed-off-by: Taylor Blau}

With GIT_TRACE_CURL=1 or GIT_CURL_VERBOSE=1, sensitive headers like "Authorization" and "Cookie" get redacted.
However, since curl/curl commit f8c3724, curl's h2h3 module (invoked when using HTTP/2) also prints headers in its "info", which don't get redacted.
For example,
echo 'github.com  TRUE    /   FALSE   1698960413304   o   foo=bar' >cookiefile &&
GIT_TRACE_CURL=1 GIT_TRACE_CURL_NO_DATA=1 git \
  -c 'http.cookiefile=cookiefile' \
  -c 'http.version=' \
  ls-remote https://github.com/git/git refs/heads/main 2>output &&
grep 'cookie' output
produces output like:
23:04:16.920495 http.c:678              == Info: h2h3 [cookie: o=foo=bar]
23:04:16.920562 http.c:637              => Send header: cookie: o=<redacted>
Teach http.c to check for h2h3 headers in info and redact them using the existing header redaction logic.
This fixes the broken redaction logic that we noted in the previous commit, so mark the redaction tests as passing under HTTP2.

With Git 2.42 (Q3 2023), Git handles both "h2" and "h2h3" in curl info lines

See commit fb7d80e (24 Jun 2023) by Junio C Hamano (gitster).
See commit db30130 (17 Jun 2023) by Jeff King (peff).
^{(Merged by Junio C Hamano -- gitster -- in commit 94486b6, 24 Jun 2023)}

http: handle both "h2" and "h2h3" in curl info lines

^{Signed-off-by: Jeff King}

When redacting auth tokens in trace output from curl, we look for http/2 headers of the form "h2h3 [header: value]".
This comes from b637a41 ("http: redact curl h2h3 headers in info", 2022-11-11, Git v2.39.0-rc0 -- merge).

But the "h2h3" prefix changed to just "h2" in curl's fc2f1e5 commit (http2: support HTTP/2 to forward proxies, non-tunneling, 2023-04-14).
That's in released version curl 8.1.0; linking against that version means we'll fail to correctly redact the trace.
Our t5559.17 notices and fails.

We can fix this by matching either prefix, which should handle both old and new versions.

With Git 2.43 (Q4 2023), HTTP Header redaction code has been adjusted for a newer version of cURL library that shows its traces differently from earlier versions.

See commit 0763c3a, commit 39fa527 (15 Sep 2023) by Jeff King (peff).
^{(Merged by Junio C Hamano -- gitster -- in commit 7a90d1e, 22 Sep 2023)}

http: update curl http/2 info matching for curl 8.3.0

^{Signed-off-by: Jeff King}

To redact header lines in http/2 curl traces, we have to parse past some prefix bytes that curl sticks in the info lines it passes to us.
That changed once already, and we adapted in db30130 (http: handle both , 2023-06-17, Git v2.42.0-rc0 -- merge listed in batch #5) (http: handle both "h2" and "h2h3" in curl info lines, 2023-06-17).

Now it has changed again, in curl's fbacb14 commit (http2: cleanup trace messages, 2023-08-04), which was released in curl 8.3.0.
Running a build of git linked against that version will fail to redact the trace (and as before, t5559 notices and complains).

The format here is a little more complicated than the other ones, as it now includes a "stream id".
This is not constant but is always numeric, so we can easily parse past it.

We'll continue to match the old versions, of course, since we want to work with many different versions of curl.
We can't even select one format at compile time, because the behavior depends on the runtime version of curl we use, not the version we build against.

trace2 streams used to record the URLs that potentially embed authentication material, which has been corrected with Git 2.44 (Q1 2024).

See commit b7d49ac (22 Nov 2023) by Johannes Schindelin (dscho).
See commit 16fa3ee, commit c73e7f8, commit abcdb97 (22 Nov 2023) by Jeff Hostetler (Jeff-Hostetler).
^{(Merged by Junio C Hamano -- gitster -- in commit c1aefb6, 18 Dec 2023)}

trace2: redact passwords from https:// URLs by default

^{Co-authored-by: Jeff Hostetler}
^{Signed-off-by: Jeff Hostetler}
^{Signed-off-by: Johannes Schindelin}

It is an unsafe practice to call something like
git clone https://user:[email protected]/
That not only risks leaking the password "over the shoulder" or into the readline history of the current Unix shell, it also gets logged via Trace2 if enabled.

Let's at least avoid logging such secrets via Trace2, much like we avoid logging secrets in http.c.
Much like the code in http.c is guarded via GIT_TRACE_REDACT (defaulting to true), we guard the new code via GIT_TRACE2_REDACT (also defaulting to true).

Bohi answered 9/7, 2016 at 20:1 Comment(4)

This feature is cool! The only point is ASCII output (where they print all that is not (ch >= 0x20) && (ch < 0x80) as dot .) and no way of hex output for http data. – Haphazardly 6/10, 2016 at 17:44

I like it. I am using git version 2.39.1 and in contrast to the documentation, I seem to find that with GIT_CURL_VERBOSE=true GIT_TRACE_CURL=true git push that GIT_TRACE_CURL is actually overridden by GIT_CURL_VERBOSE. – Augustinaaugustine 24/4, 2023 at 18:56

@Augustinaaugustine Strange, maybe a bug. These days, I usually rely only on TRACE2. From this search, GIT_CURL_VERBOSE seems really not used anymore. – Bohi 24/4, 2023 at 19:1

See also commit fb7d80e – Bohi 1/7, 2023 at 11:52

Git 2.22 (Q2 2019) introduces trace2 with commit ee4512e by Jeff Hostetler:

trace2: create new combined trace facility

Create a new unified tracing facility for git.
The eventual intent is to replace the current trace_printf* and trace_performance* routines with a unified set of git_trace2* routines.

In addition to the usual printf-style API, trace2 provides higer-level event verbs with fixed-fields allowing structured data to be written.
This makes post-processing and analysis easier for external tools.

Trace2 defines 3 output targets.
These are set using the environment variables "GIT_TR2", "GIT_TR2_PERF", and "GIT_TR2_EVENT".
These may be set to "1" or to an absolute pathname (just like the current GIT_TRACE).

Note: regarding environment variable name, always use GIT_TRACExxx, not GIT_TRxxx.
So actually GIT_TRACE2, GIT_TRACE2_PERF or GIT_TRACE2_EVENT.
See the Git 2.22 rename mentioned later below.

What follows is the initial work on this new tracing feature, with the old environment variable names:

GIT_TR2 is intended to be a replacement for GIT_TRACE and logs command summary data.

GIT_TR2_PERF is intended as a replacement for GIT_TRACE_PERFORMANCE.
It extends the output with columns for the command process, thread, repo, absolute and relative elapsed times.
It reports events for child process start/stop, thread start/stop, and per-thread function nesting.

GIT_TR2_EVENT is a new structured format. It writes event data as a series of JSON records.

Calls to trace2 functions log to any of the 3 output targets enabled without the need to call different trace_printf* or trace_performance* routines.

See commit a4d3a28 (21 Mar 2019) by Josh Steadmon (steadmon).
^{(Merged by Junio C Hamano -- gitster -- in commit 1b40314, 08 May 2019)}

trace2: write to directory targets

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.

The new documentation now includes config settings which are only read from the system and global config files (meaning repository local and worktree config files and -c command line arguments are not respected.)

Example:

$ 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
12:28:42.620989 common-main.c:39                  start git version
12:28:42.621101 git.c:432                         cmd_name version (version)
12:28:42.621215 git.c:662                         exit elapsed:0.001227 code:0
12:28:42.621250 trace2/tr2_tgt_normal.c:124 atexit elapsed:0.001265 code:0

And for performance measure:

$ 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        |     |  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

As documented in Git 2.23 (Q3 2019), the environment variable to use is GIT_TRACE2.

See commit 6114a40 (26 Jun 2019) by Carlo Marcelo Arenas Belón (carenas).
See commit 3efa1c6 (12 Jun 2019) by Ævar Arnfjörð Bjarmason (avar).
^{(Merged by Junio C Hamano -- gitster -- in commit e9eaaa4, 09 Jul 2019)}

That follows the work done in Git 2.22: commit 4e0d3aa, commit e4b75d6 (19 May 2019) by SZEDER Gábor (szeder).
^{(Merged by Junio C Hamano -- gitster -- in commit 463dca6, 30 May 2019)}

trace2: rename environment variables to GIT_TRACE2*

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.

Git 2.24 (Q3 2019) improves the Git repository initialization.

See commit 22932d9, commit 5732f2b, commit 58ebccb (06 Aug 2019) by Jeff King (peff).
^{(Merged by Junio C Hamano -- gitster -- in commit b4a1eec, 09 Sep 2019)}

common-main: delay trace2 initialization

We initialize the trace2 system in the common main() function so that all programs (even ones that aren't builtins) will enable tracing.

But trace2 startup is relatively heavy-weight, as we have to actually read on-disk config to decide whether to trace.
This can cause unexpected interactions with other common-main initialization. For instance, we'll end up in the config code before calling initialize_the_repository(), and the usual invariant that the_repository is never NULL will not hold.

Let's push the trace2 initialization further down in common-main, to just before we execute cmd_main().

Git 2.24 (Q4 2019) makes also sure that output from trace2 subsystem is formatted more prettily now.

See commit 742ed63, commit e344305, commit c2b890a (09 Aug 2019), commit ad43e37, commit 04f10d3, commit da4589c (08 Aug 2019), and commit 371df1b (31 Jul 2019) by Jeff Hostetler (jeffhostetler).
^{(Merged by Junio C Hamano -- gitster -- in commit 93fc876, 30 Sep 2019)}

And, still Git 2.24

See commit 87db61a, commit 83e57b0 (04 Oct 2019), and commit 2254101, commit 3d4548e (03 Oct 2019) by Josh Steadmon (steadmon).
^{(Merged by Junio C Hamano -- gitster -- in commit d0ce4d9, 15 Oct 2019)}

trace2: discard new traces if target directory has too many files

^{Signed-off-by: Josh Steadmon}

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.

And Git 2.24 (Q4 2019) teach trace2 about git push stages.

See commit 25e4b80, commit 5fc3118 (02 Oct 2019) by Josh Steadmon (steadmon).
^{(Merged by Junio C Hamano -- gitster -- in commit 3b9ec27, 15 Oct 2019)}

push: add trace2 instrumentation

^{Signed-off-by: Josh Steadmon}

Add trace2 regions in transport.c and builtin/push.c to better track time spent in various phases of pushing:

Listing refs

Checking submodules

Pushing submodules

Pushing refs

With Git 2.25 (Q1 2020), some of the Documentation/technical is moved to header *.h files.

See commit 6c51cb5, commit d95a77d, commit bbcfa30, commit f1ecbe0, commit 4c4066d, commit 7db0305, commit f3b9055, commit 971b1f2, commit 13aa9c8, commit c0be43f, commit 19ef3dd, commit 301d595, commit 3a1b341, commit 126c1cc, commit d27eb35, commit 405c6b1, commit d3d7172, commit 3f1480b, commit 266f03e, commit 13c4d7e (17 Nov 2019) by Heba Waly (HebaWaly).
^{(Merged by Junio C Hamano -- gitster -- in commit 26c816a, 16 Dec 2019)}

trace2: move doc to trace2.h

^{Signed-off-by: Heba Waly}

Move the functions documentation from Documentation/technical/api-trace2.txt to trace2.h as it's easier for the developers to find the usage information beside the code instead of looking for it in another doc file.

Only the functions documentation section is removed from Documentation/technical/api-trace2.txt as the file is full of details that seemed more appropriate to be in a separate doc file as it is, with a link to the doc file added in the trace2.h. Also the functions doc is removed to avoid having redundandt info which will be hard to keep syncronized with the documentation in the header file.

(although that reorganization had a side effect on another command, explained and fixed with Git 2.25.2 (March 2020) in commit cc4f2eb (14 Feb 2020) by Jeff King (peff).
^{(Merged by Junio C Hamano -- gitster -- in commit 1235384, 17 Feb 2020)})

With Git 2.27 (Q2 2020): Trace2 enhancement to allow logging of the environment variables.

See commit 3d3adaa (20 Mar 2020) by Josh Steadmon (steadmon).
^{(Merged by Junio C Hamano -- gitster -- in commit 810dc64, 22 Apr 2020)}

trace2: teach Git to log environment variables

^{Signed-off-by: Josh Steadmon}
^{Acked-by: Jeff Hostetler}

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.

With Git 2.27 (Q2 2020), teach codepaths that show progress meter to also use the start_progress() and the stop_progress() calls as a "region" to be traced.

See commit 98a1364 (12 May 2020) by Emily Shaffer (nasamuffin).
^{(Merged by Junio C Hamano -- gitster -- in commit d98abce, 14 May 2020)}

trace2: log progress time and throughput

^{Signed-off-by: Emily Shaffer}

Rather than teaching only one operation, like 'git fetch', how to write down throughput to traces, we can learn about a wide range of user operations that may seem slow by adding tooling to the progress library itself.

Operations which display progress are likely to be slow-running and the kind of thing we want to monitor for performance anyways.

By showing object counts and data transfer size, we should be able to make some derived measurements to ensure operations are scaling the way we expect.

And:

With Git 2.27 (Q2 2020), last-minute fix for our recent change to allow use of progress API as a traceable region.

See commit 3af029c (15 May 2020) by Derrick Stolee (derrickstolee).
^{(Merged by Junio C Hamano -- gitster -- in commit 85d6e28, 20 May 2020)}

progress: call trace2_region_leave() only after calling _enter()

^{Signed-off-by: Derrick Stolee}

A user of progress API calls start_progress() conditionally and depends on the display_progress() and stop_progress() functions to become no-op when start_progress() hasn't been called.

As we added a call to trace2_region_enter() to start_progress(), the calls to other trace2 API calls from the progress API functions must make sure that these trace2 calls are skipped when start_progress() hasn't been called on the progress struct.

Specifically, do not call trace2_region_leave() from stop_progress() when we haven't called start_progress(), which would have called the matching trace2_region_enter().

That last part is more robust with Git 2.29 (Q4 2020):

See commit ac900fd (10 Aug 2020) by Martin Ågren (none).
^{(Merged by Junio C Hamano -- gitster -- in commit e6ec620, 17 Aug 2020)}

progress: don't dereference before checking for NULL

^{Signed-off-by: Martin Ågren}

In stop_progress(), we're careful to check that p_progress is non-NULL before we dereference it, but by then we have already dereferenced it when calling finish_if_sparse(*p_progress).
And, for what it's worth, we'll go on to blindly dereference it again inside stop_progress_msg().

With Git 2.29 (Q4 2020), there is even more trace, this time in a Git development environment.

See commit 4441f42 (09 Sep 2020) by Han-Wen Nienhuys (hanwen).
^{(Merged by Junio C Hamano -- gitster -- in commit c9a04f0, 22 Sep 2020)}

refs: add GIT_TRACE_REFS debugging mechanism

^{Signed-off-by: Han-Wen Nienhuys}

When set in the environment, GIT_TRACE_REFS makes git print operations and results as they flow through the ref storage backend. This helps debug discrepancies between different ref backends.

Example:

$ GIT_TRACE_REFS="1" ./git branch
15:42:09.769631 refs/debug.c:26         ref_store for .git
15:42:09.769681 refs/debug.c:249        read_raw_ref: HEAD: 0000000000000000000000000000000000000000 (=> refs/heads/ref-debug) type 1: 0
15:42:09.769695 refs/debug.c:249        read_raw_ref: refs/heads/ref-debug: 3a238e539bcdfe3f9eb5010fd218640c1b499f7a (=> refs/heads/ref-debug) type 0: 0
15:42:09.770282 refs/debug.c:233        ref_iterator_begin: refs/heads/ (0x1)
15:42:09.770290 refs/debug.c:189        iterator_advance: refs/heads/b4 (0)
15:42:09.770295 refs/debug.c:189        iterator_advance: refs/heads/branch3 (0)

git now includes in its man page:

GIT_TRACE_REFS

Enables trace messages for operations on the ref database. See GIT_TRACE for available trace output options.

With Git 2.30 (Q1 2021), like die() and error(), a call to warning() will also trigger a trace2 event.

See commit 0ee10fd (23 Nov 2020) by Jonathan Tan (jhowtan).
^{(Merged by Junio C Hamano -- gitster -- in commit 2aeafbc, 08 Dec 2020)}

usage: add trace2 entry upon warning()

^{Signed-off-by: Jonathan Tan}

Emit a trace2 error event whenever warning() is called, just like when die(), error(), or usage() is called.

This helps debugging issues that would trigger warnings but not errors.
In particular, this might have helped debugging an issue I encountered with commit graphs at $DAYJOB.

There is a tradeoff between including potentially relevant messages and cluttering up the trace output produced.
I think that warning() messages should be included in traces, because by its nature, Git is used over multiple invocations of the Git tool, and a failure (currently traced) in a Git invocation might be caused by an unexpected interaction in a previous Git invocation that only has a warning (currently untraced) as a symptom - as is the case in here.

With Git 2.35 (Q1 2022), exit is properly traced:

See commit 368b584 (07 Dec 2021) by Ævar Arnfjörð Bjarmason (avar).
^{(Merged by Junio C Hamano -- gitster -- in commit 67b7017, 22 Dec 2021)}

common-main.c: call exit(), don't return

^{Signed-off-by: Ævar Arnfjörð Bjarmason}

Change the main() function to call "exit()" instead of ending with a "return" statement.
The "exit()" function is our own wrapper that calls trace2_cmd_exit_fl() for us, from git-compat-util.h:
#define exit(code) exit(trace2_cmd_exit_fl(__FILE__, __LINE__, (code)))
That "exit()" wrapper has been in use ever since ee4512e ("trace2: create new combined trace facility", 2019-02-22, Git v2.22.0-rc0 -- merge listed in batch #2).

There is already code immediately downstream of our "main()" which has a hard reliance on that, e.g. the various "exit()" calls downstream of "cmd_main()" in "git.c".

With Git 2.36 (Q2 2022), the progress API is more robust regarding tracing.

See commit b3118a5, commit 74900a6, commit accf1eb, commit 1ccad6a, commit a02014b, commit bbfb1c2, commit 791afae, commit 587c3d0, commit 8266e0c (03 Feb 2022) by Ævar Arnfjörð Bjarmason (avar).
^{(Merged by Junio C Hamano -- gitster -- in commit a47fcfe, 25 Feb 2022)}

progress API: unify stop_progress{,_msg}(), fix trace2 bug

^{Signed-off-by: Ævar Arnfjörð Bjarmason}

We've had a submarine bug here introduced with 9d81ecb ("progress: add sparse mode to force 100% complete message", 2019-03-21, Git v2.22.0-rc0 -- merge listed in batch #5).
The "start_sparse_progress()" API would only do the right thing if the progress was ended with "stop_progress()", not "stop_progress_msg()".

The only user of that API uses "stop_progress()", but let's still fix that along with the trace2 issue by making "stop_progress()" a trivial wrapper for "stop_progress_msg()".

Bohi answered 11/5, 2019 at 22:20 Comment(0)

Have you tried adding the verbose (-v) operator when you clone?

git clone -v git://git.kernel.org/pub/scm/.../linux-2.6 my2.6

Philpot answered 30/5, 2011 at 16:3 Comment(0)

For older git versions (1.8 and before)

I could find no suitable way to enable SSH debugging in an older git and ssh versions. I looked for environment variables using ltrace -e getenv ... and couldn't find any combination of GIT_TRACE or SSH_DEBUG variables that would work.

Instead here's a recipe to temporarily inject 'ssh -v' into the git->ssh sequence:

$ echo '/usr/bin/ssh -v ${@}' >/tmp/ssh
$ chmod +x /tmp/ssh
$ PATH=/tmp:${PATH} git clone ...
$ rm -f /tmp/ssh

Here's output from git version 1.8.3 with ssh version OpenSSH_5.3p1, OpenSSL 1.0.1e-fips 11 Feb 2013 cloning a github repo:

$ (echo '/usr/bin/ssh -v ${@}' >/tmp/ssh; chmod +x /tmp/ssh; PATH=/tmp:${PATH} \
   GIT_TRACE=1 git clone https://github.com/qneill/cliff.git; \
   rm -f /tmp/ssh) 2>&1 | tee log
trace: built-in: git 'clone' 'https://github.com/qneill/cliff.git'
trace: run_command: 'git-remote-https' 'origin' 'https://github.com/qneill/cliff.git'
Cloning into 'cliff'...
OpenSSH_5.3p1, OpenSSL 1.0.1e-fips 11 Feb 2013
debug1: Reading configuration data /home/q.neill/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug1: Connecting to github.com ...
...
Transferred: sent 4120, received 724232 bytes, in 0.2 seconds
Bytes per second: sent 21590.6, received 3795287.2
debug1: Exit status 0
trace: run_command: 'rev-list' '--objects' '--stdin' '--not' '--all'
trace: exec: 'git' 'rev-list' '--objects' '--stdin' '--not' '--all'
trace: built-in: git 'rev-list' '--objects' '--stdin' '--not' '--all'

Evan answered 15/8, 2019 at 23:14 Comment(0)

With Git 2.37 (Q3 2022), a new bug() and BUG_if_bug() API is introduced to make it easier to uniformly log "detect multiple bugs and abort in the end" pattern.

That will be part of trace2 output, which is used to debug git-shell related issues.

See commit 6d40f0a, commit 07b1d8f, commit 5b2f5d9, commit 53ca569, commit 0cc05b0, commit 19d7594 (02 Jun 2022) by Ævar Arnfjörð Bjarmason (avar).
^{(Merged by Junio C Hamano -- gitster -- in commit 4da14b5, 10 Jun 2022)}

usage.c: add a non-fatal bug() function to go with BUG()

^{Signed-off-by: Ævar Arnfjörð Bjarmason}

Add a bug() function to use in cases where we'd like to indicate a runtime BUG(), but would like to defer the BUG() call because we're possibly accumulating more bug() callers to exhaustively indicate what went wrong.

We already have this sort of facility in various parts of the codebase, just in the form of ad-hoc re-inventions of the functionality that this new API provides.
E.g.
this will be used to replace optbug() in parse-options.c, and the 'error("BUG:[...]' we do in a loop in builtin/receive-pack.c.

Unlike the code this replaces we'll log to trace2 with this new bug() function (as with other usage.c functions, including BUG()), we'll also be able to avoid calls to xstrfmt() in some cases, as the bug() function itself accepts variadic sprintf()-like arguments.

Any caller to bug() can follow up such calls with BUG_if_bug(), which will BUG() out (i.e.
abort()) if there were any preceding calls to bug(), callers can also decide not to call BUG_if_bug() and leave the resulting BUG() invocation until exit() time.
There are currently no bug() API users that don't call BUG_if_bug() themselves after a for-loop, but allowing for not calling BUG_if_bug() keeps the API flexible.
As the tests and documentation here show we'll catch missing BUG_if_bug() invocations in our exit() wrapper.

technical/api-error-handling now includes in its man page:

BUG, bug, die, usage, error, and warning report errors of

technical/api-error-handling now includes in its man page:

bug (lower-case, not BUG) is supposed to be used like BUG but prints a "BUG" message instead of calling abort().

A call to bug() will then result in a "real" call to the BUG() function, either explicitly by invoking BUG_if_bug() after call(s) to bug(), or implicitly at exit() time where we'll check if we encountered any outstanding bug() invocations.

If there were no prior calls to bug() before invoking BUG_if_bug() the latter is a NOOP. The BUG_if_bug() function takes the same arguments as BUG() itself. Calling BUG_if_bug() explicitly isn't necessary, but ensures that we die as soon as possible.

If you know you had prior calls to bug() then calling BUG() itself is equivalent to calling BUG_if_bug(), the latter being a wrapper calling BUG() if we've set a flag indicating that we've called bug().

technical/api-trace2 now includes in its man page:

This event is emitted when one of the BUG(), bug(), error(), die(), warning(), or usage() functions are called.

With Git 2.38 (Q3 2022), you can even print the configuration values used by a command at runtime.

Bohi answered 15/6, 2022 at 17:48 Comment(0)

Git 2.39 (Q4 2022) adds two new trace2 facilities, "timer" and "counter":

See commit 8107162, commit 8ad5756, commit 24a4c45, commit 3124793, commit a70839c, commit 8e8c5ad, commit 5bbb925, commit 545ddca (24 Oct 2022) by Jeff Hostetler (Jeff-Hostetler).
^{(Merged by Taylor Blau -- ttaylorr -- in commit e5be3c6, 30 Oct 2022)}

trace2: add stopwatch timers

^{Signed-off-by: Jeff Hostetler}

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 (Object DataBase) 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 required 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).

technical/api-trace2 now includes in its man page:

"th_timer"

This event logs the amount of time that a stopwatch timer was running in the thread. This event is generated when a thread exits for timers that requested per-thread events.
{
"event":"th_timer",
...
"category":"my_category",
"name":"my_timer",
"intervals":5,         # number of time it was started/stopped
"t_total":0.052741,    # total time in seconds it was running
"t_min":0.010061,      # shortest interval
"t_max":0.011648       # longest interval
}
"timer"

This event logs the amount of time that a stopwatch timer was running aggregated across all threads. This event is generated when the process exits.
{
"event":"timer",
...
"category":"my_category",
"name":"my_timer",
"intervals":5,         # number of time it was started/stopped
"t_total":0.052741,    # total time in seconds it was running
"t_min":0.010061,      # shortest interval
"t_max":0.011648       # longest interval
}

technical/api-trace2 now includes in its man page:

`Stopwatch Timer Events`

Measure the time spent in a function call or span of code that might be called from many places within the code throughout the life of the process.

static void expensive_function(void)
{
trace2_timer_start(TRACE2_TIMER_ID_TEST1);
...
sleep_millisec(1000); // Do something expensive
...
trace2_timer_stop(TRACE2_TIMER_ID_TEST1);
}

static int ut_100timer(int argc, const char **argv)
{
...

expensive_function();

// Do something else 1...

expensive_function();

// Do something else 2...

expensive_function();

return 0;
}

In this example, we measure the total time spent in expensive_function() regardless of when it is called in the overall flow of the program.

$ export GIT_TRACE2_PERF_BRIEF=1
$ export GIT_TRACE2_PERF=~/log.perf
$ t/helper/test-tool trace2 100timer 3 1000
...
$ cat ~/log.perf
d0 | main                     | version      |     |           |           |              | ...
d0 | main                     | start        |     |  0.001453 |           |              | t/helper/test-tool trace2 100timer 3 1000
d0 | main                     | cmd_name     |     |           |           |              | trace2 (trace2)
d0 | main                     | exit         |     |  3.003667 |           |              | code:0
d0 | main                     | timer        |     |           |           | test         | name:test1 intervals:3 total:3.001686 min:1.000254 max:1.000929
d0 | main                     | atexit       |     |  3.003796 |           |              | code:0

And, still with Git 2.39:

trace2: add global counter mechanism

^{Signed-off-by: Jeff Hostetler}

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.

technical/api-trace2 now includes in its man page:

"th_counter"

This event logs the value of a counter variable in a thread. This event is generated when a thread exits for counters that requested per-thread events.
{
"event":"th_counter",
...
"category":"my_category",
"name":"my_counter",
"count":23
}
"counter"

This event logs the value of a counter variable across all threads. This event is generated when the process exits. The total value reported here is the sum across all threads.
{
"event":"counter",
...
"category":"my_category",
"name":"my_counter",
"count":23
}

Bohi answered 5/11, 2022 at 23:38 Comment(0)

Windows cmd allows daisy chaining and thus the windows command answer is

set "GIT_CURL_VERBOSE=1" & set "GIT_TRACE=1" & git pull origin master

Haemoglobin answered 19/12, 2023 at 9:23 Comment(0)

Hot tags

Godot Unity Godot Help Programming Godot 4.X GUI GDScript 3D 2D Physics CSharp Godot 3.X VR XR Projects C++

Debugging

SSH

Examples

`http.c`: implement the `GIT_TRACE_CURL` environment variable

`refs/debug`: trace into reflog expiry too

`http`: redact curl `h2h3` headers in info

`http`: handle both "h2" and "h2h3" in curl info lines

`http`: update `curl` http/2 info matching for curl 8.3.0

`trace2`: redact passwords from https:// URLs by default

`trace2`: create new combined trace facility

`trace2`: write to directory targets

`trace2`: rename environment variables to GIT_TRACE2*

common-main: delay trace2 initialization

`trace2`: discard new traces if target directory has too many files

`push`: add trace2 instrumentation

`trace2`: move doc to `trace2.h`

`trace2`: teach Git to log environment variables

`trace2`: log progress time and throughput

`progress`: call `trace2_region_leave()` only after calling `_enter()`

`progress`: don't dereference before checking for `NULL`

`refs`: add `GIT_TRACE_REFS` debugging mechanism

`GIT_TRACE_REFS`

`usage`: add trace2 entry upon `warning()`

`common-main.c`: call exit(), don't return

`progress API`: unify `stop_progress{,_msg}()`, fix trace2 bug

For older git versions (1.8 and before)

`usage.c`: add a non-fatal bug() function to go with BUG()

`trace2`: add stopwatch timers

`"th_timer"`

`"timer"`

`Stopwatch Timer Events`

`trace2`: add global counter mechanism

`"th_counter"`

`"counter"`

Recommended topics

Hot tags

Debugging

SSH

Examples

http.c: implement the GIT_TRACE_CURL environment variable

refs/debug: trace into reflog expiry too

http: redact curl h2h3 headers in info

http: handle both "h2" and "h2h3" in curl info lines

http: update curl http/2 info matching for curl 8.3.0

trace2: redact passwords from https:// URLs by default

trace2: create new combined trace facility

trace2: write to directory targets

trace2: rename environment variables to GIT_TRACE2*

common-main: delay trace2 initialization

trace2: discard new traces if target directory has too many files

push: add trace2 instrumentation

trace2: move doc to trace2.h

trace2: teach Git to log environment variables

trace2: log progress time and throughput

progress: call trace2_region_leave() only after calling _enter()

progress: don't dereference before checking for NULL

refs: add GIT_TRACE_REFS debugging mechanism

GIT_TRACE_REFS

usage: add trace2 entry upon warning()

common-main.c: call exit(), don't return

progress API: unify stop_progress{,_msg}(), fix trace2 bug

For older git versions (1.8 and before)

usage.c: add a non-fatal bug() function to go with BUG()

trace2: add stopwatch timers

"th_timer"

"timer"

Stopwatch Timer Events

trace2: add global counter mechanism

"th_counter"

"counter"

Recommended topics

Hot tags

`http.c`: implement the `GIT_TRACE_CURL` environment variable

`refs/debug`: trace into reflog expiry too

`http`: redact curl `h2h3` headers in info

`http`: handle both "h2" and "h2h3" in curl info lines

`http`: update `curl` http/2 info matching for curl 8.3.0

`trace2`: redact passwords from https:// URLs by default

`trace2`: create new combined trace facility

`trace2`: write to directory targets

`trace2`: rename environment variables to GIT_TRACE2*

`trace2`: discard new traces if target directory has too many files

`push`: add trace2 instrumentation

`trace2`: move doc to `trace2.h`

`trace2`: teach Git to log environment variables

`trace2`: log progress time and throughput

`progress`: call `trace2_region_leave()` only after calling `_enter()`

`progress`: don't dereference before checking for `NULL`

`refs`: add `GIT_TRACE_REFS` debugging mechanism

`GIT_TRACE_REFS`

`usage`: add trace2 entry upon `warning()`

`common-main.c`: call exit(), don't return

`progress API`: unify `stop_progress{,_msg}()`, fix trace2 bug

`usage.c`: add a non-fatal bug() function to go with BUG()

`trace2`: add stopwatch timers

`"th_timer"`

`"timer"`

`Stopwatch Timer Events`

`trace2`: add global counter mechanism

`"th_counter"`

`"counter"`