Patchwork blackbox: also log alias expansions

login
register
mail settings
Submitter Augie Fackler
Date Aug. 23, 2016, 8:53 p.m.
Message ID <b3c025f053ec7573bea3.1471985627@arthedain.pit.corp.google.com>
Download mbox | patch
Permalink /patch/16396/
State Superseded
Headers show

Comments

Augie Fackler - Aug. 23, 2016, 8:53 p.m.
# HG changeset patch
# User Augie Fackler <augie@google.com>
# Date 1471984808 14400
#      Tue Aug 23 16:40:08 2016 -0400
# Node ID b3c025f053ec7573bea30e8b9482d7e2c57caf7b
# Parent  92ac2baaea86dbba8565c359206fb97d39ec6e63
blackbox: also log alias expansions

This should be extremely useful for helping users debug without having
to see their complete configuration.

Shell aliases appear to not be logged at all, which I find confusing,
but I haven't taken the time to debug in any detail.
Yuya Nishihara - Aug. 24, 2016, 2:01 p.m.
On Tue, 23 Aug 2016 16:53:47 -0400, Augie Fackler wrote:
> # HG changeset patch
> # User Augie Fackler <augie@google.com>
> # Date 1471984808 14400
> #      Tue Aug 23 16:40:08 2016 -0400
> # Node ID b3c025f053ec7573bea30e8b9482d7e2c57caf7b
> # Parent  92ac2baaea86dbba8565c359206fb97d39ec6e63
> blackbox: also log alias expansions
> 
> This should be extremely useful for helping users debug without having
> to see their complete configuration.
> 
> Shell aliases appear to not be logged at all, which I find confusing,
> but I haven't taken the time to debug in any detail.

Shell aliases are handled prior to parsing command options in _dispatch().

> --- a/mercurial/dispatch.py
> +++ b/mercurial/dispatch.py
> @@ -889,6 +889,9 @@ def _dispatch(req):
>  
>      msg = ' '.join(' ' in a and repr(a) or a for a in fullargs)
>      ui.log("command", '%s\n', msg)
> +    if isinstance(func, cmdalias):

Can we move this to cmdalias.__call__() where exactly the same debug message
exists?

> +        ui.log('commandalias',  "alias '%s' expands to '%s %s'\n" % (
> +            func.name, func.cmdname, ' '.join(func.givenargs)))

%s shouldn't be expanded by the caller, which is done by ui.log().
Augie Fackler - Aug. 25, 2016, 4:50 a.m.
> On Aug 24, 2016, at 10:01 AM, Yuya Nishihara <yuya@tcha.org> wrote:
> 
> On Tue, 23 Aug 2016 16:53:47 -0400, Augie Fackler wrote:
>> # HG changeset patch
>> # User Augie Fackler <augie@google.com>
>> # Date 1471984808 14400
>> #      Tue Aug 23 16:40:08 2016 -0400
>> # Node ID b3c025f053ec7573bea30e8b9482d7e2c57caf7b
>> # Parent  92ac2baaea86dbba8565c359206fb97d39ec6e63
>> blackbox: also log alias expansions
>> 
>> This should be extremely useful for helping users debug without having
>> to see their complete configuration.
>> 
>> Shell aliases appear to not be logged at all, which I find confusing,
>> but I haven't taken the time to debug in any detail.
> 
> Shell aliases are handled prior to parsing command options in _dispatch().

I think it’s worse than that: we don’t look for a repo to associate with the command until after shell aliases are already executed.

> 
>> --- a/mercurial/dispatch.py
>> +++ b/mercurial/dispatch.py
>> @@ -889,6 +889,9 @@ def _dispatch(req):
>> 
>>     msg = ' '.join(' ' in a and repr(a) or a for a in fullargs)
>>     ui.log("command", '%s\n', msg)
>> +    if isinstance(func, cmdalias):
> 
> Can we move this to cmdalias.__call__() where exactly the same debug message
> exists?

Done.

> 
>> +        ui.log('commandalias',  "alias '%s' expands to '%s %s'\n" % (
>> +            func.name, func.cmdname, ' '.join(func.givenargs)))
> 
> %s shouldn't be expanded by the caller, which is done by ui.log().

Oh nice, I didn’t know that.

Patch

diff --git a/mercurial/dispatch.py b/mercurial/dispatch.py
--- a/mercurial/dispatch.py
+++ b/mercurial/dispatch.py
@@ -889,6 +889,9 @@  def _dispatch(req):
 
     msg = ' '.join(' ' in a and repr(a) or a for a in fullargs)
     ui.log("command", '%s\n', msg)
+    if isinstance(func, cmdalias):
+        ui.log('commandalias',  "alias '%s' expands to '%s %s'\n" % (
+            func.name, func.cmdname, ' '.join(func.givenargs)))
     d = lambda: util.checksignature(func)(ui, *args, **cmdoptions)
     try:
         return runcommand(lui, repo, cmd, fullargs, ui, options, d,
diff --git a/tests/test-blackbox.t b/tests/test-blackbox.t
--- a/tests/test-blackbox.t
+++ b/tests/test-blackbox.t
@@ -4,6 +4,8 @@  setup
   > blackbox=
   > mock=$TESTDIR/mockblackbox.py
   > mq=
+  > [alias]
+  > confuse = log --limit 3
   > EOF
   $ hg init blackboxtest
   $ cd blackboxtest
@@ -17,6 +19,18 @@  command, exit codes, and duration
   1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a exited 0 after * seconds (glob)
   1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000+ (5000)> blackbox
 
+alias expansion is logged
+  $ hg confuse
+  $ hg blackbox
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> add a exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000+ (5000)> blackbox
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000+ (5000)> blackbox --config blackbox.dirty=True exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> confuse
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3'
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> confuse exited 0 after * seconds (glob)
+  1970/01/01 00:00:00 bob @0000000000000000000000000000000000000000 (5000)> blackbox
+
 incoming change tracking
 
 create two heads to verify that we only see one change in the log later