aboutsummaryrefslogtreecommitdiffhomepage
path: root/src
diff options
context:
space:
mode:
Diffstat (limited to 'src')
-rw-r--r--src/main/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunner.java44
-rw-r--r--src/test/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunnerTest.java31
2 files changed, 68 insertions, 7 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunner.java b/src/main/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunner.java
index 3ae6e39e6a..b96a2269ca 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunner.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunner.java
@@ -17,6 +17,7 @@ import static java.nio.charset.StandardCharsets.UTF_8;
import static java.util.logging.Level.INFO;
import static java.util.logging.Level.SEVERE;
+import com.google.common.base.Joiner;
import com.google.common.io.ByteStreams;
import com.google.devtools.build.lib.actions.ActionExecutionMetadata;
import com.google.devtools.build.lib.actions.ResourceManager;
@@ -42,7 +43,9 @@ import java.util.ArrayList;
import java.util.EnumMap;
import java.util.List;
import java.util.Map;
+import java.util.concurrent.atomic.AtomicInteger;
import java.util.logging.Level;
+import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -51,14 +54,18 @@ import javax.annotation.Nullable;
*/
@ThreadSafe
public final class LocalSpawnRunner implements SpawnRunner {
+ private static final Joiner SPACE_JOINER = Joiner.on(' ');
private static final String UNHANDLED_EXCEPTION_MSG = "Unhandled exception running a local spawn";
private static final int LOCAL_EXEC_ERROR = -1;
private static final int POSIX_TIMEOUT_EXIT_CODE = /*SIGNAL_BASE=*/128 + /*SIGWINCH=*/28;
+ private final Logger logger;
+
private final Path execRoot;
private final ResourceManager resourceManager;
private final String hostName;
+ private final AtomicInteger execCount;
private final ActionInputPrefetcher actionInputPrefetcher;
@@ -68,16 +75,20 @@ public final class LocalSpawnRunner implements SpawnRunner {
private final String processWrapper;
public LocalSpawnRunner(
+ Logger logger,
+ AtomicInteger execCount,
Path execRoot,
ActionInputPrefetcher actionInputPrefetcher,
LocalExecutionOptions localExecutionOptions,
ResourceManager resourceManager,
boolean useProcessWrapper) {
+ this.logger = logger;
this.execRoot = execRoot;
this.actionInputPrefetcher = Preconditions.checkNotNull(actionInputPrefetcher);
this.processWrapper = execRoot.getRelative("_bin/process-wrapper").getPathString();
this.localExecutionOptions = localExecutionOptions;
this.hostName = NetUtil.findShortHostName();
+ this.execCount = execCount;
this.resourceManager = resourceManager;
this.useProcessWrapper = useProcessWrapper;
}
@@ -88,6 +99,8 @@ public final class LocalSpawnRunner implements SpawnRunner {
LocalExecutionOptions localExecutionOptions,
ResourceManager resourceManager) {
this(
+ null,
+ new AtomicInteger(),
execRoot,
actionInputPrefetcher,
localExecutionOptions,
@@ -122,6 +135,8 @@ public final class LocalSpawnRunner implements SpawnRunner {
private State currentState = State.INITIALIZING;
private final Map<State, Long> stateTimes = new EnumMap<>(State.class);
+ private final int id = execCount.getAndIncrement();
+
public SubprocessHandler(
Spawn spawn,
SpawnExecutionPolicy policy) {
@@ -137,6 +152,9 @@ public final class LocalSpawnRunner implements SpawnRunner {
} catch (Error e) {
stepLog(SEVERE, UNHANDLED_EXCEPTION_MSG, e);
throw e;
+ } catch (IOException e) {
+ stepLog(SEVERE, "Local I/O error", e);
+ throw e;
} catch (RuntimeException e) {
stepLog(SEVERE, UNHANDLED_EXCEPTION_MSG, e);
throw new RuntimeException(UNHANDLED_EXCEPTION_MSG, e);
@@ -149,11 +167,21 @@ public final class LocalSpawnRunner implements SpawnRunner {
@SuppressWarnings("unused")
private void stepLog(Level level, String fmt, @Nullable Throwable cause, Object... args) {
- // Do nothing for now.
+ String msg = String.format(fmt, args);
+ String toLog = String.format("%s (#%d %s)", msg, id, desc());
+ logger.log(level, toLog, cause);
+ }
+
+ private String desc() {
+ String progressMessage = spawn.getResourceOwner().getProgressMessage();
+ return progressMessage != null
+ ? progressMessage
+ : "ActionType=" + spawn.getResourceOwner().getMnemonic();
}
private void setState(State newState) {
long now = System.currentTimeMillis();
+ long totalDelta = now - creationTime;
long stepDelta = now - stateStartTime;
stateStartTime = now;
@@ -161,11 +189,25 @@ public final class LocalSpawnRunner implements SpawnRunner {
long stateTime = (stateTimeBoxed == null) ? 0 : stateTimeBoxed;
stateTimes.put(currentState, stateTime + stepDelta);
+ logger.info(String.format(
+ "Step #%d time: %.3f delta: %.3f state: %s --> %s",
+ id, totalDelta / 1000f, stepDelta / 1000f, currentState, newState));
currentState = newState;
}
+ private String debugCmdString() {
+ String cmd = SPACE_JOINER.join(spawn.getArguments());
+ if (cmd.length() > 500) {
+ // Shrink argstr by replacing middle of string with "...".
+ return cmd.substring(0, 250) + "..." + cmd.substring(cmd.length() - 250);
+ }
+ return cmd;
+ }
+
/** Parse the request and run it locally. */
private SpawnResult start() throws InterruptedException, IOException {
+ logger.info(String.format("starting local subprocess #%d, argv: %s", id, debugCmdString()));
+
FileOutErr outErr = policy.getFileOutErr();
String actionType = spawn.getResourceOwner().getMnemonic();
if (localExecutionOptions.allowedLocalAction != null
diff --git a/src/test/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunnerTest.java b/src/test/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunnerTest.java
index 97265c4438..23d6515c0a 100644
--- a/src/test/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunnerTest.java
+++ b/src/test/java/com/google/devtools/build/lib/exec/local/LocalSpawnRunnerTest.java
@@ -47,6 +47,10 @@ import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.util.SortedMap;
+import java.util.concurrent.atomic.AtomicInteger;
+import java.util.logging.Filter;
+import java.util.logging.LogRecord;
+import java.util.logging.Logger;
import java.util.regex.Pattern;
import org.junit.After;
import org.junit.Before;
@@ -130,6 +134,8 @@ public class LocalSpawnRunnerTest {
private final ActionInputFileCache mockFileCache = mock(ActionInputFileCache.class);
private final ResourceManager resourceManager = ResourceManager.instanceForTestingOnly();
+ private Logger logger;
+ private AtomicInteger execCount = new AtomicInteger();
private FileOutErr outErr;
private long timeoutMillis = 0;
private boolean calledLockOutputFiles;
@@ -174,6 +180,13 @@ public class LocalSpawnRunnerTest {
@Before
public final void setup() throws Exception {
+ logger = Logger.getAnonymousLogger();
+ logger.setFilter(new Filter() {
+ @Override
+ public boolean isLoggable(LogRecord record) {
+ return false;
+ }
+ });
fs = new InMemoryFileSystem();
// Prevent any subprocess execution at all.
SubprocessBuilder.setSubprocessFactory(new SubprocessInterceptor());
@@ -196,7 +209,8 @@ public class LocalSpawnRunnerTest {
LocalExecutionOptions options = Options.getDefaults(LocalExecutionOptions.class);
options.localSigkillGraceSeconds = 456;
LocalSpawnRunner runner = new LocalSpawnRunner(
- fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options, resourceManager, USE_WRAPPER);
+ logger, execCount, fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options,
+ resourceManager, USE_WRAPPER);
timeoutMillis = 123 * 1000L;
outErr = new FileOutErr(fs.getPath("/out/stdout"), fs.getPath("/out/stderr"));
@@ -228,7 +242,8 @@ public class LocalSpawnRunnerTest {
LocalExecutionOptions options = Options.getDefaults(LocalExecutionOptions.class);
options.localSigkillGraceSeconds = 456;
LocalSpawnRunner runner = new LocalSpawnRunner(
- fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options, resourceManager, NO_WRAPPER);
+ logger, execCount, fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options,
+ resourceManager, NO_WRAPPER);
timeoutMillis = 123 * 1000L;
outErr = new FileOutErr(fs.getPath("/out/stdout"), fs.getPath("/out/stderr"));
@@ -257,7 +272,8 @@ public class LocalSpawnRunnerTest {
LocalExecutionOptions options = Options.getDefaults(LocalExecutionOptions.class);
LocalSpawnRunner runner = new LocalSpawnRunner(
- fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options, resourceManager, USE_WRAPPER);
+ logger, execCount, fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options,
+ resourceManager, USE_WRAPPER);
outErr = new FileOutErr(fs.getPath("/out/stdout"), fs.getPath("/out/stderr"));
SpawnResult result = runner.exec(SIMPLE_SPAWN, policy);
@@ -286,7 +302,8 @@ public class LocalSpawnRunnerTest {
LocalExecutionOptions options = Options.getDefaults(LocalExecutionOptions.class);
LocalSpawnRunner runner = new LocalSpawnRunner(
- fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options, resourceManager, USE_WRAPPER);
+ logger, execCount, fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options,
+ resourceManager, USE_WRAPPER);
outErr = new FileOutErr(fs.getPath("/out/stdout"), fs.getPath("/out/stderr"));
SpawnResult result = runner.exec(SIMPLE_SPAWN, policy);
@@ -305,7 +322,8 @@ public class LocalSpawnRunnerTest {
LocalExecutionOptions options = Options.getDefaults(LocalExecutionOptions.class);
options.allowedLocalAction = Pattern.compile("none");
LocalSpawnRunner runner = new LocalSpawnRunner(
- fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options, resourceManager, USE_WRAPPER);
+ logger, execCount, fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options,
+ resourceManager, USE_WRAPPER);
outErr = new FileOutErr();
SpawnResult reply = runner.exec(SIMPLE_SPAWN, policy);
@@ -343,7 +361,8 @@ public class LocalSpawnRunnerTest {
LocalExecutionOptions options = Options.getDefaults(LocalExecutionOptions.class);
LocalSpawnRunner runner = new LocalSpawnRunner(
- fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options, resourceManager, USE_WRAPPER);
+ logger, execCount, fs.getPath("/execroot"), ActionInputPrefetcher.NONE, options,
+ resourceManager, USE_WRAPPER);
outErr = new FileOutErr(fs.getPath("/out/stdout"), fs.getPath("/out/stderr"));
try {