logtoprocess: drop support for ui.log() call with invalid msg arguments (BC)

logtoprocess: drop support for ui.log() call with invalid msg arguments (BC)

Before, the logtoprocess extension put a formatted message into $MSG1, and
its arguments to $MSG2... If the specified arguments couldn't be formatted
because of a caller bug, an unformatted message was passed in to $MSG1
instead of exploding. This behavior doesn't make sense.

Since I'm planning to formalize the ui.log() interface such that we'll no
longer have to extend the ui class, I want to remove any features not
conforming to the ui.log() API. So this patch removes the support for
ill-formed arguments, and $MSG{n} (where n > 1) parameters which seems
useless as long as the message can be formatted. The $MSG1 variable isn't
renamed for the maximum compatibility.

In future patches, a formatted msg will be passed to a processlogger object,
instead of overriding the ui.log() function.

.. bc::

   The logtoprocess extension no longer supports invalid ``ui.log()``
   arguments. A log message is always formatted and passed in to the
   ``$MSG1`` environment variable.

--- a/hgext/logtoprocess.py	Sun Nov 11 12:35:38 2018 +0900
+++ b/hgext/logtoprocess.py	Sun Nov 11 12:55:58 2018 +0900
@@ -9,21 +9,21 @@
 This extension lets you specify a shell command per ui.log() event,
 sending all remaining arguments to as environment variables to that command.
 
-Each positional argument to the method results in a `MSG[N]` key in the
-environment, starting at 1 (so `MSG1`, `MSG2`, etc.). Each keyword argument
-is set as a `OPT_UPPERCASE_KEY` variable (so the key is uppercased, and
-prefixed with `OPT_`). The original event name is passed in the `EVENT`
-environment variable, and the process ID of mercurial is given in `HGPID`.
+Positional arguments construct a log message, which is passed in the `MSG1`
+environment variables. Each keyword argument is set as a `OPT_UPPERCASE_KEY`
+variable (so the key is uppercased, and prefixed with `OPT_`). The original
+event name is passed in the `EVENT` environment variable, and the process ID
+of mercurial is given in `HGPID`.
 
-So given a call `ui.log('foo', 'bar', 'baz', spam='eggs'), a script configured
-for the `foo` event can expect an environment with `MSG1=bar`, `MSG2=baz`, and
-`OPT_SPAM=eggs`.
+So given a call `ui.log('foo', 'bar %s\n', 'baz', spam='eggs'), a script
+configured for the `foo` event can expect an environment with `MSG1=bar baz`,
+and `OPT_SPAM=eggs`.
 
 Scripts are configured in the `[logtoprocess]` section, each key an event name.
 For example::
 
   [logtoprocess]
-  commandexception = echo "$MSG2$MSG3" > /var/log/mercurial_exceptions.log
+  commandexception = echo "$MSG1" > /var/log/mercurial_exceptions.log
 
 would log the warning message and traceback of any failed command dispatch.
 
@@ -60,25 +60,11 @@
             """
             script = self.config('logtoprocess', event)
             if script:
-                if msg:
-                    # try to format the log message given the remaining
-                    # arguments
-                    try:
-                        # Format the message as blackbox does
-                        formatted = msg[0] % msg[1:]
-                    except (TypeError, KeyError):
-                        # Failed to apply the arguments, ignore
-                        formatted = msg[0]
-                    messages = (formatted,) + msg[1:]
-                else:
-                    messages = msg
                 env = {
                     b'EVENT': event,
                     b'HGPID': os.getpid(),
+                    b'MSG1': msg[0] % msg[1:],
                 }
-                # positional arguments are listed as MSG[N] keys in the
-                # environment
-                env.update((b'MSG%d' % i, m) for i, m in enumerate(messages, 1))
                 # keyword arguments get prefixed with OPT_ and uppercased
                 env.update((b'OPT_%s' % key.upper(), value)
                            for key, value in pycompat.byteskwargs(opts).items())

--- a/tests/test-logtoprocess.t	Sun Nov 11 12:35:38 2018 +0900
+++ b/tests/test-logtoprocess.t	Sun Nov 11 12:55:58 2018 +0900
@@ -29,18 +29,14 @@
   > [logtoprocess]
   > command=(echo 'logtoprocess command output:';
   >     echo "\$EVENT";
-  >     echo "\$MSG1";
-  >     echo "\$MSG2") > $TESTTMP/command.log
+  >     echo "\$MSG1") > $TESTTMP/command.log
   > commandfinish=(echo 'logtoprocess commandfinish output:';
   >     echo "\$EVENT";
   >     echo "\$MSG1";
-  >     echo "\$MSG2";
-  >     echo "\$MSG3";
   >     echo "canonical: \$OPT_CANONICAL_COMMAND") > $TESTTMP/commandfinish.log
   > foo=(echo 'logtoprocess foo output:';
   >     echo "\$EVENT";
-  >     echo "\$MSG1";
-  >     echo "\$MSG2") > $TESTTMP/foo.log
+  >     echo "\$MSG1") > $TESTTMP/foo.log
   > EOF
 
 Running a command triggers both a ui.log('command') and a
@@ -53,16 +49,13 @@
   
   command
   fooba
-  fooba
   logtoprocess command output:
 
 #if no-chg
   $ cat $TESTTMP/commandfinish.log | sort
   
-  0
   canonical: foobar
   commandfinish
-  fooba
   fooba exited 0 after * seconds (glob)
   logtoprocess commandfinish output:
   $ cat $TESTTMP/foo.log | sort
@@ -70,7 +63,6 @@
   a message: spam
   foo
   logtoprocess foo output:
-  spam
 #endif
 
 Confirm that logging blocked time catches stdio properly: