[RFC] git --trace: trace command execution

[RFC] git --trace: trace command execution

[Matthias Lederhofer]

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.

Example:
% git repo-config alias.showtag
trace: exec: /home/matled/local/stow/git/bin/git-repo-config
alias.showtag
% 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: built-in command: git cat-file tag v1.4.1-rc1
% git showtag 'a b "c" `d` $e \f'
trace: exec: /home/matled/local/stow/git/bin/git-showtag "a b \"c\" \`d\` \$e \\f"
trace: exec failed: No such file or directory
trace: built-in command: git cat-file tag "a b \"c\" \`d\` \$e \\f"
fatal: Not a valid object name a b "c" `d` $e \f
% git cat-file tag "a b \"c\" \`d\` \$e \\f"
trace: built-in command: git cat-file tag "a b \"c\" \`d\` \$e \\f"
fatal: Not a valid object name a b "c" `d` $e \f

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.

---
 exec_cmd.c |   42 ++++++++++++++++++++++++++++++++++++++++++
 exec_cmd.h |    1 +
 git.c      |   10 ++++++++++
 3 files changed, 53 insertions(+), 0 deletions(-)

diff --git a/exec_cmd.c b/exec_cmd.c
index c1539d1..85afbf3 100644
--- a/exec_cmd.c
+++ b/exec_cmd.c
@@ -87,6 +87,16 @@ int execv_git_cmd(const char **argv)
 			break;
 		}
 
+		fprintf(stderr, "trace: exec: ");
+		print_shell_escape(stderr, git_command);
+		const char **p = argv;
+		while (*(++p)) {
+			putc(' ', stderr);
+			print_shell_escape(stderr, *p);
+		}
+		putc('\n', stderr);
+		fflush(stderr);
+
 		/* argv[0] must be the git command, but the argv array
 		 * belongs to the caller, and my be reused in
 		 * subsequent loop iterations. Save argv[0] and
@@ -98,6 +108,8 @@ int execv_git_cmd(const char **argv)
 
 		/* execve() can only ever return if it fails */
 		execve(git_command, (char **)argv, environ);
+		fprintf(stderr, "trace: exec failed: %s\n", strerror(errno));
+		fflush(stderr);
 
 		argv[0] = tmp;
 	}
@@ -128,3 +140,33 @@ int execl_git_cmd(const char *cmd,...)
 	argv[argc] = NULL;
 	return execv_git_cmd(argv);
 }
+
+void print_shell_escape(FILE *stream, const char *s)
+{
+	const char *c = s;
+	short int quote = 0;
+	while (*c) {
+		if (*c == '"' || *c == '`' || *c == '$' || *c == '\\' ||
+			isspace(*c))
+		{
+			quote = 1;
+			break;
+		}
+		++c;
+	}
+
+	if (!quote) {
+		fputs(s, stream);
+		return;
+	}
+
+	putc('"', stream);
+	c = s;
+	while (*c) {
+		if (*c == '"' || *c == '`' || *c == '$' || *c == '\\')
+			putc('\\', stream);
+		putc(*c, stream);
+		++c;
+	}
+	putc('"', stream);
+}
diff --git a/exec_cmd.h b/exec_cmd.h
index 989621f..8b237fa 100644
--- a/exec_cmd.h
+++ b/exec_cmd.h
@@ -5,6 +5,7 @@ extern void git_set_exec_path(const char
 extern const char* git_exec_path(void);
 extern int execv_git_cmd(const char **argv); /* NULL terminated */
 extern int execl_git_cmd(const char *cmd, ...);
+extern void print_shell_escape(FILE *stream, const char *s);
 
 
 #endif /* __GIT_EXEC_CMD_H_ */
diff --git a/git.c b/git.c
index 94e9a4a..361fb25 100644
--- a/git.c
+++ b/git.c
@@ -198,6 +198,16 @@ static void handle_internal_command(int 
 		struct cmd_struct *p = commands+i;
 		if (strcmp(p->cmd, cmd))
 			continue;
+
+		fprintf(stderr, "trace: built-in command: git");
+		int i;
+		for (i = 0; i < argc; ++i) {
+			putc(' ', stderr);
+			print_shell_escape(stderr, argv[i]);
+		}
+		putc('\n', stderr);
+		fflush(stderr);
+
 		exit(p->fn(argc, argv, envp));
 	}
 }
-- 
1.4.GIT

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

[Junio C Hamano]

Matthias Lederhofer <matled@gmx.net> 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?

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

[Matthias Lederhofer]

> 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"
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'.

[PATCH] GIT_TRACE: show which built-in/external commands are executed

[Matthias Lederhofer]

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 <matled@gmx.net>
---
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

Re: [PATCH] GIT_TRACE: show which built-in/external commands are executed

[Johannes Schindelin]

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.

Re: [PATCH] GIT_TRACE: show which built-in/external commands are executed

[Petr Baudis]

  Hi,

Dear diary, on Sun, Jun 25, 2006 at 04:11:48PM CEST, I got a letter
where Johannes Schindelin <Johannes.Schindelin@gmx.de> 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.

Re: [PATCH] GIT_TRACE: show which built-in/external commands are executed

[Matthias Lederhofer]

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

Re: [PATCH] GIT_TRACE: show which built-in/external commands are executed

[Johannes Schindelin]

Hi,

On Sun, 25 Jun 2006, Matthias Lederhofer wrote:

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

Re: [PATCH] GIT_TRACE: show which built-in/external commands are executed

[Matthias Lederhofer]

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

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

[Jakub Narebski]

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 <junkio@cox.net> Sat Jun 10 12:43:37 2006 -0700

$ git cat-file -p `cat .git/refs/heads/origin`
author Johannes Schindelin <Johannes.Schindelin@gmx.de> 1151491527 +0200
committer Junio C Hamano <junkio@cox.net> 1151492136 -0700

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

-- 
Jakub Narebski
Warsaw, Poland
ShadeHawk on #git