Patchwork [2,of,2] profiling: introduce a "profiling.time-track" option

login
register
mail settings
Submitter Boris Feld
Date June 11, 2018, 7:29 a.m.
Message ID <103356a223b19890241c.1528702171@localhost.localdomain>
Download mbox | patch
Permalink /patch/32048/
State Accepted
Headers show

Comments

Boris Feld - June 11, 2018, 7:29 a.m.
# HG changeset patch
# User Boris Feld <boris.feld@octobus.net>
# Date 1527866878 -7200
#      Fri Jun 01 17:27:58 2018 +0200
# Node ID 103356a223b19890241cabfa588fcf8acc46a4ec
# Parent  358e59e9b92acd32e9f02246598e8bb3122cf846
# EXP-Topic wallstat
# Available At https://bitbucket.org/octobus/mercurial-devel/
#              hg pull https://bitbucket.org/octobus/mercurial-devel/ -r 103356a223b1
profiling: introduce a "profiling.time-track" option

This option allows to switch the time used by the statistical profiler from
cpu to real time. Our goal is to profile IO intensive operations using the
mercurial profiler.

Patch

diff --git a/mercurial/configitems.py b/mercurial/configitems.py
--- a/mercurial/configitems.py
+++ b/mercurial/configitems.py
@@ -869,6 +869,9 @@  coreconfigitem('profiling', 'sort',
 coreconfigitem('profiling', 'statformat',
     default='hotpath',
 )
+coreconfigitem('profiling', 'time-track',
+    default='cpu',
+)
 coreconfigitem('profiling', 'type',
     default='stat',
 )
diff --git a/mercurial/help/config.txt b/mercurial/help/config.txt
--- a/mercurial/help/config.txt
+++ b/mercurial/help/config.txt
@@ -1652,6 +1652,10 @@  statistical text report generated from t
     ``inlinetime``.
     (default: inlinetime)
 
+``time-track``
+    Control if the stat profiler track ``cpu`` or ``real`` time.
+    (default: ``cpu``)
+
 ``limit``
     Number of lines to show. Specific to the ``ls`` instrumenting profiler.
     (default: 30)
diff --git a/mercurial/profiling.py b/mercurial/profiling.py
--- a/mercurial/profiling.py
+++ b/mercurial/profiling.py
@@ -101,7 +101,8 @@  def statprofile(ui, fp):
     else:
         ui.warn(_("invalid sampling frequency '%s' - ignoring\n") % freq)
 
-    statprof.start(mechanism='thread')
+    track = ui.config('profiling', 'time-track')
+    statprof.start(mechanism='thread', track=track)
 
     try:
         yield
diff --git a/mercurial/statprof.py b/mercurial/statprof.py
--- a/mercurial/statprof.py
+++ b/mercurial/statprof.py
@@ -148,6 +148,7 @@  def clock():
 class ProfileState(object):
     def __init__(self, frequency=None):
         self.reset(frequency)
+        self.track = 'cpu'
 
     def reset(self, frequency=None):
         # total so far
@@ -180,7 +181,13 @@  class ProfileState(object):
         )
 
     def seconds_per_sample(self):
-        return self.accumulated_time[0] / len(self.samples)
+        return self.accumulated_time[self.timeidx] / len(self.samples)
+
+    @property
+    def timeidx(self):
+        if self.track == 'real':
+            return 1
+        return 0
 
 state = ProfileState()
 
@@ -268,7 +275,8 @@  def profile_signal_handler(signum, frame
         now = clock()
         state.accumulate_time(now)
 
-        state.samples.append(Sample.from_frame(frame, state.accumulated_time[0]))
+        timestamp = state.accumulated_time[state.timeidx]
+        state.samples.append(Sample.from_frame(frame, timestamp))
 
         signal.setitimer(signal.ITIMER_PROF,
             state.sample_interval, 0.0)
@@ -281,7 +289,9 @@  def samplerthread(tid):
         state.accumulate_time(now)
 
         frame = sys._current_frames()[tid]
-        state.samples.append(Sample.from_frame(frame, state.accumulated_time[0]))
+
+        timestamp = state.accumulated_time[state.timeidx]
+        state.samples.append(Sample.from_frame(frame, timestamp))
 
         state.last_start_time = now
         time.sleep(state.sample_interval)
@@ -295,8 +305,9 @@  def is_active():
     return state.profile_level > 0
 
 lastmechanism = None
-def start(mechanism='thread'):
+def start(mechanism='thread', track='cpu'):
     '''Install the profiling signal handler, and start profiling.'''
+    state.track = track # note: nesting different mode won't work
     state.profile_level += 1
     if state.profile_level == 1:
         state.last_start_time = clock()