commit ebbbdf7949ef202b5a1141eee81cdb95235e863c
author twerth <twerth@google.com> Fri Feb 07 07:28:04 2020 -0800
committer Copybara-Service <copybara-worker@google.com> Fri Feb 07 07:28:58 2020 -0800
tree 743e62b8dfa72e3d8bccf7392452509460c4f7a1
parent e6ee35faaa351a77e6fa667a74ed195e3d1927bf

Add more instrumentation to what happens at the end of an action.

RELNOTES: None
PiperOrigin-RevId: 293809772

src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java

diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java
index ba1b203..09b50ad 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java
@@ -338,7 +338,6 @@
               // CRITICAL_PATH corresponds to writing the file.
               && profilerTask != ProfilerTask.CRITICAL_PATH
               && profilerTask != ProfilerTask.SKYFUNCTION
-              && profilerTask != ProfilerTask.ACTION_COMPLETE
               && !profilerTask.isStarlark()) {
             profiledTasksBuilder.add(profilerTask);
           }

src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java

diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
index dd33610..d64509e 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
@@ -1152,8 +1152,13 @@
       }
 
       try {
-        return new ActionCacheWriteStep(
-            actuallyCompleteAction(eventHandler, nextActionContinuationOrResult.get()));
+        ActionExecutionValue actionExecutionValue;
+        try (SilentCloseable c =
+            profiler.profile(ProfilerTask.ACTION_COMPLETE, "actuallyCompleteAction")) {
+          actionExecutionValue =
+              actuallyCompleteAction(eventHandler, nextActionContinuationOrResult.get());
+        }
+        return new ActionCacheWriteStep(actionExecutionValue);
       } catch (ActionExecutionException e) {
         return ActionStepOrResult.of(e);
       } finally {
@@ -1191,19 +1196,17 @@
         Preconditions.checkState(action.inputsDiscovered(),
             "Action %s successfully executed, but inputs still not known", action);
 
-        try (SilentCloseable c =
-            profiler.profile(ProfilerTask.ACTION_COMPLETE, action.describe())) {
-          if (!checkOutputs(action, metadataHandler)) {
-            throw toActionExecutionException(
-                "not all outputs were created or valid",
-                null,
-                action,
-                outputAlreadyDumped ? null : fileOutErr);
-          }
+        if (!checkOutputs(action, metadataHandler)) {
+          throw toActionExecutionException(
+              "not all outputs were created or valid",
+              null,
+              action,
+              outputAlreadyDumped ? null : fileOutErr);
         }
 
         if (outputService != null && finalizeActions) {
-          try {
+          try (SilentCloseable c =
+              profiler.profile(ProfilerTask.INFO, "outputService.finalizeAction")) {
             outputService.finalizeAction(action, metadataHandler);
           } catch (EnvironmentalExecException | IOException e) {
             logger.log(Level.WARNING, String.format("unable to finalize action: '%s'", action), e);
@@ -1293,7 +1296,7 @@
 
       @Override
       public ActionStepOrResult run(Environment env) {
-        try {
+        try (SilentCloseable c = profiler.profile(ProfilerTask.INFO, "postprocessing.run")) {
           postprocessing.run(env, action, metadataHandler, actionExecutionContext.getClientEnv());
           if (env.valuesMissing()) {
             return this;