From 4f4de83bfce9a83a825bdb955186c5d001a0f791 Mon Sep 17 00:00:00 2001
From: Son Luong Ngoc <sluongng@gmail.com>
Date: Thu, 30 Nov 2023 15:40:43 +0100
Subject: [PATCH] RemoteSpawnRunner: record inbetween phases in timing profile

After an action was executed remotely, RemoteSpawnRunner would use
the timestamps in the execution metadata to record appropriate timing
phases into the JSON profile.

However, there are durations in-between the existing phases that are
unaccounted for. Depending on the RBE server implemenation, these
phases could mean different things:
- Sandbox preparation
- Cleaning up sandbox environments post-execution
- Others

Missing these durations inside the timing profile would cause confusion
to end users as it would be interpreted as nothing happened in between
the existing phases.

Add these durations into the profile as "pre-X" phases so that user is
aware of activities could still be happening during that time. RBE
server implementation should be able to alter these label
programmatically if necessary.
---
 .../build/lib/remote/RemoteSpawnRunner.java    | 18 ++++++++++++++++++
 1 file changed, 18 insertions(+)

diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java
index 5cb796eddb5208..5ac37255127ca1 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/RemoteSpawnRunner.java
@@ -339,18 +339,36 @@ private static void profileAccounting(ExecutedActionMetadata executedActionMetad
         executedActionMetadata.getWorkerStartTimestamp(),
         REMOTE_QUEUE,
         "queue");
+    logProfileTask(
+        converter,
+        executedActionMetadata.getWorkerStartTimestamp(),
+        executedActionMetadata.getInputFetchStartTimestamp(),
+        REMOTE_SETUP,
+        "pre-fetch");
     logProfileTask(
         converter,
         executedActionMetadata.getInputFetchStartTimestamp(),
         executedActionMetadata.getInputFetchCompletedTimestamp(),
         REMOTE_SETUP,
         "fetch");
+    logProfileTask(
+        converter,
+        executedActionMetadata.getInputFetchCompletedTimestamp(),
+        executedActionMetadata.getExecutionStartTimestamp(),
+        REMOTE_PROCESS_TIME,
+        "pre-execute");
     logProfileTask(
         converter,
         executedActionMetadata.getExecutionStartTimestamp(),
         executedActionMetadata.getExecutionCompletedTimestamp(),
         REMOTE_PROCESS_TIME,
         "execute");
+    logProfileTask(
+        converter,
+        executedActionMetadata.getExecutionCompletedTimestamp(),
+        executedActionMetadata.getOutputUploadStartTimestamp(),
+        UPLOAD_TIME,
+        "pre-upload");
     logProfileTask(
         converter,
         executedActionMetadata.getOutputUploadStartTimestamp(),