Use AutoProfiler for logging timing info for potentially expensive local actions.

--
MOS_MIGRATED_REVID=102592965

3 files changed, 36 insertions, 78 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/exec/FileWriteStrategy.java b/src/main/java/com/google/devtools/build/lib/exec/FileWriteStrategy.java
index 48f7f1df21..e10de702f3 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/FileWriteStrategy.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/FileWriteStrategy.java
@@ -24,19 +24,21 @@ import com.google.devtools.build.lib.actions.ResourceSet;
 import com.google.devtools.build.lib.analysis.actions.AbstractFileWriteAction;
 import com.google.devtools.build.lib.analysis.actions.FileWriteActionContext;
 import com.google.devtools.build.lib.events.EventHandler;
+import com.google.devtools.build.lib.profiler.AutoProfiler;
 import com.google.devtools.build.lib.util.io.FileOutErr;
 import com.google.devtools.build.lib.vfs.Path;
 
 import java.io.BufferedOutputStream;
 import java.io.IOException;
 import java.io.OutputStream;
+import java.util.logging.Logger;
 
 /**
  * A strategy for executing an {@link AbstractFileWriteAction}.
  */
 @ExecutionStrategy(name = { "local" }, contextType = FileWriteActionContext.class)
 public final class FileWriteStrategy implements FileWriteActionContext {
-
+  private static final Logger LOG = Logger.getLogger(FileWriteStrategy.class.getName());
   public static final Class<FileWriteStrategy> TYPE = FileWriteStrategy.class;
 
   public FileWriteStrategy() {
@@ -46,21 +48,20 @@ public final class FileWriteStrategy implements FileWriteActionContext {
   public void exec(Executor executor, AbstractFileWriteAction action, FileOutErr outErr,
       ActionExecutionContext actionExecutionContext) throws ExecException, InterruptedException {
     EventHandler reporter = executor == null ? null : executor.getEventHandler();
-    LocalActionLogging logging = new LocalActionLogging(action);
-    try {
-      Path outputPath = Iterables.getOnlyElement(action.getOutputs()).getPath();
-      try (OutputStream out = new BufferedOutputStream(outputPath.getOutputStream())) {
-        action.newDeterministicWriter(reporter, executor).writeOutputFile(out);
-      }
-      if (action.makeExecutable()) {
-        outputPath.setExecutable(true);
+    try (AutoProfiler p = AutoProfiler.logged("running " + action.prettyPrint(), LOG)) {
+      try {
+        Path outputPath = Iterables.getOnlyElement(action.getOutputs()).getPath();
+        try (OutputStream out = new BufferedOutputStream(outputPath.getOutputStream())) {
+          action.newDeterministicWriter(reporter, executor).writeOutputFile(out);
+        }
+        if (action.makeExecutable()) {
+          outputPath.setExecutable(true);
+        }
+      } catch (IOException e) {
+        throw new EnvironmentalExecException("failed to create file '"
+            + Iterables.getOnlyElement(action.getOutputs()).prettyPrint()
+            + "' due to I/O error: " + e.getMessage(), e);
       }
-    } catch (IOException e) {
-      throw new EnvironmentalExecException("failed to create file '"
-          + Iterables.getOnlyElement(action.getOutputs()).prettyPrint()
-          + "' due to I/O error: " + e.getMessage(), e);
-    } finally {
-      logging.finish();
     }
   }
 
diff --git a/src/main/java/com/google/devtools/build/lib/exec/LocalActionLogging.java b/src/main/java/com/google/devtools/build/lib/exec/LocalActionLogging.java
deleted file mode 100644
index f9f5185f82..0000000000
--- a/src/main/java/com/google/devtools/build/lib/exec/LocalActionLogging.java
+++ /dev/null
@@ -1,47 +0,0 @@
-// Copyright 2015 Google Inc. All rights reserved.
-//
-// Licensed under the Apache License, Version 2.0 (the "License");
-// you may not use this file except in compliance with the License.
-// You may obtain a copy of the License at
-//
-//    http://www.apache.org/licenses/LICENSE-2.0
-//
-// Unless required by applicable law or agreed to in writing, software
-// distributed under the License is distributed on an "AS IS" BASIS,
-// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-// See the License for the specific language governing permissions and
-// limitations under the License.
-
-package com.google.devtools.build.lib.exec;
-
-import com.google.common.base.Preconditions;
-import com.google.devtools.build.lib.actions.ActionMetadata;
-import com.google.devtools.build.lib.util.BlazeClock;
-
-import java.util.concurrent.TimeUnit;
-import java.util.logging.Logger;
-
-/**
- * Utility class for logging time of locally executed actions.
- */
-class LocalActionLogging {
-
-  private static final Logger LOG = Logger.getLogger(LocalActionLogging.class.getName());
-
-  private final ActionMetadata action;
-  private final long startTime;
-  private boolean isRunning = true;
-
-  LocalActionLogging(ActionMetadata action) {
-    this.action = action;
-    startTime = BlazeClock.nanoTime();
-    LOG.info("Started to run " + action.prettyPrint());
-  }
-
-  void finish() {
-    Preconditions.checkState(isRunning, action);
-    isRunning = false;
-    LOG.info("Finished running " + action.prettyPrint()
-        + " in " + TimeUnit.NANOSECONDS.toMillis(BlazeClock.nanoTime() - startTime) + "ms");
-  }
-}
diff --git a/src/main/java/com/google/devtools/build/lib/exec/SymlinkTreeStrategy.java b/src/main/java/com/google/devtools/build/lib/exec/SymlinkTreeStrategy.java
index 2fe14606b4..8cbb9bf114 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/SymlinkTreeStrategy.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/SymlinkTreeStrategy.java
@@ -21,6 +21,9 @@ import com.google.devtools.build.lib.actions.Executor;
 import com.google.devtools.build.lib.analysis.SymlinkTreeAction;
 import com.google.devtools.build.lib.analysis.SymlinkTreeActionContext;
 import com.google.devtools.build.lib.analysis.config.BinTools;
+import com.google.devtools.build.lib.profiler.AutoProfiler;
+
+import java.util.logging.Logger;
 
 /**
  * Implements SymlinkTreeAction by using the output service or by running an embedded script to
@@ -28,6 +31,8 @@ import com.google.devtools.build.lib.analysis.config.BinTools;
  */
 @ExecutionStrategy(contextType = SymlinkTreeActionContext.class)
 public final class SymlinkTreeStrategy implements SymlinkTreeActionContext {
+  private static final Logger LOG = Logger.getLogger(SymlinkTreeStrategy.class.getName());
+
   private final OutputService outputService;
   private final BinTools binTools;
 
@@ -41,23 +46,22 @@ public final class SymlinkTreeStrategy implements SymlinkTreeActionContext {
       ActionExecutionContext actionExecutionContext)
       throws ActionExecutionException, InterruptedException {
     Executor executor = actionExecutionContext.getExecutor();
-    LocalActionLogging logging = new LocalActionLogging(action);
-    try {
-      SymlinkTreeHelper helper = new SymlinkTreeHelper(
-          action.getInputManifest().getExecPath(),
-          action.getOutputManifest().getExecPath().getParentDirectory(), action.isFilesetTree());
-      if (outputService != null && outputService.canCreateSymlinkTree()) {
-        outputService.createSymlinkTree(action.getInputManifest().getPath(),
-            action.getOutputManifest().getPath(),
-            action.isFilesetTree(), helper.getSymlinkTreeRoot());
-      } else {
-        helper.createSymlinks(action, actionExecutionContext, binTools);
+    try (AutoProfiler p = AutoProfiler.logged("running " + action.prettyPrint(), LOG)) {
+      try {
+        SymlinkTreeHelper helper = new SymlinkTreeHelper(
+            action.getInputManifest().getExecPath(),
+            action.getOutputManifest().getExecPath().getParentDirectory(), action.isFilesetTree());
+        if (outputService != null && outputService.canCreateSymlinkTree()) {
+          outputService.createSymlinkTree(action.getInputManifest().getPath(),
+              action.getOutputManifest().getPath(),
+              action.isFilesetTree(), helper.getSymlinkTreeRoot());
+        } else {
+          helper.createSymlinks(action, actionExecutionContext, binTools);
+        }
+      } catch (ExecException e) {
+        throw e.toActionExecutionException(
+            action.getProgressMessage(), executor.getVerboseFailures(), action);
       }
-    } catch (ExecException e) {
-      throw e.toActionExecutionException(
-          action.getProgressMessage(), executor.getVerboseFailures(), action);
-    } finally {
-      logging.finish();
     }
   }
 }