Patchwork [1,of,2] statprof: also gather wall time

login
register
mail settings
Submitter Boris Feld
Date June 11, 2018, 7:29 a.m.
Message ID <358e59e9b92acd32e9f0.1528702170@localhost.localdomain>
Download mbox | patch
Permalink /patch/32049/
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 1527845007 -7200
#      Fri Jun 01 11:23:27 2018 +0200
# Node ID 358e59e9b92acd32e9f02246598e8bb3122cf846
# Parent  c019db5ccfa155de8a98cced1e7f5ddaede439e5
# EXP-Topic wallstat
# Available At https://bitbucket.org/octobus/mercurial-devel/
#              hg pull https://bitbucket.org/octobus/mercurial-devel/ -r 358e59e9b92a
statprof: also gather wall time

Gathering wall time information is useful for operations that are IO (files,
network) intensive.

For now we only expose it in the final summary.
Yuya Nishihara - June 11, 2018, 12:21 p.m.
On Mon, 11 Jun 2018 09:29:30 +0200, Boris Feld wrote:
> # HG changeset patch
> # User Boris Feld <boris.feld@octobus.net>
> # Date 1527845007 -7200
> #      Fri Jun 01 11:23:27 2018 +0200
> # Node ID 358e59e9b92acd32e9f02246598e8bb3122cf846
> # Parent  c019db5ccfa155de8a98cced1e7f5ddaede439e5
> # EXP-Topic wallstat
> # Available At https://bitbucket.org/octobus/mercurial-devel/
> #              hg pull https://bitbucket.org/octobus/mercurial-devel/ -r 358e59e9b92a
> statprof: also gather wall time

Seems fine. Queued, thanks.

>      def accumulate_time(self, stop_time):
> -        self.accumulated_time += stop_time - self.last_start_time
> +        increment = (
> +            stop_time[0] - self.last_start_time[0],
> +            stop_time[1] - self.last_start_time[1],
> +        )
> +        self.accumulated_time = (
> +            self.accumulated_time[0] + increment[0],
> +            self.accumulated_time[1] + increment[1],
> +        )

This would break load/save_data(). I don't think we use these functions, but
can you fix them as a follow up?

Patch

diff --git a/mercurial/statprof.py b/mercurial/statprof.py
--- a/mercurial/statprof.py
+++ b/mercurial/statprof.py
@@ -139,7 +139,7 @@  skips = {"util.py:check", "extensions.py
 
 def clock():
     times = os.times()
-    return times[0] + times[1]
+    return (times[0] + times[1], times[4])
 
 
 ###########################################################################
@@ -151,7 +151,7 @@  class ProfileState(object):
 
     def reset(self, frequency=None):
         # total so far
-        self.accumulated_time = 0.0
+        self.accumulated_time = (0.0, 0.0)
         # start_time when timer is active
         self.last_start_time = None
         # a float
@@ -170,10 +170,17 @@  class ProfileState(object):
         self.samples = []
 
     def accumulate_time(self, stop_time):
-        self.accumulated_time += stop_time - self.last_start_time
+        increment = (
+            stop_time[0] - self.last_start_time[0],
+            stop_time[1] - self.last_start_time[1],
+        )
+        self.accumulated_time = (
+            self.accumulated_time[0] + increment[0],
+            self.accumulated_time[1] + increment[1],
+        )
 
     def seconds_per_sample(self):
-        return self.accumulated_time / len(self.samples)
+        return self.accumulated_time[0] / len(self.samples)
 
 state = ProfileState()
 
@@ -261,7 +268,7 @@  def profile_signal_handler(signum, frame
         now = clock()
         state.accumulate_time(now)
 
-        state.samples.append(Sample.from_frame(frame, state.accumulated_time))
+        state.samples.append(Sample.from_frame(frame, state.accumulated_time[0]))
 
         signal.setitimer(signal.ITIMER_PROF,
             state.sample_interval, 0.0)
@@ -274,7 +281,7 @@  def samplerthread(tid):
         state.accumulate_time(now)
 
         frame = sys._current_frames()[tid]
-        state.samples.append(Sample.from_frame(frame, state.accumulated_time))
+        state.samples.append(Sample.from_frame(frame, state.accumulated_time[0]))
 
         state.last_start_time = now
         time.sleep(state.sample_interval)
@@ -465,7 +472,7 @@  def display(fp=None, format=3, data=None
     if format not in (DisplayFormats.Json, DisplayFormats.Chrome):
         print('---', file=fp)
         print('Sample count: %d' % len(data.samples), file=fp)
-        print('Total time: %f seconds' % data.accumulated_time, file=fp)
+        print('Total time: %f seconds (%f wall)' % data.accumulated_time, file=fp)
 
 def display_by_line(data, fp):
     '''Print the profiler data with each sample line represented