[PATCH 1 of 2] ui: track time spent reading and writing

[Bryan O'Sullivan]

# HG changeset patch
# User Bryan O'Sullivan <bryano at fb.com>
# Date 1486062596 28800
#      Thu Feb 02 11:09:56 2017 -0800
# Node ID 61c6d4a49500f37aca3a7ae58b83d43c64eaa846
# Parent  abf029200e198878a4576a87e095bd8d77d9cea9
ui: track time spent reading and writing

diff --git a/mercurial/ui.py b/mercurial/ui.py
--- a/mercurial/ui.py
+++ b/mercurial/ui.py
@@ -18,6 +18,8 @@ import sys
 import tempfile
 import traceback
 
+from time import time as _iotime
+
 from .i18n import _
 from .node import hex
 
@@ -102,6 +104,7 @@ class ui(object):
         In most cases, you should use ui.copy() to create a copy of an existing
         ui object.
         """
+        self._iotime = 0.0
         # _buffers: used for temporary capture of output
         self._buffers = []
         # 3-tuple describing how each buffer in the stack behaves.
@@ -714,31 +717,43 @@ class ui(object):
             self._buffers[-1].extend(a for a in args)
         else:
             self._progclear()
-            for a in args:
-                self.fout.write(a)
+            try:
+                starttime = _iotime()
+                for a in args:
+                    self.fout.write(a)
+            finally:
+                self._iotime += _iotime() - starttime
 
     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()
+            try:
+                starttime = _iotime()
+                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()
+            finally:
+                self._iotime += _iotime() - starttime
         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
+        try:
+            starttime = _iotime()
+            try: self.fout.flush()
+            except (IOError, ValueError): pass
+            try: self.ferr.flush()
+            except (IOError, ValueError): pass
+        finally:
+            self._iotime += _iotime() - starttime
 
     def _isatty(self, fh):
         if self.configbool('ui', 'nontty', False):
@@ -900,7 +915,11 @@ class ui(object):
         sys.stdout = self.fout
         # prompt ' ' must exist; otherwise readline may delete entire line
         # - http://bugs.python.org/issue12833
-        line = raw_input(' ')
+        try:
+            starttime = _iotime()
+            line = raw_input(' ')
+        finally:
+            self._iotime = _iotime() - starttime
         sys.stdin = oldin
         sys.stdout = oldout
 
@@ -980,13 +999,17 @@ class ui(object):
             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('')
+            try:
+                starttime = _iotime()
+                if self.configbool('ui', 'nontty'):
+                    l = self.fin.readline()
+                    if not l:
+                        raise EOFError
+                    return l.rstrip('\n')
+                else:
+                    return getpass.getpass('')
+            finally:
+                self._iotime = _iotime() - starttime
         except EOFError:
             raise error.ResponseExpected()
     def status(self, *msg, **opts):
@@ -1038,6 +1061,7 @@ class ui(object):
                                       suffix=extra['suffix'], text=True,
                                       dir=rdir)
         try:
+            starttime = _iotime()
             f = os.fdopen(fd, "w")
             f.write(text)
             f.close()
@@ -1064,6 +1088,7 @@ class ui(object):
             t = f.read()
             f.close()
         finally:
+            self._iotime += _iotime() - starttime
             os.unlink(name)
 
         return t
@@ -1075,8 +1100,12 @@ class ui(object):
         out = self.fout
         if any(s[1] for s in self._bufferstates):
             out = self
-        return util.system(cmd, environ=environ, cwd=cwd, onerr=onerr,
-                           errprefix=errprefix, out=out)
+        try:
+            starttime = _iotime()
+            return util.system(cmd, environ=environ, cwd=cwd, onerr=onerr,
+                               errprefix=errprefix, out=out)
+        finally:
+            self._iotime += _iotime() - starttime
 
     def traceback(self, exc=None, force=False):
         '''print exception traceback if traceback printing enabled or forced.
@@ -1130,7 +1159,11 @@ class ui(object):
         if '_progbar' not in vars(self): # nothing loaded yet
             return
         if self._progbar is not None and self._progbar.printed:
-            self._progbar.clear()
+            try:
+                starttime = _iotime()
+                self._progbar.clear()
+            finally:
+                self._iotime += _iotime() - starttime
 
     def progress(self, topic, pos, item="", unit="", total=None):
         '''show a progress message
@@ -1148,8 +1181,12 @@ class ui(object):
         termination.
         '''
         if self._progbar is not None:
-            self._progbar.progress(topic, pos, item=item, unit=unit,
-                                   total=total)
+            try:
+                starttime = _iotime()
+                self._progbar.progress(topic, pos, item=item, unit=unit,
+                                       total=total)
+            finally:
+                self._iotime += _iotime() - starttime
         if pos is None or not self.configbool('progress', 'debug'):
             return