Mercurial > hg-stable
changeset 39283:4019b4542e61
dispatch: have dispatch.dispatch and dispatch._runcatch emit trace events
Differential Revision: https://phab.mercurial-scm.org/D4345
| author | Augie Fackler <augie@google.com> |
|---|---|
| date | Tue, 21 Aug 2018 15:25:07 -0400 |
| parents | 284440041141 |
| children | 574e1d3bc667 |
| files | mercurial/dispatch.py |
| diffstat | 1 files changed, 167 insertions(+), 162 deletions(-) [+] |
line wrap: on
line diff
--- a/mercurial/dispatch.py Tue Aug 21 15:24:20 2018 -0400 +++ b/mercurial/dispatch.py Tue Aug 21 15:25:07 2018 -0400 @@ -21,6 +21,8 @@ from .i18n import _ +from hgdemandimport import tracing + from . import ( cmdutil, color, @@ -84,7 +86,8 @@ def run(): "run the command in sys.argv" initstdio() - req = request(pycompat.sysargv[1:]) + with tracing.log('parse args into request'): + req = request(pycompat.sysargv[1:]) err = None try: status = dispatch(req) @@ -176,182 +179,184 @@ def dispatch(req): """run the command specified in req.args; returns an integer status code""" - if req.ferr: - ferr = req.ferr - elif req.ui: - ferr = req.ui.ferr - else: - ferr = procutil.stderr + with tracing.log('dispatch.dispatch'): + if req.ferr: + ferr = req.ferr + elif req.ui: + ferr = req.ui.ferr + else: + ferr = procutil.stderr - try: - if not req.ui: - req.ui = uimod.ui.load() - req.earlyoptions.update(_earlyparseopts(req.ui, req.args)) - if req.earlyoptions['traceback']: - req.ui.setconfig('ui', 'traceback', 'on', '--traceback') + try: + if not req.ui: + req.ui = uimod.ui.load() + req.earlyoptions.update(_earlyparseopts(req.ui, req.args)) + if req.earlyoptions['traceback']: + req.ui.setconfig('ui', 'traceback', 'on', '--traceback') - # set ui streams from the request - if req.fin: - req.ui.fin = req.fin - if req.fout: - req.ui.fout = req.fout - if req.ferr: - req.ui.ferr = req.ferr - except error.Abort as inst: - ferr.write(_("abort: %s\n") % inst) - if inst.hint: - ferr.write(_("(%s)\n") % inst.hint) - return -1 - except error.ParseError as inst: - _formatparse(ferr.write, inst) - return -1 + # set ui streams from the request + if req.fin: + req.ui.fin = req.fin + if req.fout: + req.ui.fout = req.fout + if req.ferr: + req.ui.ferr = req.ferr + except error.Abort as inst: + ferr.write(_("abort: %s\n") % inst) + if inst.hint: + ferr.write(_("(%s)\n") % inst.hint) + return -1 + except error.ParseError as inst: + _formatparse(ferr.write, inst) + return -1 - msg = _formatargs(req.args) - starttime = util.timer() - ret = 1 # default of Python exit code on unhandled exception - try: - ret = _runcatch(req) or 0 - except error.ProgrammingError as inst: - req.ui.error(_('** ProgrammingError: %s\n') % inst) - if inst.hint: - req.ui.error(_('** (%s)\n') % inst.hint) - raise - except KeyboardInterrupt as inst: + msg = _formatargs(req.args) + starttime = util.timer() + ret = 1 # default of Python exit code on unhandled exception try: - if isinstance(inst, error.SignalInterrupt): - msg = _("killed!\n") - else: - msg = _("interrupted!\n") - req.ui.error(msg) - except error.SignalInterrupt: - # maybe pager would quit without consuming all the output, and - # SIGPIPE was raised. we cannot print anything in this case. - pass - except IOError as inst: - if inst.errno != errno.EPIPE: - raise - ret = -1 - finally: - duration = util.timer() - starttime - req.ui.flush() - if req.ui.logblockedtimes: - req.ui._blockedtimes['command_duration'] = duration * 1000 - req.ui.log('uiblocked', 'ui blocked ms', - **pycompat.strkwargs(req.ui._blockedtimes)) - req.ui.log("commandfinish", "%s exited %d after %0.2f seconds\n", - msg, ret & 255, duration) - try: - req._runexithandlers() - except: # exiting, so no re-raises - ret = ret or -1 - return ret + ret = _runcatch(req) or 0 + except error.ProgrammingError as inst: + req.ui.error(_('** ProgrammingError: %s\n') % inst) + if inst.hint: + req.ui.error(_('** (%s)\n') % inst.hint) + raise + except KeyboardInterrupt as inst: + try: + if isinstance(inst, error.SignalInterrupt): + msg = _("killed!\n") + else: + msg = _("interrupted!\n") + req.ui.error(msg) + except error.SignalInterrupt: + # maybe pager would quit without consuming all the output, and + # SIGPIPE was raised. we cannot print anything in this case. + pass + except IOError as inst: + if inst.errno != errno.EPIPE: + raise + ret = -1 + finally: + duration = util.timer() - starttime + req.ui.flush() + if req.ui.logblockedtimes: + req.ui._blockedtimes['command_duration'] = duration * 1000 + req.ui.log('uiblocked', 'ui blocked ms', + **pycompat.strkwargs(req.ui._blockedtimes)) + req.ui.log("commandfinish", "%s exited %d after %0.2f seconds\n", + msg, ret & 255, duration) + try: + req._runexithandlers() + except: # exiting, so no re-raises + ret = ret or -1 + return ret def _runcatch(req): - def catchterm(*args): - raise error.SignalInterrupt + with tracing.log('dispatch._runcatch'): + def catchterm(*args): + raise error.SignalInterrupt - ui = req.ui - try: - for name in 'SIGBREAK', 'SIGHUP', 'SIGTERM': - num = getattr(signal, name, None) - if num: - signal.signal(num, catchterm) - except ValueError: - pass # happens if called in a thread - - def _runcatchfunc(): - realcmd = None + ui = req.ui try: - cmdargs = fancyopts.fancyopts(req.args[:], commands.globalopts, {}) - cmd = cmdargs[0] - aliases, entry = cmdutil.findcmd(cmd, commands.table, False) - realcmd = aliases[0] - except (error.UnknownCommand, error.AmbiguousCommand, - IndexError, getopt.GetoptError): - # Don't handle this here. We know the command is - # invalid, but all we're worried about for now is that - # it's not a command that server operators expect to - # be safe to offer to users in a sandbox. - pass - if realcmd == 'serve' and '--stdio' in cmdargs: - # We want to constrain 'hg serve --stdio' instances pretty - # closely, as many shared-ssh access tools want to grant - # access to run *only* 'hg -R $repo serve --stdio'. We - # restrict to exactly that set of arguments, and prohibit - # any repo name that starts with '--' to prevent - # shenanigans wherein a user does something like pass - # --debugger or --config=ui.debugger=1 as a repo - # name. This used to actually run the debugger. - if (len(req.args) != 4 or - req.args[0] != '-R' or - req.args[1].startswith('--') or - req.args[2] != 'serve' or - req.args[3] != '--stdio'): - raise error.Abort( - _('potentially unsafe serve --stdio invocation: %s') % - (stringutil.pprint(req.args),)) + for name in 'SIGBREAK', 'SIGHUP', 'SIGTERM': + num = getattr(signal, name, None) + if num: + signal.signal(num, catchterm) + except ValueError: + pass # happens if called in a thread - try: - debugger = 'pdb' - debugtrace = { - 'pdb': pdb.set_trace - } - debugmortem = { - 'pdb': pdb.post_mortem - } + def _runcatchfunc(): + realcmd = None + try: + cmdargs = fancyopts.fancyopts( + req.args[:], commands.globalopts, {}) + cmd = cmdargs[0] + aliases, entry = cmdutil.findcmd(cmd, commands.table, False) + realcmd = aliases[0] + except (error.UnknownCommand, error.AmbiguousCommand, + IndexError, getopt.GetoptError): + # Don't handle this here. We know the command is + # invalid, but all we're worried about for now is that + # it's not a command that server operators expect to + # be safe to offer to users in a sandbox. + pass + if realcmd == 'serve' and '--stdio' in cmdargs: + # We want to constrain 'hg serve --stdio' instances pretty + # closely, as many shared-ssh access tools want to grant + # access to run *only* 'hg -R $repo serve --stdio'. We + # restrict to exactly that set of arguments, and prohibit + # any repo name that starts with '--' to prevent + # shenanigans wherein a user does something like pass + # --debugger or --config=ui.debugger=1 as a repo + # name. This used to actually run the debugger. + if (len(req.args) != 4 or + req.args[0] != '-R' or + req.args[1].startswith('--') or + req.args[2] != 'serve' or + req.args[3] != '--stdio'): + raise error.Abort( + _('potentially unsafe serve --stdio invocation: %s') % + (stringutil.pprint(req.args),)) - # read --config before doing anything else - # (e.g. to change trust settings for reading .hg/hgrc) - cfgs = _parseconfig(req.ui, req.earlyoptions['config']) - - if req.repo: - # copy configs that were passed on the cmdline (--config) to - # the repo ui - for sec, name, val in cfgs: - req.repo.ui.setconfig(sec, name, val, source='--config') + try: + debugger = 'pdb' + debugtrace = { + 'pdb': pdb.set_trace + } + debugmortem = { + 'pdb': pdb.post_mortem + } - # developer config: ui.debugger - debugger = ui.config("ui", "debugger") - debugmod = pdb - if not debugger or ui.plain(): - # if we are in HGPLAIN mode, then disable custom debugging - debugger = 'pdb' - elif req.earlyoptions['debugger']: - # This import can be slow for fancy debuggers, so only - # do it when absolutely necessary, i.e. when actual - # debugging has been requested - with demandimport.deactivated(): - try: - debugmod = __import__(debugger) - except ImportError: - pass # Leave debugmod = pdb + # read --config before doing anything else + # (e.g. to change trust settings for reading .hg/hgrc) + cfgs = _parseconfig(req.ui, req.earlyoptions['config']) + + if req.repo: + # copy configs that were passed on the cmdline (--config) to + # the repo ui + for sec, name, val in cfgs: + req.repo.ui.setconfig(sec, name, val, source='--config') - debugtrace[debugger] = debugmod.set_trace - debugmortem[debugger] = debugmod.post_mortem + # developer config: ui.debugger + debugger = ui.config("ui", "debugger") + debugmod = pdb + if not debugger or ui.plain(): + # if we are in HGPLAIN mode, then disable custom debugging + debugger = 'pdb' + elif req.earlyoptions['debugger']: + # This import can be slow for fancy debuggers, so only + # do it when absolutely necessary, i.e. when actual + # debugging has been requested + with demandimport.deactivated(): + try: + debugmod = __import__(debugger) + except ImportError: + pass # Leave debugmod = pdb - # enter the debugger before command execution - if req.earlyoptions['debugger']: - ui.warn(_("entering debugger - " - "type c to continue starting hg or h for help\n")) + debugtrace[debugger] = debugmod.set_trace + debugmortem[debugger] = debugmod.post_mortem - if (debugger != 'pdb' and - debugtrace[debugger] == debugtrace['pdb']): - ui.warn(_("%s debugger specified " - "but its module was not found\n") % debugger) - with demandimport.deactivated(): - debugtrace[debugger]() - try: - return _dispatch(req) - finally: - ui.flush() - except: # re-raises - # enter the debugger when we hit an exception - if req.earlyoptions['debugger']: - traceback.print_exc() - debugmortem[debugger](sys.exc_info()[2]) - raise + # enter the debugger before command execution + if req.earlyoptions['debugger']: + ui.warn(_("entering debugger - " + "type c to continue starting hg or h for help\n")) - return _callcatch(ui, _runcatchfunc) + if (debugger != 'pdb' and + debugtrace[debugger] == debugtrace['pdb']): + ui.warn(_("%s debugger specified " + "but its module was not found\n") % debugger) + with demandimport.deactivated(): + debugtrace[debugger]() + try: + return _dispatch(req) + finally: + ui.flush() + except: # re-raises + # enter the debugger when we hit an exception + if req.earlyoptions['debugger']: + traceback.print_exc() + debugmortem[debugger](sys.exc_info()[2]) + raise + return _callcatch(ui, _runcatchfunc) def _callcatch(ui, func): """like scmutil.callcatch but handles more high-level exceptions about