Re: [RFC] git --trace: trace command execution

Matthias Lederhofer [off-list ref] writes:

Show parameters to execve/builtin-cmds before executing them. This
version does not yet have a parameter --trace to git to enable this I
just want to get feedback first :)

I think this is quite useful to debug what is going on since a command
may be another program (shell/python/perl/.. script etc) or just an
alias for a internal command. Before that many commands became
built-ins this was quite easy to do with strace.

Interesting.  Debugging one's alias entries would be helped with
this I would imagine, and for that you would want something like
this:

Example:
% git showtag v1.4.1-rc1 > /dev/null
trace: exec: /home/matled/local/stow/git/bin/git-showtag v1.4.1-rc1
trace: exec failed: No such file or directory

* trace: expanded alias "showtag" => "cat-file tag"

trace: built-in command: git cat-file tag v1.4.1-rc1

By the way "git cat-file -p" or "git verify-tag -v" might be
more pleasant to view a tag since they make the tagger timestamp
human readable.

print_shell_escape will escape the arguments to be used as strings in
the shell to prevent ambiguity with spaces and other special
characters and make them copy-and-pastable.

Might be worth reusing quote.c::sq_quote(), perhaps?

Interesting.  Debugging one's alias entries would be helped with
this I would imagine, and for that you would want something like
this:

quoted

Example:
% git showtag v1.4.1-rc1 > /dev/null
trace: exec: /home/matled/local/stow/git/bin/git-showtag v1.4.1-rc1
trace: exec failed: No such file or directory

* trace: expanded alias "showtag" => "cat-file tag"

That's a good idea, I'll integrate that.

By the way "git cat-file -p" or "git verify-tag -v" might be
more pleasant to view a tag since they make the tagger timestamp
human readable.

Ok, yesterday I was searching for something to see the annotation of a
tag. verify-tag -v looks quite much like that, is there any other way
to read this? Or in general: how do I work with tags? I want to build
a version tagged as v1.2 so currently I'll do

git checkout -b 1.2 v1.2

and built it. But then I've to type the version number twice (typing
it once is annoying enough :)) and I've to type it once more to get
the tag annotation.

Might be worth reusing quote.c::sq_quote(), perhaps?

Oh, sure, did not know about this. This would result in a loop of
malloc'ing memory for the buffer. Is this ok? Or should I add a
function like sq_quote which takes a stream and writes to it?

So for the --trace part I think an environment variable GIT_TRACE is
more suitable for this because children inherit this. So running git
status will show what internal commands the shell script uses.
Otherwise I see no way to pass the --trace option down because an
extern program like git-status, git-annotate etc will not accept
parameters which can be passed to `git'.

With the environment variable GIT_TRACE set git will show
 - alias expansion
 - built-in command execution
 - external command execution
on stderr.

Signed-off-by: Matthias Lederhofer <redacted>
---
Examples:
% GIT_TRACE=1 git status > /dev/null
trace: exec: '/home/matled/local/stow/git/bin/git-status'
trace: built-in: git 'rev-parse' '--git-dir'
trace: built-in: git 'rev-parse' '--show-cdup'
trace: built-in: git 'update-index' '-q' '--unmerged' '--refresh'
trace: built-in: git 'diff-index' '-M' '--cached' '--name-status' \
    '--diff-filter=MDTCRA' 'HEAD'
trace: built-in: git 'diff-files' '--name-status'
trace: built-in: git 'ls-files' '-z' '--others' '--directory' \
    '--no-empty-directory' '--exclude-from=.git/info/exclude' \
    '--exclude-per-directory=.gitignore'

This seems to be quite useful to find out how tools do things and for
debugging.

% GIT_TRACE=1 git showtag v1.4.0 > /dev/null
trace: exec: '/home/matled/local/stow/git/bin/git-showtag' 'v1.4.0'
trace: exec failed: No such file or directory
trace: alias expansion: showtag => 'cat-file' 'tag'
trace: built-in: git 'cat-file' 'tag' 'v1.4.0'

% GIT_TRACE=1 git l > /dev/null
trace: exec: '/home/matled/local/stow/git/bin/git-l'
trace: exec failed: No such file or directory
trace: alias expansion: l => 'log' '-p'
trace: built-in: git 'log' '-p'

 Documentation/git.txt |    7 +++++++
 exec_cmd.c            |   19 +++++++++++++++++++
 git.c                 |   25 +++++++++++++++++++++++++
 quote.c               |   17 +++++++++++++++++
 quote.h               |    1 +
 5 files changed, 69 insertions(+), 0 deletions(-)

diff --git a/Documentation/git.txt b/Documentation/git.txt
index 51f20c6..603c474 100644
--- a/Documentation/git.txt
+++ b/Documentation/git.txt

@@ -615,6 +615,13 @@ git Diffs
 	gitlink:git-diff-files[1];
 	gitlink:git-diff-tree[1]
 
+other
+~~~~~
+'GIT_TRACE'::
+	If this variable is set git will print `trace:` messages on
+	stderr telling about alias expansion, built-in command
+	execution and external command execution.
+
 Discussion[[Discussion]]
 ------------------------
 include::README[]

diff --git a/exec_cmd.c b/exec_cmd.c
index c1539d1..f2133ec 100644
--- a/exec_cmd.c
+++ b/exec_cmd.c

@@ -1,5 +1,6 @@
 #include "cache.h"
 #include "exec_cmd.h"
+#include "quote.h"
 #define MAX_ARGS	32
 
 extern char **environ;

@@ -96,9 +97,27 @@ int execv_git_cmd(const char **argv)
 		tmp = argv[0];
 		argv[0] = git_command;
 
+		if (getenv("GIT_TRACE")) {
+			fputs("trace: exec:", stderr);
+			const char **p = argv;
+			while (*p) {
+				fputc(' ', stderr);
+				sq_quote_print(stderr, *p);
+				++p;
+			}
+			putc('\n', stderr);
+			fflush(stderr);
+		}
+
 		/* execve() can only ever return if it fails */
 		execve(git_command, (char **)argv, environ);
 
+		if (getenv("GIT_TRACE")) {
+			fprintf(stderr, "trace: exec failed: %s\n",
+				strerror(errno));
+			fflush(stderr);
+		}
+
 		argv[0] = tmp;
 	}
 	return -1;

diff --git a/git.c b/git.c
index 94e9a4a..8b060e8 100644
--- a/git.c
+++ b/git.c

@@ -11,6 +11,7 @@ #include <stdarg.h>
 #include "git-compat-util.h"
 #include "exec_cmd.h"
 #include "cache.h"
+#include "quote.h"
 
 #include "builtin.h"
 

@@ -119,6 +120,18 @@ static int handle_alias(int *argcp, cons
 			if (!strcmp(alias_command, new_argv[0]))
 				die("recursive alias: %s", alias_command);
 
+			if (getenv("GIT_TRACE")) {
+				int i;
+				fprintf(stderr, "trace: alias expansion: %s =>",
+					alias_command);
+				for (i = 0; i < count; ++i) {
+					fputc(' ', stderr);
+					sq_quote_print(stderr, new_argv[i]);
+				}
+				fputc('\n', stderr);
+				fflush(stderr);
+			}
+
 			/* insert after command name */
 			if (*argcp > 1) {
 				new_argv = realloc(new_argv, sizeof(char*) *

@@ -198,6 +211,18 @@ static void handle_internal_command(int 
 		struct cmd_struct *p = commands+i;
 		if (strcmp(p->cmd, cmd))
 			continue;
+
+		if (getenv("GIT_TRACE")) {
+			int i;
+			fprintf(stderr, "trace: built-in: git");
+			for (i = 0; i < argc; ++i) {
+				fputc(' ', stderr);
+				sq_quote_print(stderr, argv[i]);
+			}
+			putc('\n', stderr);
+			fflush(stderr);
+		}
+
 		exit(p->fn(argc, argv, envp));
 	}
 }

diff --git a/quote.c b/quote.c
index dcc2326..2ca18e8 100644
--- a/quote.c
+++ b/quote.c

@@ -45,6 +45,23 @@ size_t sq_quote_buf(char *dst, size_t n,
 	return len;
 }
 
+void sq_quote_print(FILE *stream, const char *src)
+{
+	char c;
+
+	fputc('\'', stream);
+	while ((c = *src++)) {
+		if (need_bs_quote(c)) {
+			fputs("'\\", stream);
+			fputc(c, stream);
+			fputc('\'', stream);
+		} else {
+			fputc(c, stream);
+		}
+	}
+	fputc('\'', stream);
+}
+
 char *sq_quote(const char *src)
 {
 	char *buf;

diff --git a/quote.h b/quote.h
index c1ab378..fc5481e 100644
--- a/quote.h
+++ b/quote.h

@@ -29,6 +29,7 @@ #include <stdio.h>
  */
 
 extern char *sq_quote(const char *src);
+extern void sq_quote_print(FILE *stream, const char *src);
 extern size_t sq_quote_buf(char *dst, size_t n, const char *src);
 
 /* This unwraps what sq_quote() produces in place, but returns

-- 
1.4.1.rc1.gfa6c9-dirty

Hi,

On Sun, 25 Jun 2006, Matthias Lederhofer wrote:

With the environment variable GIT_TRACE set git will show
 - alias expansion
 - built-in command execution
 - external command execution
on stderr.

Nice.

Ciao,
Dscho

P.S.: Now we only have to convert all "git-" invocations in the scripts to
"git " invocations so we can benefit from it. But that would mean two 
forks instead of one for the non-builtins. Hmm.

  Hi,

Dear diary, on Sun, Jun 25, 2006 at 04:11:48PM CEST, I got a letter
where Johannes Schindelin [off-list ref] said that...

P.S.: Now we only have to convert all "git-" invocations in the scripts to
"git " invocations so we can benefit from it. But that would mean two 
forks instead of one for the non-builtins. Hmm.

  actually this is a myth - not two fork()s since 'git' has no reason to
fork; only two execve()s in line after a single fork().

-- 
				Petr "Pasky" Baudis
Stuff: http://pasky.or.cz/
A person is just about as big as the things that make them angry.

Hi,

On Sun, 25 Jun 2006, Matthias Lederhofer wrote:

quoted

With the environment variable GIT_TRACE set git will show
 - alias expansion
 - built-in command execution
 - external command execution
on stderr.

Nice.

Thanks :)

P.S.: Now we only have to convert all "git-" invocations in the scripts to
"git " invocations so we can benefit from it. But that would mean two 
forks instead of one for the non-builtins. Hmm.

Why do we not use this policy:

git-* is guaranteed to be the normal command without any strange alias
expansion, default parameters or something else a script does not like
to be changed in the commands. So all scripts use git-*, this will
prevent a double exec. The path to git-* should be obtained using git
--exec-path in the beginnig.

git <command> is to be used by the user if he wants aliases, default
parameters and other fancy stuff.

Using this policy the user can always get the normal behaviour and it
is possible to shadown built-in commands etc.

Hi,

On Sun, 25 Jun 2006, Matthias Lederhofer wrote:

quoted

P.S.: Now we only have to convert all "git-" invocations in the scripts to
"git " invocations so we can benefit from it. But that would mean two 
forks instead of one for the non-builtins. Hmm.

Why do we not use this policy:

git-* is guaranteed to be the normal command without any strange alias
expansion, default parameters or something else a script does not like
to be changed in the commands. So all scripts use git-*, this will
prevent a double exec. The path to git-* should be obtained using git
--exec-path in the beginnig.

That still leaves my problem: GIT_TRACE=1 on scripts is incomplete.

Ciao,
Dscho

That still leaves my problem: GIT_TRACE=1 on scripts is incomplete.

Ok, I see what you mean.

This actually affects all scripts which are called as git-foo instead
of git foo (but built-in commands show up anyway). So I'd add a
warning to the documentation in which cases GIT_TRACE will not show
that a command is executed.
In the git repository I found 47 shell scripts (git-* without the
header file) which would be affected. Searching for all occurences of
git-(one of those shell-scripts) I found 50 lines of code which use
it. If there is any interest in changing this I can try to change
this.

Junio C Hamano wrote:

By the way "git cat-file -p" or "git verify-tag -v" might be
more pleasant to view a tag since they make the tagger timestamp
human readable.

Interesting, -p makes tagger timestamp human readable, but not author or
commiter:

$ git cat-file -p `cat .git/refs/tags/v1.4.0`
tagger Junio C Hamano [off-list ref] Sat Jun 10 12:43:37 2006 -0700

$ git cat-file -p `cat .git/refs/heads/origin`
author Johannes Schindelin [off-list ref] 1151491527 +0200
committer Junio C Hamano [off-list ref] 1151492136 -0700

Is it intended, or a bug/missing feature (git 1.4.0)?

-- 
Jakub Narebski
Warsaw, Poland
ShadeHawk on #git