# HG changeset patch # User Simon Farnsworth <simon...@fb.com> # Date 1486676409 28800 # Thu Feb 09 13:40:09 2017 -0800 # Node ID be7dac985b12af413b43fa9685e29a90f80de4ef # Parent ec1dac3c0d5fc7d0d15af324b345958a41000960 ui: log time spent blocked on stdio
We use a wrapper around Mercurial at Facebook that logs key statistics (like elpased time) to our standard performance tooling. This is less useful than it could be, because we currently can't tell when a command is slow because we need to fix Mercurial versus when a command is slow because the user isn't interacting quickly. Teach Mercurial to log the time it spends blocked, so that our tooling can pick it up and submit it with the elapsed time - we can then do the math in our tooling to see if Mercurial is slow, or if the user simply failed to interact. Combining this with the command duration log means that we can ensure that we concentrate performance efforts on the things that bite Facebook users. diff --git a/mercurial/ui.py b/mercurial/ui.py --- a/mercurial/ui.py +++ b/mercurial/ui.py @@ -728,31 +728,34 @@ self._buffers[-1].extend(a for a in args) else: self._progclear() - for a in args: - self.fout.write(a) + with self.timeblockedsection('stdio'): + for a in args: + self.fout.write(a) def write_err(self, *args, **opts): self._progclear() try: if self._bufferstates and self._bufferstates[-1][0]: return self.write(*args, **opts) - if not getattr(self.fout, 'closed', False): - self.fout.flush() - for a in args: - self.ferr.write(a) - # stderr may be buffered under win32 when redirected to files, - # including stdout. - if not getattr(self.ferr, 'closed', False): - self.ferr.flush() + with self.timeblockedsection('stdio'): + if not getattr(self.fout, 'closed', False): + self.fout.flush() + for a in args: + self.ferr.write(a) + # stderr may be buffered under win32 when redirected to files, + # including stdout. + if not getattr(self.ferr, 'closed', False): + self.ferr.flush() except IOError as inst: if inst.errno not in (errno.EPIPE, errno.EIO, errno.EBADF): raise def flush(self): - try: self.fout.flush() - except (IOError, ValueError): pass - try: self.ferr.flush() - except (IOError, ValueError): pass + with self.timeblockedsection('stdio'): + try: self.fout.flush() + except (IOError, ValueError): pass + try: self.ferr.flush() + except (IOError, ValueError): pass def _isatty(self, fh): if self.configbool('ui', 'nontty', False): @@ -914,7 +917,8 @@ sys.stdout = self.fout # prompt ' ' must exist; otherwise readline may delete entire line # - http://bugs.python.org/issue12833 - line = raw_input(' ') + with self.timeblockedsection('stdio'): + line = raw_input(' ') sys.stdin = oldin sys.stdout = oldout @@ -994,13 +998,14 @@ self.write_err(self.label(prompt or _('password: '), 'ui.prompt')) # disable getpass() only if explicitly specified. it's still valid # to interact with tty even if fin is not a tty. - if self.configbool('ui', 'nontty'): - l = self.fin.readline() - if not l: - raise EOFError - return l.rstrip('\n') - else: - return getpass.getpass('') + with self.timeblockedsection('stdio'): + if self.configbool('ui', 'nontty'): + l = self.fin.readline() + if not l: + raise EOFError + return l.rstrip('\n') + else: + return getpass.getpass('') except EOFError: raise error.ResponseExpected() def status(self, *msg, **opts): _______________________________________________ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel