Bug 1497638 - Gather telemetry for mach commands other than build. r=ted,firefox-build-system-reviewers,nalexander
authorChris Manchester <cmanchester@mozilla.com>
Wed, 31 Oct 2018 20:03:56 +0000
changeset 443826 b42fc1ea86f31b66547e101e9407a1cdfdfa6464
parent 443825 25749072215e52ab46e5d5036978a674be4b33fa
child 443827 6fc2aad03a346ba27b63dff77e59e139a58889fc
push id34972
push userebalazs@mozilla.com
push dateThu, 01 Nov 2018 09:11:48 +0000
treeherdermozilla-central@cfb6077ee31b [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersted, firefox-build-system-reviewers, nalexander
bugs1497638
milestone65.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1497638 - Gather telemetry for mach commands other than build. r=ted,firefox-build-system-reviewers,nalexander Differential Revision: https://phabricator.services.mozilla.com/D10177
build/mach_bootstrap.py
python/mach/mach/registrar.py
python/mozbuild/mozbuild/controller/building.py
python/mozbuild/mozbuild/telemetry.py
--- a/build/mach_bootstrap.py
+++ b/build/mach_bootstrap.py
@@ -230,31 +230,49 @@ def bootstrap(topsrcdir, mozilla_dir=Non
             return True
 
         # The environment is likely a machine invocation.
         if sys.stdin.closed or not sys.stdin.isatty():
             return True
 
         return False
 
-    def post_dispatch_handler(context, handler, args):
+    def post_dispatch_handler(context, handler, instance, result,
+                              start_time, end_time, args):
         """Perform global operations after command dispatch.
 
 
         For now,  we will use this to handle build system telemetry.
         """
         # Don't do anything when...
         if should_skip_dispatch(context, handler):
             return
 
         # We have not opted-in to telemetry
         if not context.settings.build.telemetry:
             return
 
-        # Every n-th operation
+        from mozbuild.telemetry import gather_telemetry
+        from mozbuild.base import MozbuildObject
+
+        if not isinstance(instance, MozbuildObject):
+            instance = MozbuildObject.from_environment()
+
+        try:
+            substs = instance.substs
+        except Exception:
+            substs = {}
+
+        # We gather telemetry for every operation...
+        gather_telemetry(command=handler.name, success=(result == 0),
+                         start_time=start_time, end_time=end_time,
+                         mach_context=context, substs=substs,
+                         paths=[instance.topsrcdir, instance.topobjdir])
+
+        # But only submit about every n-th operation
         if random.randint(1, TELEMETRY_SUBMISSION_FREQUENCY) != 1:
             return
 
         with open(os.devnull, 'wb') as devnull:
             subprocess.Popen([sys.executable,
                               os.path.join(topsrcdir, 'build',
                                            'submit_telemetry_data.py'),
                               get_state_dir()[0]],
--- a/python/mach/mach/registrar.py
+++ b/python/mach/mach/registrar.py
@@ -1,15 +1,16 @@
 # This Source Code Form is subject to the terms of the Mozilla Public
 # License, v. 2.0. If a copy of the MPL was not distributed with this
 # file, You can obtain one at http://mozilla.org/MPL/2.0/.
 
 from __future__ import absolute_import, unicode_literals
 
 from .base import MachError
+import time
 
 INVALID_COMMAND_CONTEXT = r'''
 It looks like you tried to run a mach command from an invalid context. The %s
 command failed to meet the following conditions: %s
 
 Run |mach help| to show a list of all commands available to the current context.
 '''.lstrip()
 
@@ -78,29 +79,34 @@ class MachRegistrar(object):
                     fail_conditions.append(c)
 
             if fail_conditions:
                 print(self._condition_failed_message(handler.name, fail_conditions))
                 return 1
 
         fn = getattr(instance, handler.method)
 
+        start_time = time.time()
+
         if debug_command:
             import pdb
             result = pdb.runcall(fn, **kwargs)
         else:
             result = fn(**kwargs)
 
+        end_time = time.time()
+
         result = result or 0
         assert isinstance(result, (int, long))
 
         if context and not debug_command:
             postrun = getattr(context, 'post_dispatch_handler', None)
             if postrun:
-                postrun(context, handler, args=kwargs)
+                postrun(context, handler, instance, result,
+                        start_time, end_time, args=kwargs)
 
         return result
 
     def dispatch(self, name, context=None, argv=None, subcommand=None, **kwargs):
         """Dispatch/run a command.
 
         Commands can use this to call other commands.
         """
--- a/python/mozbuild/mozbuild/controller/building.py
+++ b/python/mozbuild/mozbuild/controller/building.py
@@ -51,19 +51,16 @@ from ..testing import (
 )
 from ..compilation.warnings import (
     WarningsCollector,
     WarningsDatabase,
 )
 from ..shellutil import (
     quote as shell_quote,
 )
-from ..telemetry import (
-    gather_telemetry,
-)
 from ..util import (
     FileAvoidWrite,
     mkdir,
     resolve_target_to_make,
 )
 
 
 FINDER_SLOW_MESSAGE = '''
@@ -1280,20 +1277,16 @@ class BuildDriver(MozbuildObject):
         except ValueError:
             # Just stick with the default
             pass
 
         if monitor.elapsed > notify_minimum_time:
             # Display a notification when the build completes.
             self.notify('Build complete' if not status else 'Build failed')
 
-        gather_telemetry(command='build', success=(status == 0), monitor=monitor,
-                         mach_context=mach_context, substs=self.substs,
-                         paths=[self.topsrcdir, self.topobjdir])
-
         if status:
             return status
 
         if monitor.have_resource_usage:
             excessive, swap_in, swap_out = monitor.have_excessive_swapping()
             # if excessive:
             #    print(EXCESSIVE_SWAP_MESSAGE)
 
--- a/python/mozbuild/mozbuild/telemetry.py
+++ b/python/mozbuild/mozbuild/telemetry.py
@@ -234,34 +234,34 @@ def filter_args(command, argv, paths):
         base = mozpath.basedir(p, paths)
         if base:
             return mozpath.relpath(p, base)
         # Best-effort.
         return '<path omitted>'
     return [filter_path(arg) for arg in args]
 
 
-def gather_telemetry(command='', success=False, monitor=None, mach_context=None, substs={},
-                     paths=[]):
+def gather_telemetry(command='', success=False, start_time=None, end_time=None,
+                     mach_context=None, substs={}, paths=[]):
     '''
     Gather telemetry about the build and the user's system and pass it to the telemetry
     handler to be stored for later submission.
 
     Any absolute paths on the command line will be made relative to `paths` or replaced
     with a placeholder to avoid including paths from developer's machines.
     '''
     data = {
         'client_id': get_client_id(mach_context.state_dir),
         # Simplest way to get an rfc3339 datetime string, AFAICT.
-        'time': datetime.utcfromtimestamp(monitor.start_time).isoformat(b'T') + 'Z',
+        'time': datetime.utcfromtimestamp(start_time).isoformat(b'T') + 'Z',
         'command': command,
         'argv': filter_args(command, sys.argv, paths),
         'success': success,
         # TODO: use a monotonic clock: https://bugzilla.mozilla.org/show_bug.cgi?id=1481624
-        'duration_ms': int(monitor.elapsed * 1000),
+        'duration_ms': int((end_time - start_time) * 1000),
         'build_opts': get_build_opts(substs),
         'system': get_system_info(),
         # TODO: exception: https://bugzilla.mozilla.org/show_bug.cgi?id=1481617
         # TODO: file_types_changed: https://bugzilla.mozilla.org/show_bug.cgi?id=1481774
     }
     try:
         # Validate against the schema.
         schema(data)