GIT_TRACE doesn't show content filter files it's operating on

Hello,

I'm debugging the workings of a configured git content filter (nbstripout) and I'm trying to get GIT_TRACE to show me the files it's operating on, but it doesn't. Consider:

$ GIT_TRACE=1 git pull origin master [...] removed irrelevant sections of the output 16:49:28.846707 run-command.c:640 trace: run_command: git merge FETCH_HEAD 16:49:28.849309 git.c:344 trace: built-in: git merge FETCH_HEAD Updating 1ea49ad..ae0ba93 16:49:28.863291 run-command.c:640 trace: run_command: nbstripout 16:49:28.864700 run-command.c:640 trace: run_command: nbstripout 16:49:28.866060 run-command.c:640 trace: run_command: nbstripout [...] many more of the same

How can I get GIT_TRACE's run_command to show the arguments passed to the filter? I looked at various other debug environment variables in git's manual, but I don't see anything that would enable that level of debug.

I'm aware of git check-attr, but I'd like to see the run time trace on which files it's running the filter on and with which arguments.

git version 2.17.1

I originally posted this as a question here: <https://stackoverflow.com/questions/51995773/getting-git-to-show-specific-filenames-it-is-running-content-filters-on> and it appears that sq_quote_argv_pretty() doesn't get argv when a content filter is invoked, so it doesn't show this information.

Would it be possible to make the files and any other passed arguments show in the trace?

Thank you.

On Mon, Aug 27, 2018 at 04:23:34PM -0700, Stas Bekman wrote:

GIT_TRACE should always show the arguments. But unless you specify arguments in the clean/smudge filter config, then Git won't pass any. The stdin/stdout stream is all that matters.

So e.g.:

  $ echo '* filter=foo' >.gitattributes
  $ git config filter.foo.clean 'myfilter'
  $ GIT_TRACE=1 git add .
  19:42:16.516401 [pid=14112] git.c:415             trace: built-in: git add .
  19:42:16.517454 [pid=14112] run-command.c:637     trace: run_command: myfilter

  $ git config filter.foo.clean 'myfilter --foo'
  $ touch .gitattributes ;# make sure we actually read it again ;)
  $ GIT_TRACE=1 git add .
  19:42:58.122942 [pid=14156] git.c:415             trace: built-in: git add .
  19:42:58.124023 [pid=14156] run-command.c:637     trace: run_command: 'myfilter --foo'

You can use "%f" to pass the name of the file, like:

  $ git config filter.foo.clean 'myfilter %f'
  $ touch .gitattributes
  $ GIT_TRACE=1 git add .
  19:44:51.187177 [pid=14318] git.c:415             trace: built-in: git add .
  19:44:51.188256 [pid=14318] run-command.c:637     trace: run_command: 'myfilter '\''.gitattributes'\'''

Of course that won't be helpful if your filter actually respects the argument. For a "clean" filter that might be OK (e.g., if it just tells your filter to read from the filesystem instead of stdin), but it's almost certainly not what you want for a "smudge" filter.

You can work around it with some shell hackery:

  git config filter.foo.clean 'f() { echo >&2 "cleaning $1"; myfilter ...; }; f %f'

and then even without GIT_TRACE, you get:

  $ git add .
  cleaning .gitattributes

Or if you really just want to trigger for GIT_TRACE, try just this:

  $ git config filter.foo.clean 'f() { myfilter; }; f %f'
  19:52:52.874064 [pid=14719] git.c:415             trace: built-in: git add .
  19:52:52.875115 [pid=14719] run-command.c:637     trace: run_command: 'f() { myfilter; }; f '\''.gitattributes'\'''

There you get the name in the trace output, but the invoked command doesn't actually do anything with it.

-Peff

On 2018-08-27 04:53 PM, Jeff King wrote:

[...]

[...]

Your suggestions do the trick, Jeff. Thank you.

1. To benefit others who might be looking for something similar may I
post your suggestions as an answer to:
<https://stackoverflow.com/questions/51995773/getting-git-to-show-specific-filenames-it-is-running-content-filters-on>?

2. Is there no way to get git to do the filename reporting as a normal
GIT_TRACE behavior? I don't know anything about its internal workings,
but it surely must knows which file it operates on when it opens it and
sends its data as stdin to the content filter. It makes the debugging so
much easier when one can see what files are being worked on. So perhaps
this utility can be made available to all not just as a hack/workaround.

On Mon, Aug 27, 2018 at 05:22:13PM -0700, Stas Bekman wrote:

Great, thanks.

No, because GIT_TRACE itself only reports on the execution of commands and sub-processes. There are other GIT_TRACE_* variables for various subsystems, but AFAIK nobody has instrumented the smudge/clean filter code. IMHO it would be reasonable to have a GIT_TRACE_CONVERT that covered convert.c (so these filters, but also newline conversion, etc).

-Peff

On 2018-08-27 05:58 PM, Jeff King wrote: [...]

Thank you, Jeff.

Would you please add this to the TODO list (if that's how new feature requests are made)?

I now know how get the filenames for "clean/smudge" filters. Can you please help with the same for "textconv". %f doesn't work - it gets stuck there waiting for stdin, the following seems to pass, but I'm not sure it's correct:

[diff "ipynb-code"]
	textconv = "f() { echo >&2 \"textconv: nbstripout -t $*\"; nbstripout
-t; }; cat $1 > f"

In a trace (git diff w/ one modified file) it gets invoked twice:

18:05:27.640955 run-command.c:640       trace: run_command: 'f() { echo

/tmp/4nCYaT_004_callbacks.ipynb 18:05:27.642205 run-command.c:640 trace: run_command: 'f() { echo

dev_nb/004_callbacks.ipynb

The first trace gives a tmp filename, whereas I need the actual filename.

Thank you.

On 2018-08-27 06:13 PM, Stas Bekman wrote: [...]

On a closer look this is not needed for "textconv" as it already logs the filename in the GIT_TRACE=1 trace.

I have no more remaining questions, Thank you for your help, Jeff.