From 9118178e3b80808831c369df98ec4ac63a182e06 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Florian=20Qu=C3=A8ze?= <florian@queze.net>
Date: Tue, 30 Apr 2024 08:17:13 +0000
Subject: [PATCH] Bug 1892641 - include timestamps in BUILDSTATUS lines from
 gradle, r=glandium.

Differential Revision: https://phabricator.services.mozilla.com/D208531
---
 build.gradle                                     | 13 +++++++++----
 python/mozbuild/mozbuild/controller/building.py  | 10 ++++++++--
 .../mozsystemmonitor/resourcemonitor.py          | 16 +++++++++++++---
 3 files changed, 30 insertions(+), 9 deletions(-)

diff --git a/build.gradle b/build.gradle
index 55da44edcf71..859609b3d07b 100644
--- a/build.gradle
+++ b/build.gradle
@@ -72,6 +72,11 @@ def getRustVersionFor(packageName) {
     return version
 }
 
+def now() {
+    Instant now = Instant.now();
+    return now.getEpochSecond() + now.getNano() / 1_000_000_000L;
+}
+
 allprojects {
     def shouldPrintBuildStatus =
             System.getenv("MACH") && !System.getenv("NO_BUILDSTATUS_MESSAGES")
@@ -80,23 +85,23 @@ allprojects {
         // Adding new line before each line to make sure they're dumped as a separate line.
         // Add profile marker to the start of the project evaluation
         project.beforeEvaluate {
-            println "\nBUILDSTATUS START_gradle:evaluate-project ${project.name}"
+            println "\nBUILDSTATUS ${now()} START_gradle:evaluate-project ${project.name}"
         }
 
         // Add profile marker to the end of the project evaluation
         project.afterEvaluate {
-            println "\nBUILDSTATUS END_gradle:evaluate-project ${project.name}"
+            println "\nBUILDSTATUS ${now()} END_gradle:evaluate-project ${project.name}"
         }
 
         tasks.configureEach { task ->
             // Add profile marker to the start of the gradle task
             task.doFirst {
-                println "\nBUILDSTATUS START_gradle:${project.name}-tasks ${task.name}"
+                println "\nBUILDSTATUS ${now()} START_gradle-task ${project.name}:${task.name}"
             }
 
             // Add profile marker to the end of the gradle task
             task.doLast {
-                println "\nBUILDSTATUS END_gradle:${project.name}-tasks ${task.name}"
+                println "\nBUILDSTATUS ${now()} END_gradle-task ${project.name}:${task.name}"
             }
         }
     }
diff --git a/python/mozbuild/mozbuild/controller/building.py b/python/mozbuild/mozbuild/controller/building.py
index e584f55a2ea4..75f80996725e 100644
--- a/python/mozbuild/mozbuild/controller/building.py
+++ b/python/mozbuild/mozbuild/controller/building.py
@@ -263,6 +263,12 @@ class BuildMonitor(MozbuildObject):
 
             _, _, disambiguator = args.pop(0).partition("@")
             action = args.pop(0)
+            time = None
+            regexp = re.compile(r"\d{10}(\.\d{1,9})?$")
+            if regexp.match(action):
+                time = float(action)
+                action = args.pop(0)
+
             update_needed = True
 
             if action == "TIERS":
@@ -280,12 +286,12 @@ class BuildMonitor(MozbuildObject):
                 update_needed = False
             elif action.startswith("START_"):
                 self.resources.begin_marker(
-                    action[len("START_") :], " ".join(args), disambiguator
+                    action[len("START_") :], " ".join(args), disambiguator, time
                 )
                 update_needed = False
             elif action.startswith("END_"):
                 self.resources.end_marker(
-                    action[len("END_") :], " ".join(args), disambiguator
+                    action[len("END_") :], " ".join(args), disambiguator, time
                 )
                 update_needed = False
             elif action == "BUILD_VERBOSE":
diff --git a/testing/mozbase/mozsystemmonitor/mozsystemmonitor/resourcemonitor.py b/testing/mozbase/mozsystemmonitor/mozsystemmonitor/resourcemonitor.py
index 978d7d691169..553fcde28411 100644
--- a/testing/mozbase/mozsystemmonitor/mozsystemmonitor/resourcemonitor.py
+++ b/testing/mozbase/mozsystemmonitor/mozsystemmonitor/resourcemonitor.py
@@ -314,6 +314,7 @@ class SystemResourceMonitor(object):
         self._swap_type = type(swap)
         self._swap_len = len(swap)
         self.start_timestamp = time.time()
+        self.start_time = time.monotonic()
 
         self._pipe, child_pipe = multiprocessing.Pipe(True)
 
@@ -328,6 +329,9 @@ class SystemResourceMonitor(object):
             self._pipe.send(("terminate",))
             self._process.join()
 
+    def convert_to_monotonic_time(self, timestamp):
+        return timestamp - self.start_timestamp + self.start_time
+
     # Methods to control monitoring.
 
     def start(self):
@@ -458,18 +462,24 @@ class SystemResourceMonitor(object):
             SystemResourceMonitor.instance.markers.append((name, start, end, text))
 
     @staticmethod
-    def begin_marker(name, text, disambiguator=None):
+    def begin_marker(name, text, disambiguator=None, timestamp=None):
         if SystemResourceMonitor.instance:
             id = name + ":" + text
             if disambiguator:
                 id += ":" + disambiguator
-            SystemResourceMonitor.instance._active_markers[id] = time.monotonic()
+            SystemResourceMonitor.instance._active_markers[id] = (
+                SystemResourceMonitor.instance.convert_to_monotonic_time(timestamp)
+                if timestamp
+                else time.monotonic()
+            )
 
     @staticmethod
-    def end_marker(name, text, disambiguator=None):
+    def end_marker(name, text, disambiguator=None, timestamp=None):
         if not SystemResourceMonitor.instance:
             return
         end = time.monotonic()
+        if timestamp:
+            end = SystemResourceMonitor.instance.convert_to_monotonic_time(timestamp)
         id = name + ":" + text
         if disambiguator:
             id += ":" + disambiguator