in src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java [279:640]
private BlazeCommandResult execExclusively(
OriginalUnstructuredCommandLineEvent unstructuredServerCommandLineEvent,
InvocationPolicy invocationPolicy,
List<String> args,
OutErr outErr,
long firstContactTime,
String commandName,
BlazeCommand command,
long waitTimeInMs,
Optional<List<Pair<String, String>>> startupOptionsTaggedWithBazelRc,
List<Any> commandExtensions) {
// Record the start time for the profiler. Do not put anything before this!
long execStartTimeNanos = runtime.getClock().nanoTime();
Command commandAnnotation = command.getClass().getAnnotation(Command.class);
BlazeWorkspace workspace = runtime.getWorkspace();
StoredEventHandler storedEventHandler = new StoredEventHandler();
BlazeOptionHandler optionHandler =
new BlazeOptionHandler(
runtime,
workspace,
command,
commandAnnotation,
// Provide the options parser so that we can cache OptionsData here.
createOptionsParser(command),
invocationPolicy);
DetailedExitCode earlyExitCode = optionHandler.parseOptions(args, storedEventHandler);
OptionsParsingResult options = optionHandler.getOptionsResult();
CommandLineEvent originalCommandLineEvent =
new CommandLineEvent.OriginalCommandLineEvent(
runtime, commandName, options, startupOptionsTaggedWithBazelRc);
CommandLineEvent canonicalCommandLineEvent =
new CommandLineEvent.CanonicalCommandLineEvent(runtime, commandName, options);
// The initCommand call also records the start time for the timestamp granularity monitor.
List<String> commandEnvWarnings = new ArrayList<>();
CommandEnvironment env =
workspace.initCommand(
commandAnnotation,
options,
commandEnvWarnings,
waitTimeInMs,
firstContactTime,
commandExtensions,
this::setShutdownReason);
CommonCommandOptions commonOptions = options.getOptions(CommonCommandOptions.class);
boolean tracerEnabled = false;
if (commonOptions.enableTracer == TriState.YES) {
tracerEnabled = true;
} else if (commonOptions.enableTracer == TriState.AUTO) {
boolean commandSupportsProfile =
(commandAnnotation.builds() || "query".equals(commandName))
&& !"clean".equals(commandName)
&& !"info".equals(commandName);
tracerEnabled = commandSupportsProfile || commonOptions.profilePath != null;
}
// TODO(ulfjack): Move the profiler initialization as early in the startup sequence as possible.
// Profiler setup and shutdown must always happen in pairs. Shutdown is currently performed in
// the afterCommand call in the finally block below.
ProfilerStartedEvent profilerStartedEvent =
runtime.initProfiler(
tracerEnabled,
storedEventHandler,
workspace,
commonOptions,
options.getOptions(BuildEventProtocolOptions.class),
env,
execStartTimeNanos,
waitTimeInMs);
storedEventHandler.post(profilerStartedEvent);
// Enable Starlark CPU profiling (--starlark_cpu_profile=/tmp/foo.pprof.gz)
boolean success = false;
if (!commonOptions.starlarkCpuProfile.isEmpty()) {
FileOutputStream out;
try {
out = new FileOutputStream(commonOptions.starlarkCpuProfile);
} catch (IOException ex) {
String message = "Starlark CPU profiler: " + ex.getMessage();
outErr.printErrLn(message);
return createDetailedCommandResult(
message, FailureDetails.Command.Code.STARLARK_CPU_PROFILE_FILE_INITIALIZATION_FAILURE);
}
try {
success = Starlark.startCpuProfile(out, Duration.ofMillis(10));
} catch (IllegalStateException ex) { // e.g. SIGPROF in use
String message = Strings.nullToEmpty(ex.getMessage());
outErr.printErrLn(message);
return createDetailedCommandResult(
message, FailureDetails.Command.Code.STARLARK_CPU_PROFILING_INITIALIZATION_FAILURE);
}
}
BlazeCommandResult result =
createDetailedCommandResult(
"Unknown command failure", FailureDetails.Command.Code.COMMAND_FAILURE_UNKNOWN);
boolean needToCallAfterCommand = true;
Reporter reporter = env.getReporter();
OutErr.SystemPatcher systemOutErrPatcher = reporter.getOutErr().getSystemPatcher();
try {
// Temporary: there are modules that output events during beforeCommand, but the reporter
// isn't setup yet. Add the stored event handler to catch those events.
reporter.addHandler(storedEventHandler);
for (BlazeModule module : runtime.getBlazeModules()) {
try (SilentCloseable closeable = Profiler.instance().profile(module + ".beforeCommand")) {
module.beforeCommand(env);
} catch (AbruptExitException e) {
logger.atInfo().withCause(e).log("Error in %s", module);
// Don't let one module's complaints prevent the other modules from doing necessary
// setup. We promised to call beforeCommand exactly once per-module before each command
// and will be calling afterCommand soon in the future - a module's afterCommand might
// rightfully assume its beforeCommand has already been called.
storedEventHandler.handle(Event.error(e.getMessage()));
// It's not ideal but we can only return one exit code, so we just pick the code of the
// last exception.
earlyExitCode = e.getDetailedExitCode();
}
}
reporter.removeHandler(storedEventHandler);
// Setup stdout / stderr.
outErr = tee(outErr, env.getOutputListeners());
// Early exit. We need to guarantee that the ErrOut and Reporter setup below never error out,
// so any invariants they need must be checked before this point.
if (!earlyExitCode.isSuccess()) {
replayEarlyExitEvents(
outErr,
optionHandler,
storedEventHandler,
env,
new NoBuildEvent(
commandName, firstContactTime, false, true, env.getCommandId().toString()));
result = BlazeCommandResult.detailedExitCode(earlyExitCode);
return result;
}
try (SilentCloseable closeable = Profiler.instance().profile("setup event handler")) {
UiOptions eventHandlerOptions = options.getOptions(UiOptions.class);
OutErr colorfulOutErr = outErr;
if (!eventHandlerOptions.useColor()) {
outErr = ansiStripOut(ansiStripErr(outErr));
if (!commandAnnotation.binaryStdOut()) {
colorfulOutErr = ansiStripOut(colorfulOutErr);
}
if (!commandAnnotation.binaryStdErr()) {
colorfulOutErr = ansiStripErr(colorfulOutErr);
}
}
if (!commandAnnotation.binaryStdOut()) {
outErr = bufferOut(outErr);
}
if (!commandAnnotation.binaryStdErr()) {
outErr = bufferErr(outErr);
}
DebugLoggerConfigurator.setupLogging(commonOptions.verbosity);
EventHandler handler = createEventHandler(outErr, eventHandlerOptions);
reporter.addHandler(handler);
env.getEventBus().register(handler);
// We register an ANSI-allowing handler associated with {@code handler} so that ANSI control
// codes can be re-introduced later even if blaze is invoked with --color=no. This is useful
// for commands such as 'blaze run' where the output of the final executable shouldn't be
// modified.
if (!eventHandlerOptions.useColor()) {
UiEventHandler ansiAllowingHandler =
createEventHandler(colorfulOutErr, eventHandlerOptions);
reporter.registerAnsiAllowingHandler(handler, ansiAllowingHandler);
env.getEventBus().register(new PassiveExperimentalEventHandler(ansiAllowingHandler));
}
}
try (SilentCloseable closeable = Profiler.instance().profile("replay stored events")) {
// Now we're ready to replay the events.
storedEventHandler.replayOn(reporter);
for (String warning : commandEnvWarnings) {
reporter.handle(Event.warn(warning));
}
}
try (SilentCloseable closeable = Profiler.instance().profile("announce rc options")) {
if (commonOptions.announceRcOptions) {
if (startupOptionsTaggedWithBazelRc.isPresent()) {
String lastBlazerc = "";
List<String> accumulatedStartupOptions = new ArrayList<>();
for (Pair<String, String> option : startupOptionsTaggedWithBazelRc.get()) {
// Do not include the command line options, marked by the empty string.
if (option.getFirst().isEmpty()) {
continue;
}
// If we've moved to a new blazerc in the list, print out the info from the last one,
// and clear the accumulated list.
if (!lastBlazerc.isEmpty() && !option.getFirst().equals(lastBlazerc)) {
String logMessage =
String.format(
"Reading 'startup' options from %s: %s",
lastBlazerc, String.join(", ", accumulatedStartupOptions));
reporter.handle(Event.info(logMessage));
accumulatedStartupOptions = new ArrayList<>();
}
lastBlazerc = option.getFirst();
accumulatedStartupOptions.add(option.getSecond());
}
// Print out the final blazerc-grouped list, if any startup options were provided by
// blazerc.
if (!lastBlazerc.isEmpty()) {
String logMessage =
String.format(
"Reading 'startup' options from %s: %s",
lastBlazerc, String.join(", ", accumulatedStartupOptions));
reporter.handle(Event.info(logMessage));
}
}
for (String note : optionHandler.getRcfileNotes()) {
reporter.handle(Event.info(note));
}
}
}
// While a Blaze command is active, direct all errors to the client's event handler (and
// out/err streams).
systemOutErrPatcher.start();
try (SilentCloseable closeable = Profiler.instance().profile("CommandEnv.beforeCommand")) {
// Notify the BlazeRuntime, so it can do some initial setup.
env.beforeCommand(invocationPolicy);
} catch (AbruptExitException e) {
logger.atInfo().withCause(e).log("Error before command");
reporter.handle(Event.error(e.getMessage()));
result = BlazeCommandResult.detailedExitCode(e.getDetailedExitCode());
return result;
}
// Log the command line now that the modules have all had a change to register their listeners
// to the event bus.
env.getEventBus().post(unstructuredServerCommandLineEvent);
env.getEventBus().post(originalCommandLineEvent);
env.getEventBus().post(canonicalCommandLineEvent);
env.getEventBus().post(commonOptions.toolCommandLine);
for (BlazeModule module : runtime.getBlazeModules()) {
try (SilentCloseable closeable =
Profiler.instance().profile(module + ".injectExtraPrecomputedValues")) {
env.getSkyframeExecutor().injectExtraPrecomputedValues(module.getPrecomputedValues());
}
}
// {@link CleanCommand} is annotated with {@code builds = true}
// to have access to relevant build options but don't actually do building.
// {@link InfoCommand} is annotated with {@code builds = true} but only conditionally
// does this step based on some complicated logic.
if (commandAnnotation.builds()
&& !commandAnnotation.name().equals("clean")
&& !commandAnnotation.name().equals("info")) {
try {
env.syncPackageLoading(options);
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
String message = "command interrupted while syncing package loading";
reporter.handle(Event.error(message));
earlyExitCode = InterruptedFailureDetails.detailedExitCode(message);
} catch (AbruptExitException e) {
logger.atInfo().withCause(e).log("Error package loading");
reporter.handle(Event.error(e.getMessage()));
earlyExitCode = e.getDetailedExitCode();
}
if (!earlyExitCode.isSuccess()) {
replayEarlyExitEvents(
outErr,
optionHandler,
storedEventHandler,
env,
new NoBuildEvent(
commandName, firstContactTime, false, true, env.getCommandId().toString()));
result = BlazeCommandResult.detailedExitCode(earlyExitCode);
return result;
}
}
// Parse starlark options.
earlyExitCode = optionHandler.parseStarlarkOptions(env, storedEventHandler);
if (!earlyExitCode.isSuccess()) {
replayEarlyExitEvents(
outErr,
optionHandler,
storedEventHandler,
env,
new NoBuildEvent(
commandName, firstContactTime, false, true, env.getCommandId().toString()));
result = BlazeCommandResult.detailedExitCode(earlyExitCode);
return result;
}
options = optionHandler.getOptionsResult();
// Run the command.
result = command.exec(env, options);
DetailedExitCode moduleExitCode = env.precompleteCommand(result.getDetailedExitCode());
// If Blaze did not suffer an infrastructure failure, check for errors in modules.
if (!result.getExitCode().isInfrastructureFailure() && moduleExitCode != null) {
result = BlazeCommandResult.detailedExitCode(moduleExitCode);
}
// Finalize the Starlark CPU profile.
if (!commonOptions.starlarkCpuProfile.isEmpty() && success) {
try {
Starlark.stopCpuProfile();
} catch (IOException ex) {
String message = "Starlark CPU profiler: " + ex.getMessage();
reporter.handle(Event.error(message));
if (result.getDetailedExitCode().isSuccess()) { // don't clobber existing error
result =
createDetailedCommandResult(
message, FailureDetails.Command.Code.STARLARK_CPU_PROFILE_FILE_WRITE_FAILURE);
}
}
}
needToCallAfterCommand = false;
return runtime.afterCommand(env, result);
} catch (Throwable e) {
logger.atSevere().withCause(e).log("Shutting down due to exception");
Crash crash = Crash.from(e);
bugReporter.handleCrash(crash, CrashContext.keepAlive().withArgs(args));
needToCallAfterCommand = false; // We are crashing.
result = BlazeCommandResult.createShutdown(crash);
return result;
} finally {
if (needToCallAfterCommand) {
BlazeCommandResult newResult = runtime.afterCommand(env, result);
if (!newResult.equals(result)) {
logger.atWarning().log("afterCommand yielded different result: %s %s", result, newResult);
}
}
try {
Profiler.instance().stop();
MemoryProfiler.instance().stop();
} catch (IOException e) {
env.getReporter()
.handle(Event.error("Error while writing profile file: " + e.getMessage()));
}
// Swallow IOException, as we are already in a finally clause
Flushables.flushQuietly(outErr.getOutputStream());
Flushables.flushQuietly(outErr.getErrorStream());
systemOutErrPatcher.close();
env.getTimestampGranularityMonitor().waitForTimestampGranularity(outErr);
}
}