[PATCH 5 of 6 v2] crecord: log blocked time waiting for curses input

[Simon Farnsworth]

# HG changeset patch
# User Simon Farnsworth <simonfar at fb.com>
# Date 1486063056 28800
#      Thu Feb 02 11:17:36 2017 -0800
# Node ID 581cb462ae6eb9ae95fdd64ec55df2b58ab6233a
# Parent  a590327ef7a47e1390bcef0eef686c40ffc4894d
crecord: log blocked time waiting for curses input

We want to know when we're blocked on user input - log it.

diff --git a/mercurial/crecord.py b/mercurial/crecord.py
--- a/mercurial/crecord.py
+++ b/mercurial/crecord.py
@@ -514,6 +514,7 @@
 
         self.ui = ui
         self.opts = {}
+        self.elapsedms = 0
 
         self.errorstr = None
         # list of all chunks
@@ -1374,29 +1375,40 @@
         except curses.error:
             pass
         helpwin.refresh()
+        if self.ui.logblockedtime:
+            helpwin = util.elapsedtimewrapper(helpwin)
         try:
             helpwin.getkey()
         except curses.error:
             pass
+        finally:
+            if self.ui.logblockedtime:
+                self.elapsedms += helpwin.elapsedms
 
     def confirmationwindow(self, windowtext):
         "display an informational window, then wait for and return a keypress."
 
         confirmwin = curses.newwin(self.yscreensize, 0, 0, 0)
+        if self.ui.logblockedtime:
+            confirmwin = util.elapsedtimewrapper(confirmwin)
         try:
-            lines = windowtext.split("\n")
-            for line in lines:
-                self.printstring(confirmwin, line, pairname="selected")
-        except curses.error:
-            pass
-        self.stdscr.refresh()
-        confirmwin.refresh()
-        try:
-            response = chr(self.stdscr.getch())
-        except ValueError:
-            response = None
+            try:
+                lines = windowtext.split("\n")
+                for line in lines:
+                    self.printstring(confirmwin, line, pairname="selected")
+            except curses.error:
+                pass
+            self.stdscr.refresh()
+            confirmwin.refresh()
+            try:
+                response = chr(self.stdscr.getch())
+            except ValueError:
+                response = None
 
-        return response
+            return response
+        finally:
+            if self.ui.logblockedtime:
+                self.elapsedms += confirmwin.elapsedms
 
     def reviewcommit(self):
         """ask for 'y' to be pressed to confirm selected. return True if
@@ -1614,6 +1626,8 @@
         origsigwinchhandler = signal.signal(signal.SIGWINCH,
                                             self.sigwinchhandler)
         self.stdscr = stdscr
+        if self.ui.logblockedtime:
+            self.stdscr = util.elapsedtimewrapper(self.stdscr)
         # error during initialization, cannot be printed in the curses
         # interface, it should be printed by the calling code
         self.initerr = None
@@ -1632,6 +1646,8 @@
         self.initcolorpair(curses.COLOR_WHITE, curses.COLOR_BLUE, name="legend")
         # newwin([height, width,] begin_y, begin_x)
         self.statuswin = curses.newwin(self.numstatuslines, 0, 0, 0)
+        if self.ui.logblockedtime:
+            self.statuswin = util.elapsedtimewrapper(self.statuswin)
         self.statuswin.keypad(1) # interpret arrow-key, etc. esc sequences
 
         # figure out how much space to allocate for the chunk-pad which is
@@ -1652,15 +1668,23 @@
         self.selecteditemendline = self.getnumlinesdisplayed(
             self.currentselecteditem, recursechildren=False)
 
-        while True:
-            self.updatescreen()
-            try:
-                keypressed = self.statuswin.getkey()
-                if self.errorstr is not None:
-                    self.errorstr = None
-                    continue
-            except curses.error:
-                keypressed = "foobar"
-            if self.handlekeypressed(keypressed):
-                break
+        try:
+            while True:
+                self.updatescreen()
+                try:
+                    keypressed = self.statuswin.getkey()
+                    if self.errorstr is not None:
+                        self.errorstr = None
+                        continue
+                except curses.error:
+                    keypressed = "foobar"
+                if self.handlekeypressed(keypressed):
+                    break
+        finally:
+            if self.ui.logblockedtime:
+                self.elapsedms += self.stdscr.elapsedms
+                self.elapsedms += self.statuswin.elapsedms
+                self.ui.log('uiblocked',
+                            'crecord blocked for %0.1f ms', self.elapsedms,
+                            crecord_blocked=self.elapsedms)
         signal.signal(signal.SIGWINCH, origsigwinchhandler)