From affec78d17e4c4bfe19f8510ba9a73dc42bf82b3 Mon Sep 17 00:00:00 2001 From: Martijn Pieters Date: Mon, 4 Apr 2016 15:56:15 +0100 Subject: [PATCH] logtoprocess: execute processes asynchronously Summary: Create a Popen() object, and each time ui.log() is called poll these to clear out any that are done. When dispatch ends, kill any that remain. Test Plan: Run $HG/tests/run-tests.py test-logtoprocess.t Reviewers: durham, #sourcecontrol, ttung, quark Reviewed By: quark Subscribers: ikostia, simonfar, mjpieters Differential Revision: https://phabricator.fb.com/D3091363 Signature: t1:3091363:1459781710:4f04e37db3fb1f81abadfe168c5dbc00c376cda7 --- logtoprocess.py | 54 ++++++++++++++++++++++++++++++++++----- tests/test-logtoprocess.t | 30 ++++++++++++++-------- 2 files changed, 67 insertions(+), 17 deletions(-) diff --git a/logtoprocess.py b/logtoprocess.py index fa71427b80..31bed10e4f 100644 --- a/logtoprocess.py +++ b/logtoprocess.py @@ -11,8 +11,9 @@ 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` argument (so the key is uppercased, and -prefixed with `OPT_`). +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 @@ -26,17 +27,55 @@ For example:: would log the warning message and traceback of any failed command dispatch. -Scripts are run sychronously; they should exit ASAP. Preferably the command -should fork and disown to avoid slowing mercurial down. +Scripts are run asychronously as detached daemon processes; mercurial will +not ensure that they exit cleanly. """ import os +import platform import subprocess +import sys from itertools import chain def uisetup(ui): + if platform.system() == 'Windows': + # no fork on Windows, but we can create a detached process + # https://msdn.microsoft.com/en-us/library/windows/desktop/ms684863(v=vs.85).aspx + # No stdlib constant exists for this value + DETACHED_PROCESS = 0x00000008 + _creationflags = DETACHED_PROCESS | subprocess.CREATE_NEW_PROCESS_GROUP + + def runshellcommand(script, env): + # we can't use close_fds *and* redirect stdin. I'm not sure that we + # need to because the detached process has no console connection. + subprocess.Popen( + script, shell=True, env=env, close_fds=True, + creationflags=_creationflags) + else: + def runshellcommand(script, env): + # double-fork to completely detach from the parent process + # based on http://code.activestate.com/recipes/278731 + pid = os.fork() + if pid: + # parent + return + # subprocess.Popen() forks again, all we need to add is + # flag the new process as a new session. + if sys.version_info < (3, 2): + newsession = {'preexec_fn': os.setsid} + else: + newsession = {'start_new_session': True} + # connect stdin to devnull to make sure the subprocess can't + # muck up that stream for mercurial. + subprocess.Popen( + script, shell=True, stdin=open(os.devnull, 'r'), env=env, + close_fds=True, **newsession) + # mission accomplished, this child needs to exit and not + # continue the hg process here. + os._exit(0) + class logtoprocessui(ui.__class__): def log(self, event, *msg, **opts): """Map log events to external commands @@ -69,8 +108,11 @@ def uisetup(ui): optpairs = ( ('OPT_{0}'.format(key.upper()), str(value)) for key, value in opts.iteritems()) - env = dict(chain(os.environ.items(), msgpairs, optpairs)) - subprocess.call(script, shell=True, env=env) + env = dict(chain(os.environ.items(), msgpairs, optpairs), + EVENT=event, HGPID=str(os.getpid())) + # Connect stdin to /dev/null to prevent child processes messing + # with mercurial's stdin. + runshellcommand(script, env) return super(logtoprocessui, self).log(event, *msg, **opts) # Replace the class for this instance and all clones created from it: diff --git a/tests/test-logtoprocess.t b/tests/test-logtoprocess.t index aeaf833256..b389bcc2ca 100644 --- a/tests/test-logtoprocess.t +++ b/tests/test-logtoprocess.t @@ -18,31 +18,39 @@ Test if logtoprocess correctly captures command-related log calls. > foocommand=$TESTTMP/foocommand.py > [logtoprocess] > command=echo 'logtoprocess command output:'; + > echo "\$EVENT"; > echo "\$MSG1"; > echo "\$MSG2" > commandfinish=echo 'logtoprocess commandfinish output:'; + > echo "\$EVENT"; > echo "\$MSG1"; > echo "\$MSG2"; > echo "\$MSG3" > foo=echo 'logtoprocess foo output:'; + > echo "\$EVENT"; > echo "\$MSG1"; > echo "\$OPT_BAR" > EOF Running a command triggers both a ui.log('command') and a -ui.log('commandfinish') call. The foo command also uses ui.log: +ui.log('commandfinish') call. The foo command also uses ui.log. - $ hg foo - logtoprocess command output: - foo +Use head to ensure we wait for all lines to be produced, and sort to avoid +ordering issues between the various processes we spawn: + $ hg foo | head -n 17 | sort - foo - logtoprocess foo output: - a message: spam - spam - logtoprocess commandfinish output: - foo exited 0 after * seconds (glob) - foo 0 + a message: spam + command + commandfinish + foo + foo + foo + foo + foo exited 0 after * seconds (glob) + logtoprocess command output: + logtoprocess commandfinish output: + logtoprocess foo output: + spam