Invert to including client timing in main workunit.

src/python/pants/base/workunit.py

@@ -119,7 +119,6 @@ def __init__(self, run_info_dir, parent, name, labels=None, cmd='', log_config=N
     # In seconds since the epoch. Doubles, to account for fractional seconds.
     self.start_time = 0
     self.end_time = 0
-    self._synthetic_duration = None
 
     # A workunit may have multiple outputs, which we identify by a name.
     # E.g., a tool invocation may have 'stdout', 'stderr', 'debug_log' etc.
@@ -141,9 +140,9 @@ def has_label(self, label):
     """
     return label in self.labels
 
-  def start(self):
+  def start(self, start_time=None):
     """Mark the time at which this workunit started."""
-    self.start_time = time.time()
+    self.start_time = start_time or time.time()
 
   def end(self):
     """Mark the time at which this workunit ended."""
@@ -214,14 +213,8 @@ def duration(self):
 
     :API: public
     """
-    if self._synthetic_duration is not None:
-      return self._synthetic_duration
     return (self.end_time or time.time()) - self.start_time
 
-  def set_duration(self, seconds):
-    """Sets a synthetic/pre-computed duration."""
-    self._synthetic_duration = seconds
-
   @property
   def start_time_string(self):
     """A convenient string representation of start_time.

src/python/pants/bin/daemon_pants_runner.py

@@ -74,7 +74,7 @@ class DaemonPantsRunner(ProcessManager):
   """
 
   def __init__(self, socket, exiter, args, env, graph_helper, fork_lock, preceding_graph_size,
-               graph_warmth_timing, deferred_exception=None):
+               deferred_exception=None):
     """
     :param socket socket: A connected socket capable of speaking the nailgun protocol.
     :param Exiter exiter: The Exiter instance for this run.
@@ -85,7 +85,6 @@ def __init__(self, socket, exiter, args, env, graph_helper, fork_lock, preceding
                                            None.
     :param threading.RLock fork_lock: A lock to use during forking for thread safety.
     :param int preceding_graph_size: The size of the graph pre-warming, for stats.
-    :param float graph_warmth_timing: The elapsed time of daemon-size graph warming.
     :param Exception deferred_exception: A deferred exception from the daemon's graph construction.
                                          If present, this will be re-raised in the client context.
     """
@@ -97,7 +96,6 @@ def __init__(self, socket, exiter, args, env, graph_helper, fork_lock, preceding
     self._graph_helper = graph_helper
     self._fork_lock = fork_lock
     self._preceding_graph_size = preceding_graph_size
-    self._graph_warmth_timing = graph_warmth_timing
     self._deferred_exception = deferred_exception
 
   def _make_identity(self):
@@ -238,7 +236,6 @@ def post_fork_child(self):
         # Otherwise, conduct a normal run.
         runner = LocalPantsRunner(self._exiter, self._args, self._env, self._graph_helper)
         runner.set_preceding_graph_size(self._preceding_graph_size)
-        runner.set_graph_warmth_timing(self._graph_warmth_timing)
         runner.run()
       except KeyboardInterrupt:
         self._exiter.exit(1, msg='Interrupted by user.\n')

src/python/pants/bin/local_pants_runner.py

@@ -32,19 +32,19 @@ def __init__(self, exiter, args, env, daemon_build_graph=None, options_bootstrap
     self._daemon_build_graph = daemon_build_graph
     self._options_bootstrapper = options_bootstrapper
     self._preceding_graph_size = -1
-    self._graph_warmth_timing = 0.0
 
   def set_preceding_graph_size(self, size):
     self._preceding_graph_size = size
 
-  def set_graph_warmth_timing(self, timing):
-    self._graph_warmth_timing = timing
-
   def run(self):
     profile_path = self._env.get('PANTS_PROFILE')
     with hard_exit_handler(), maybe_profiled(profile_path):
       self._run()
 
+  def _maybe_get_client_start_time_from_env(self):
+    client_start_time = self._env.pop('PANTSD_RUNTRACKER_CLIENT_START_TIME', None)
+    return None if client_start_time is None else float(client_start_time)
+
   def _run(self):
     # Bootstrap options and logging.
     options_bootstrapper = self._options_bootstrapper or OptionsBootstrapper(env=self._env,
@@ -67,7 +67,7 @@ def _run(self):
     # Launch RunTracker as early as possible (just after Subsystem options are initialized).
     run_tracker = RunTracker.global_instance()
     reporting = Reporting.global_instance()
-    reporting.initialize(run_tracker)
+    reporting.initialize(run_tracker, self._maybe_get_client_start_time_from_env())
 
     try:
       # Determine the build root dir.
@@ -79,7 +79,6 @@ def _run(self):
         repro.capture(run_tracker.run_info.get_as_dict())
 
       # Record the preceding product graph size.
-      run_tracker.new_pre_timed_workunit('graph_warmth', self._graph_warmth_timing)
       run_tracker.pantsd_stats.set_preceding_graph_size(self._preceding_graph_size)
 
       # Setup and run GoalRunner.

src/python/pants/bin/remote_pants_runner.py

@@ -8,6 +8,7 @@
 import logging
 import signal
 import sys
+import time
 from contextlib import contextmanager
 
 from pants.console.stty_utils import STTYSettings
@@ -43,6 +44,7 @@ def __init__(self, exiter, args, env, bootstrap_options, stdin=None, stdout=None
     :param file stdout: The stream representing stdout.
     :param file stderr: The stream representing stderr.
     """
+    self._start_time = time.time()
     self._exiter = exiter
     self._args = args
     self._env = env
@@ -93,6 +95,7 @@ def _connect_and_execute(self, port):
     # Merge the nailgun TTY capability environment variables with the passed environment dict.
     ng_env = NailgunProtocol.isatty_to_env(self._stdin, self._stdout, self._stderr)
     modified_env = combined_dict(self._env, ng_env)
+    modified_env['PANTSD_RUNTRACKER_CLIENT_START_TIME'] = str(self._start_time)
 
     assert isinstance(port, int), 'port {} is not an integer!'.format(port)
 

src/python/pants/goal/run_tracker.py

@@ -194,7 +194,7 @@ def initialize(self):
 
     return run_id
 
-  def start(self, report):
+  def start(self, report, run_start_time=None):
     """Start tracking this pants run using the given Report.
 
     `RunTracker.initialize` must have been called first to create the run_info_dir and
@@ -213,7 +213,8 @@ def start(self, report):
     self._main_root_workunit = WorkUnit(run_info_dir=self.run_info_dir, parent=None,
                                         name=RunTracker.DEFAULT_ROOT_NAME, cmd=None)
     self.register_thread(self._main_root_workunit)
-    self._main_root_workunit.start()
+    # Set the true start time in the case of e.g. the daemon.
+    self._main_root_workunit.start(run_start_time)
     self.report.start_workunit(self._main_root_workunit)
 
     # Log reporting details.
@@ -227,32 +228,6 @@ def set_root_outcome(self, outcome):
     """Useful for setup code that doesn't have a reference to a workunit."""
     self._main_root_workunit.set_outcome(outcome)
 
-  @contextmanager
-  def new_pre_timed_workunit(self, name, timing, labels=None, cmd='', log_config=None):
-    """Creates a synthetic workunit with a pre-computed timing.
-
-    - name: A short name for this work. E.g., 'resolve', 'compile', 'scala', 'zinc'.
-    - timing: The pre-compted timing for this workunit.
-    - labels: An optional iterable of labels. The reporters can use this to decide how to
-              display information about this work.
-    - cmd: An optional longer string representing this work.
-           E.g., the cmd line of a compiler invocation.
-    - log_config: An optional tuple WorkUnit.LogConfig of task-level options affecting reporting.
-    """
-    parent = self._threadlocal.current_workunit
-    workunit = WorkUnit(
-      run_info_dir=self.run_info_dir,
-      parent=parent,
-      name=name,
-      labels=labels,
-      cmd=cmd,
-      log_config=log_config
-    )
-    self.report.start_workunit(workunit)
-    workunit.set_duration(timing)
-    workunit.set_outcome(WorkUnit.SUCCESS)
-    self.end_workunit(workunit)
-
   @contextmanager
   def new_workunit(self, name, labels=None, cmd='', log_config=None):
     """Creates a (hierarchical) subunit of work for the purpose of timing and reporting.

src/python/pants/pantsd/service/pailgun_service.py

@@ -8,7 +8,6 @@
 import logging
 import select
 import sys
-import time
 import traceback
 from contextlib import contextmanager
 
@@ -54,7 +53,6 @@ def _setup_pailgun(self):
     """Sets up a PailgunServer instance."""
     # Constructs and returns a runnable PantsRunner.
     def runner_factory(sock, arguments, environment):
-      start_time = time.time()
       exiter = self._exiter_class(sock)
       graph_helper = None
       deferred_exc = None
@@ -82,8 +80,6 @@ def runner_factory(sock, arguments, environment):
           ''.join(traceback.format_exception(*deferred_exc))
         )
 
-      graph_warmth_time = time.time() - start_time
-
       return self._runner_class(
         sock,
         exiter,
@@ -92,7 +88,6 @@ def runner_factory(sock, arguments, environment):
         graph_helper,
         self.fork_lock,
         preceding_graph_size,
-        graph_warmth_time,
         deferred_exc
       )
 

src/python/pants/reporting/reporting.py

@@ -46,7 +46,7 @@ def register_options(cls, register):
                   '{workunits}.  Possible formatting values are {formats}'.format(
                workunits=WorkUnitLabel.keys(), formats=ToolOutputFormat.keys()))
 
-  def initialize(self, run_tracker):
+  def initialize(self, run_tracker, start_time=None):
     """Initialize with the given RunTracker.
 
     TODO: See `RunTracker.start`.
@@ -88,7 +88,7 @@ def initialize(self, run_tracker):
       run_tracker.run_info.add_info('report_url', 'http://localhost:{}/run/{}'.format(port, run_id))
 
     # And start tracking the run.
-    run_tracker.start(report)
+    run_tracker.start(report, start_time)
 
   def _get_invalidation_report(self):
     return InvalidationReport() if self.get_options().invalidation_report else None

tests/python/pants_test/testutils/process_test_util.py

@@ -17,7 +17,7 @@ class ProcessStillRunning(AssertionError):
 def _safe_iter_matching_processes(name):
   for proc in psutil.process_iter():
     try:
-      if name in ''.join(proc.cmdline()):
+      if name in ''.join([part.decode('utf-8') for part in proc.cmdline()]):
         yield proc
     except (psutil.NoSuchProcess, psutil.AccessDenied):
       pass