Migrating to fluent logging (green).
I did some minor clean-ups of the resulting logging statements (mostly moving/adding exceptions as causes that were missed), and a few other drive-bys.
PiperOrigin-RevId: 306429419
diff --git a/src/main/java/com/google/devtools/build/lib/BUILD b/src/main/java/com/google/devtools/build/lib/BUILD
index d1acc3b..5aa7e84 100644
--- a/src/main/java/com/google/devtools/build/lib/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/BUILD
@@ -176,6 +176,7 @@
"//src/main/java/com/google/devtools/build/lib/util",
"//src/main/java/com/google/devtools/common/options",
"//third_party:auto_value",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
],
@@ -463,6 +464,7 @@
"//src/main/java/com/google/devtools/build/lib/util:resource_converter",
"//src/main/java/com/google/devtools/build/lib/vfs:pathfragment",
"//src/main/java/com/google/devtools/common/options",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
],
@@ -481,6 +483,7 @@
"//src/main/java/com/google/devtools/build/lib/actions:localhost_capacity",
"//src/main/java/com/google/devtools/build/lib/util:resource_converter",
"//src/main/java/com/google/devtools/common/options",
+ "//third_party:flogger",
],
)
@@ -511,6 +514,7 @@
"//src/main/protobuf:command_server_java_proto",
"//src/main/protobuf:failure_details_java_proto",
"//src/main/protobuf:invocation_policy_java_proto",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
"//third_party/grpc:grpc-jar",
@@ -530,6 +534,7 @@
"//src/main/java/com/google/devtools/build/lib/util:exit_code",
"//src/main/java/com/google/devtools/build/lib/util:logging",
"//src/main/java/com/google/devtools/build/lib/util/io:out-err",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
],
@@ -647,6 +652,7 @@
],
deps = [
"//src/main/java/com/google/devtools/build/lib/util:string",
+ "//third_party:flogger",
"//third_party:guava",
],
)
diff --git a/src/main/java/com/google/devtools/build/lib/analysis/BlazeVersionInfo.java b/src/main/java/com/google/devtools/build/lib/analysis/BlazeVersionInfo.java
index 9adf996..0024b85 100644
--- a/src/main/java/com/google/devtools/build/lib/analysis/BlazeVersionInfo.java
+++ b/src/main/java/com/google/devtools/build/lib/analysis/BlazeVersionInfo.java
@@ -16,10 +16,10 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.collect.ImmutableMap;
import com.google.common.collect.Maps;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.util.StringUtilities;
import java.util.Date;
import java.util.Map;
-import java.util.logging.Logger;
/**
* Determines the version information of the current process.
@@ -31,15 +31,15 @@
*/
public class BlazeVersionInfo {
public static final String BUILD_LABEL = "Build label";
-
- private final Map<String, String> buildData = Maps.newTreeMap();
- private static BlazeVersionInfo instance = null;
-
- private static final Logger logger = Logger.getLogger(BlazeVersionInfo.class.getName());
-
/** Key for the release timestamp is seconds. */
public static final String BUILD_TIMESTAMP = "Build timestamp as int";
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
+
+ private static BlazeVersionInfo instance = null;
+
+ private final Map<String, String> buildData = Maps.newTreeMap();
+
public BlazeVersionInfo(Map<String, String> info) {
buildData.putAll(info);
}
@@ -59,9 +59,9 @@
private static void logVersionInfo(BlazeVersionInfo info) {
if (info.getSummary() == null) {
- logger.warning("Bazel release version information not available");
+ logger.atWarning().log("Bazel release version information not available");
} else {
- logger.info("Bazel version info: " + info.getSummary());
+ logger.atInfo().log("Bazel version info: %s", info.getSummary());
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/analysis/config/BuildOptions.java b/src/main/java/com/google/devtools/build/lib/analysis/config/BuildOptions.java
index 5f81b3e..f404e1c3 100644
--- a/src/main/java/com/google/devtools/build/lib/analysis/config/BuildOptions.java
+++ b/src/main/java/com/google/devtools/build/lib/analysis/config/BuildOptions.java
@@ -31,6 +31,7 @@
import com.google.common.collect.Multimap;
import com.google.common.collect.Ordering;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.cmdline.Label;
import com.google.devtools.build.lib.skyframe.serialization.DeserializationContext;
import com.google.devtools.build.lib.skyframe.serialization.ObjectCodec;
@@ -66,8 +67,6 @@
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ExecutionException;
-import java.util.logging.Level;
-import java.util.logging.Logger;
import java.util.stream.Collectors;
import javax.annotation.Nullable;
@@ -79,7 +78,7 @@
private static final Comparator<Class<? extends FragmentOptions>>
lexicalFragmentOptionsComparator = Comparator.comparing(Class::getName);
private static final Comparator<Label> skylarkOptionsComparator = Ordering.natural();
- private static final Logger logger = Logger.getLogger(BuildOptions.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
public static Map<Label, Object> labelizeStarlarkOptions(Map<String, Object> starlarkOptions) {
return starlarkOptions.entrySet().stream()
@@ -1185,14 +1184,9 @@
int optionsDiffSize = byteStringOut.size();
bytes = byteStringOut.toByteString();
cache.putBytesFromOptionsDiff(diff, bytes);
- if (logger.isLoggable(Level.FINE)) {
- logger.fine(
- "Serialized OptionsDiffForReconstruction "
- + diff
- + ". Diff took "
- + optionsDiffSize
- + " bytes.");
- }
+ logger.atFine().log(
+ "Serialized OptionsDiffForReconstruction %s. Diff took %d bytes.",
+ diff, optionsDiffSize);
}
codedOut.writeBytesNoTag(bytes);
}
diff --git a/src/main/java/com/google/devtools/build/lib/bugreport/BugReport.java b/src/main/java/com/google/devtools/build/lib/bugreport/BugReport.java
index dc512d1..a853d93 100644
--- a/src/main/java/com/google/devtools/build/lib/bugreport/BugReport.java
+++ b/src/main/java/com/google/devtools/build/lib/bugreport/BugReport.java
@@ -19,6 +19,7 @@
import com.google.common.base.Preconditions;
import com.google.common.base.Throwables;
import com.google.common.collect.ImmutableList;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.analysis.BlazeVersionInfo;
import com.google.devtools.build.lib.util.CrashFailureDetails;
import com.google.devtools.build.lib.util.CustomExitCodePublisher;
@@ -31,7 +32,6 @@
import java.util.Arrays;
import java.util.List;
import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -43,7 +43,7 @@
*/
public abstract class BugReport {
- private static final Logger logger = Logger.getLogger(BugReport.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
static final BugReporter REPORTER_INSTANCE = new DefaultBugReporter();
@@ -125,7 +125,7 @@
"Bug reports in tests should crash: " + args + ", " + Arrays.toString(values), exception);
}
if (!versionInfo.isReleasedBlaze()) {
- logger.info("(Not a released binary; not logged.)");
+ logger.atInfo().log("(Not a released binary; not logged.)");
return;
}
@@ -133,7 +133,7 @@
}
private static void logCrash(Throwable throwable, boolean sendBugReport, String... args) {
- logger.severe("Crash: " + throwable + " " + Throwables.getStackTraceAsString(throwable));
+ logger.atSevere().withCause(throwable).log("Crash");
if (sendBugReport) {
BugReport.sendBugReport(throwable, Arrays.asList(args));
}
@@ -249,7 +249,7 @@
PrintStream err = new PrintStream(outErr.getErrorStream());
e.printStackTrace(err);
err.flush();
- logger.log(Level.SEVERE, getProductName() + " crashed", e);
+ logger.atSevere().withCause(e).log("%s crashed", getProductName());
}
/**
@@ -299,7 +299,7 @@
// Log the exception. Because this method is only called in a blaze release,
// this will result in a report being sent to a remote logging service.
private static void logException(Throwable exception, List<String> args, String... values) {
- logger.severe("Exception: " + Throwables.getStackTraceAsString(exception));
+ logger.atSevere().withCause(exception).log("Exception");
// The preamble is used in the crash watcher, so don't change it
// unless you know what you're doing.
String preamble = getProductName()
diff --git a/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceUploader.java b/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceUploader.java
index 6d5d65d..4c830e3 100644
--- a/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceUploader.java
+++ b/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceUploader.java
@@ -24,6 +24,7 @@
import com.google.common.base.Throwables;
import com.google.common.collect.Iterables;
import com.google.common.eventbus.EventBus;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.util.concurrent.FutureCallback;
import com.google.common.util.concurrent.Futures;
import com.google.common.util.concurrent.ListenableFuture;
@@ -76,8 +77,6 @@
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
import java.util.function.Consumer;
-import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.concurrent.GuardedBy;
/**
@@ -91,7 +90,7 @@
// different packages and rely on this.
@VisibleForTesting
public final class BuildEventServiceUploader implements Runnable {
- private static final Logger logger = Logger.getLogger(BuildEventServiceUploader.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/** Configuration knobs related to RPC retries. Values chosen by good judgement. */
private static final int MAX_NUM_RETRIES =
@@ -276,7 +275,7 @@
private void logAndExitAbruptly(
String message, ExitCode exitCode, BuildProgress.Code bpCode, Throwable cause) {
checkState(!exitCode.equals(ExitCode.SUCCESS));
- logger.severe(message);
+ logger.atSevere().log(message);
DetailedExitCode detailedExitCode =
DetailedExitCode.of(
exitCode,
@@ -308,7 +307,7 @@
}
}
} catch (InterruptedException e) {
- logger.info("Aborting the BES upload due to having received an interrupt");
+ logger.atInfo().log("Aborting the BES upload due to having received an interrupt");
synchronized (lock) {
Preconditions.checkState(
interruptCausedByCancel, "Unexpected interrupt on BES uploader thread");
@@ -330,7 +329,7 @@
e.getCause());
} catch (Throwable e) {
closeFuture.setException(e);
- logger.severe("BES upload failed due to a RuntimeException / Error. This is a bug.");
+ logger.atSevere().log("BES upload failed due to a RuntimeException / Error. This is a bug.");
throw e;
} finally {
buildEventUploader.shutdown();
@@ -407,8 +406,7 @@
{
// Invariant: the eventQueue only contains events of type SEND_REGULAR_BUILD_EVENT
// or SEND_LAST_BUILD_EVENT
- logger.info(
- String.format("Starting publishBuildEvents: eventQueue=%d", eventQueue.size()));
+ logger.atInfo().log("Starting publishBuildEvents: eventQueue=%d", eventQueue.size());
streamContext =
besClient.openStream(
(ack) -> eventQueue.addLast(new AckReceivedCommand(ack.getSequenceNumber())));
@@ -451,7 +449,7 @@
streamContext.sendOverStream(request);
streamContext.halfCloseStream();
halfCloseFuture.set(null);
- logger.info("BES uploader is half-closed");
+ logger.atInfo().log("BES uploader is half-closed");
}
break;
@@ -470,7 +468,7 @@
String.format(
"Expected ACK with seqNum=%d but received ACK with seqNum=%d",
expected.getSequenceNumber(), actualSeqNum);
- logger.info(message);
+ logger.atInfo().log(message);
streamContext.abortStream(Status.FAILED_PRECONDITION.withDescription(message));
}
} else {
@@ -478,7 +476,7 @@
String.format(
"Received ACK (seqNum=%d) when no ACK was expected",
ackEvent.getSequenceNumber());
- logger.info(message);
+ logger.atInfo().log(message);
streamContext.abortStream(Status.FAILED_PRECONDITION.withDescription(message));
}
}
@@ -493,7 +491,7 @@
Status streamStatus = completeEvent.status();
if (streamStatus.isOk()) {
if (lastEventSent && ackQueue.isEmpty()) {
- logger.info("publishBuildEvents was successful");
+ logger.atInfo().log("publishBuildEvents was successful");
// Upload successful. Break out from the while(true) loop.
return;
} else {
@@ -512,7 +510,7 @@
if (!shouldRetryStatus(streamStatus)) {
String message =
String.format("Not retrying publishBuildEvents: status='%s'", streamStatus);
- logger.info(message);
+ logger.atInfo().log(message);
throw withFailureDetail(
streamStatus.asException(),
BuildProgress.Code.BES_STREAM_NOT_RETRYING_FAILURE,
@@ -523,7 +521,7 @@
String.format(
"Not retrying publishBuildEvents, no more attempts left: status='%s'",
streamStatus);
- logger.info(message);
+ logger.atInfo().log(message);
throw withFailureDetail(
streamStatus.asException(),
BuildProgress.Code.BES_UPLOAD_RETRY_LIMIT_EXCEEDED_FAILURE,
@@ -539,9 +537,8 @@
}
long sleepMillis = retrySleepMillis(retryAttempt);
- logger.info(
- String.format(
- "Retrying stream: status='%s', sleepMillis=%d", streamStatus, sleepMillis));
+ logger.atInfo().log(
+ "Retrying stream: status='%s', sleepMillis=%d", streamStatus, sleepMillis);
sleeper.sleepMillis(sleepMillis);
// If we made progress, meaning the server ACKed events that we sent, then reset
@@ -559,21 +556,20 @@
}
} catch (InterruptedException | LocalFileUploadException e) {
int limit = 30;
- logger.info(
- String.format(
- "Publish interrupt. Showing up to %d items from queues: ack_queue_size: %d, "
- + "ack_queue: %s, event_queue_size: %d, event_queue: %s",
- limit,
- ackQueue.size(),
- Iterables.limit(ackQueue, limit),
- eventQueue.size(),
- Iterables.limit(eventQueue, limit)));
+ logger.atInfo().log(
+ "Publish interrupt. Showing up to %d items from queues: ack_queue_size: %d, "
+ + "ack_queue: %s, event_queue_size: %d, event_queue: %s",
+ limit,
+ ackQueue.size(),
+ Iterables.limit(ackQueue, limit),
+ eventQueue.size(),
+ Iterables.limit(eventQueue, limit));
if (streamContext != null) {
streamContext.abortStream(Status.CANCELLED);
}
throw e;
} finally {
- logger.info("About to cancel all local file uploads");
+ logger.atInfo().log("About to cancel all local file uploads");
try (AutoProfiler ignored = GoogleAutoProfilerUtils.logged("local file upload cancelation")) {
// Cancel all local file uploads that may still be running
// of events that haven't been uploaded.
@@ -612,17 +608,16 @@
if (!shouldRetryStatus(e.getStatus())) {
String message =
String.format("Not retrying publishLifecycleEvent: status='%s'", e.getStatus());
- logger.info(message);
+ logger.atInfo().log(message);
throw withFailureDetail(e, BuildProgress.Code.BES_STREAM_NOT_RETRYING_FAILURE, message);
}
cause = e;
long sleepMillis = retrySleepMillis(retryAttempt);
- logger.info(
- String.format(
- "Retrying publishLifecycleEvent: status='%s', sleepMillis=%d",
- e.getStatus(), sleepMillis));
+ logger.atInfo().log(
+ "Retrying publishLifecycleEvent: status='%s', sleepMillis=%d",
+ e.getStatus(), sleepMillis);
sleeper.sleepMillis(sleepMillis);
retryAttempt++;
}
@@ -644,6 +639,7 @@
}
}
+ @SuppressWarnings("LogAndThrow") // Not confident in BES's error-handling.
private PathConverter waitForUploads(SendRegularBuildEventCommand orderedBuildEvent)
throws LocalFileUploadException, InterruptedException {
try {
@@ -653,10 +649,8 @@
.get();
return orderedBuildEvent.localFileUploadProgress().get();
} catch (ExecutionException e) {
- logger.log(
- Level.WARNING,
- String.format("Failed to upload files referenced by build event: %s", e.getMessage()),
- e);
+ logger.atWarning().withCause(e).log(
+ "Failed to upload files referenced by build event: %s", e.getMessage());
Throwables.throwIfUnchecked(e.getCause());
throw new LocalFileUploadException(e.getCause());
}
diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java b/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java
index c45aa64..21d6f10 100644
--- a/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java
+++ b/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java
@@ -15,6 +15,7 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.cache.CacheBuilderSpec;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.LocalHostCapacity;
import com.google.devtools.build.lib.util.OptionsUtils;
import com.google.devtools.build.lib.util.ResourceConverter;
@@ -33,7 +34,6 @@
import com.google.devtools.common.options.OptionsParsingException;
import com.google.devtools.common.options.RegexPatternOption;
import java.util.List;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -45,7 +45,7 @@
public class BuildRequestOptions extends OptionsBase {
public static final OptionDefinition EXPERIMENTAL_MULTI_CPU =
OptionsParser.getOptionDefinitionByName(BuildRequestOptions.class, "experimental_multi_cpu");
- private static final Logger logger = Logger.getLogger(BuildRequestOptions.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final int JOBS_TOO_HIGH_WARNING = 2500;
@VisibleForTesting public static final int MAX_JOBS = 5000;
@@ -493,12 +493,11 @@
String.format("Value '(%d)' must be at least %d.", value, minValue));
}
if (value > maxValue) {
- logger.warning(
- String.format(
- "Flag remoteWorker \"jobs\" ('%d') was set too high. "
- + "This is a result of passing large values to --local_resources or --jobs. "
- + "Using '%d' jobs",
- value, maxValue));
+ logger.atWarning().log(
+ "Flag remoteWorker \"jobs\" ('%d') was set too high. "
+ + "This is a result of passing large values to --local_resources or --jobs. "
+ + "Using '%d' jobs",
+ value, maxValue);
value = maxValue;
}
return value;
diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java b/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java
index ab878e9..7fc9102 100644
--- a/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java
+++ b/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java
@@ -19,6 +19,7 @@
import com.google.common.base.Preconditions;
import com.google.common.base.Throwables;
import com.google.common.collect.ImmutableList;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.BuildFailedException;
import com.google.devtools.build.lib.actions.TestExecException;
import com.google.devtools.build.lib.analysis.AnalysisResult;
@@ -50,8 +51,6 @@
import com.google.devtools.build.lib.vfs.Path;
import com.google.devtools.common.options.OptionsProvider;
import com.google.devtools.common.options.RegexPatternOption;
-import java.util.logging.Level;
-import java.util.logging.Logger;
/**
* Provides the bulk of the implementation of the 'blaze build' command.
@@ -66,7 +65,7 @@
*/
public class BuildTool {
- private static Logger logger = Logger.getLogger(BuildTool.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
protected final CommandEnvironment env;
protected final BlazeRuntime runtime;
@@ -120,7 +119,7 @@
try (SilentCloseable c = Profiler.instance().profile("BuildStartingEvent")) {
env.getEventBus().post(new BuildStartingEvent(env, request));
}
- logger.info("Build identifier: " + request.getId());
+ logger.atInfo().log("Build identifier: %s", request.getId());
// Error out early if multi_cpus is set, but we're not in build or test command.
if (!request.getMultiCpus().isEmpty()) {
@@ -416,11 +415,9 @@
if (detailedExitCode.isSuccess()) {
result.setDetailedExitCode(DetailedExitCode.justExitCode(ExitCode.INTERRUPTED));
} else if (!detailedExitCode.getExitCode().equals(ExitCode.INTERRUPTED)) {
- logger.log(
- Level.WARNING,
- "Suppressed interrupted exception during stop request because already failing with: "
- + detailedExitCode,
- ie);
+ logger.atWarning().withCause(ie).log(
+ "Suppressed interrupted exception during stop request because already failing with: %s",
+ detailedExitCode);
}
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/SymlinkForest.java b/src/main/java/com/google/devtools/build/lib/buildtool/SymlinkForest.java
index e336c4f..fbaa9ac 100644
--- a/src/main/java/com/google/devtools/build/lib/buildtool/SymlinkForest.java
+++ b/src/main/java/com/google/devtools/build/lib/buildtool/SymlinkForest.java
@@ -21,6 +21,7 @@
import com.google.common.collect.Iterables;
import com.google.common.collect.Maps;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.cmdline.LabelConstants;
import com.google.devtools.build.lib.cmdline.PackageIdentifier;
import com.google.devtools.build.lib.cmdline.RepositoryName;
@@ -42,14 +43,10 @@
import java.util.Collections;
import java.util.Map;
import java.util.Set;
-import java.util.logging.Level;
-import java.util.logging.Logger;
/** Creates a symlink forest based on a package path map. */
public class SymlinkForest {
-
- private static final Logger logger = Logger.getLogger(SymlinkForest.class.getName());
- private static final boolean LOG_FINER = logger.isLoggable(Level.FINER);
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final ImmutableMap<PackageIdentifier, Root> packageRoots;
private final Path execroot;
@@ -242,9 +239,8 @@
.createDirectoryAndParents();
}
if (dirRootsMap.get(dir).size() > 1) {
- if (LOG_FINER) {
- logger.finer("mkdir " + execroot.getRelative(dir.getExecPath(siblingRepositoryLayout)));
- }
+ logger.atFiner().log(
+ "mkdir %s", execroot.getRelative(dir.getExecPath(siblingRepositoryLayout)));
execroot.getRelative(dir.getExecPath(siblingRepositoryLayout)).createDirectoryAndParents();
}
}
@@ -261,9 +257,7 @@
// This is the top-most dir that can be linked to a single root. Make it so.
Root root = roots.iterator().next(); // lone root in set
Path link = execroot.getRelative(dir.getExecPath(siblingRepositoryLayout));
- if (LOG_FINER) {
- logger.finer("ln -s " + root.getRelative(dir.getSourceRoot()) + " " + link);
- }
+ logger.atFiner().log("ln -s %s %s", root.getRelative(dir.getSourceRoot()), link);
link.createSymbolicLink(root.getRelative(dir.getSourceRoot()));
plantedSymlinks.add(link);
}
@@ -278,10 +272,8 @@
try {
Path absdir = root.getRelative(dir.getSourceRoot());
if (absdir.isDirectory()) {
- if (LOG_FINER) {
- logger.finer(
- "ln -s " + absdir + "/* " + execroot.getRelative(dir.getSourceRoot()) + "/");
- }
+ logger.atFiner().log(
+ "ln -s %s/* %s/", absdir, execroot.getRelative(dir.getSourceRoot()));
for (Path target : absdir.getDirectoryEntries()) {
PathFragment p = root.relativize(target);
if (!dirRootsMap.containsKey(createInRepo(pkgId, p))) {
@@ -290,17 +282,14 @@
}
}
} else {
- logger.fine("Symlink planting skipping dir '" + absdir + "'");
+ logger.atFine().log("Symlink planting skipping dir '%s'", absdir);
}
} catch (IOException e) {
// TODO(arostovtsev): Why are we swallowing the IOException here instead of letting it
// be thrown?
- logger.log(
- Level.WARNING,
- "I/O error while planting symlinks to contents of '"
- + root.getRelative(dir.getSourceRoot())
- + "'",
- e);
+ logger.atWarning().withCause(e).log(
+ "I/O error while planting symlinks to contents of '%s'",
+ root.getRelative(dir.getSourceRoot()));
}
// Otherwise its just an otherwise empty common parent dir.
}
@@ -420,7 +409,7 @@
plantSymlinkForestWithPartialMainRepository(plantedSymlinks, mainRepoLinks);
}
- logger.info("Planted symlink forest in " + execroot);
+ logger.atInfo().log("Planted symlink forest in %s", execroot);
return plantedSymlinks.build();
}
diff --git a/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java b/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java
index 38bf09b..7223b86 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/SpawnLogContext.java
@@ -15,6 +15,7 @@
import build.bazel.remote.execution.v2.Platform;
import com.google.common.base.Preconditions;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.hash.HashCode;
import com.google.devtools.build.lib.actions.ActionContext;
import com.google.devtools.build.lib.actions.ActionInput;
@@ -48,8 +49,6 @@
import java.util.TreeMap;
import java.util.TreeSet;
import java.util.function.Consumer;
-import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -57,7 +56,7 @@
*/
public class SpawnLogContext implements ActionContext {
- private static final Logger logger = Logger.getLogger(SpawnLogContext.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final Path execRoot;
private final MessageOutputStream executionLog;
@Nullable private final RemoteOptions remoteOptions;
@@ -100,7 +99,7 @@
}
}
} catch (IOException e) {
- logger.log(Level.WARNING, "Error computing spawn inputs", e);
+ logger.atWarning().withCause(e).log("Error computing spawn inputs");
}
ArrayList<String> outputPaths = new ArrayList<>();
for (ActionInput output : spawn.getOutputFiles()) {
@@ -118,7 +117,7 @@
try {
outputBuilder.setDigest(computeDigest(e.getValue(), path, metadataProvider));
} catch (IOException ex) {
- logger.log(Level.WARNING, "Error computing spawn event output properties", ex);
+ logger.atWarning().withCause(ex).log("Error computing spawn event output properties");
}
}
}
@@ -190,7 +189,7 @@
}
}
} catch (IOException e) {
- logger.log(Level.WARNING, "Error computing spawn event file properties", e);
+ logger.atWarning().withCause(e).log("Error computing spawn event file properties");
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/remote/BUILD b/src/main/java/com/google/devtools/build/lib/remote/BUILD
index 6bc20f7..7185151 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/remote/BUILD
@@ -70,6 +70,7 @@
"//src/main/java/com/google/devtools/build/lib/vfs:pathfragment",
"//src/main/java/com/google/devtools/common/options",
"//third_party:auth",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
"//third_party:netty",
diff --git a/src/main/java/com/google/devtools/build/lib/remote/ByteStreamUploader.java b/src/main/java/com/google/devtools/build/lib/remote/ByteStreamUploader.java
index 90c9e45..711cdd1 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/ByteStreamUploader.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/ByteStreamUploader.java
@@ -27,6 +27,7 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.Strings;
import com.google.common.base.Throwables;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.hash.HashCode;
import com.google.common.util.concurrent.Futures;
import com.google.common.util.concurrent.ListenableFuture;
@@ -56,8 +57,6 @@
import java.util.concurrent.ExecutionException;
import java.util.concurrent.Future;
import java.util.concurrent.atomic.AtomicLong;
-import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
import javax.annotation.concurrent.GuardedBy;
@@ -71,7 +70,7 @@
*/
class ByteStreamUploader extends AbstractReferenceCounted {
- private static final Logger logger = Logger.getLogger(ByteStreamUploader.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final String instanceName;
private final ReferenceCountedChannel channel;
@@ -543,7 +542,7 @@
// This exception indicates that closing the underlying input stream failed.
// We don't expect this to ever happen, but don't want to swallow the exception
// completely.
- logger.log(Level.WARNING, "Chunker failed closing data source.", e1);
+ logger.atWarning().withCause(e1).log("Chunker failed closing data source.");
} finally {
call.cancel("Failed to read next chunk.", e);
}
diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteActionInputFetcher.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteActionInputFetcher.java
index 72c6d54..b47b728 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteActionInputFetcher.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/RemoteActionInputFetcher.java
@@ -17,6 +17,7 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.Preconditions;
import com.google.common.collect.ImmutableSet;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.util.concurrent.FutureCallback;
import com.google.common.util.concurrent.Futures;
import com.google.common.util.concurrent.ListenableFuture;
@@ -41,8 +42,6 @@
import java.util.Map;
import java.util.Set;
import java.util.concurrent.ExecutionException;
-import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.concurrent.GuardedBy;
/**
@@ -53,7 +52,7 @@
*/
class RemoteActionInputFetcher implements ActionInputPrefetcher {
- private static final Logger logger = Logger.getLogger(RemoteActionInputFetcher.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final Object lock = new Object();
@@ -191,7 +190,7 @@
try {
path.chmod(0755);
} catch (IOException e) {
- logger.log(Level.WARNING, "Failed to chmod 755 on " + path, e);
+ logger.atWarning().withCause(e).log("Failed to chmod 755 on %s", path);
}
}
@@ -203,10 +202,8 @@
try {
path.delete();
} catch (IOException e) {
- logger.log(
- Level.WARNING,
- "Failed to delete output file after incomplete download: " + path,
- e);
+ logger.atWarning().withCause(e).log(
+ "Failed to delete output file after incomplete download: %s", path);
}
}
},
diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteModule.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteModule.java
index d8aaf0b..770e7db 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteModule.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/RemoteModule.java
@@ -21,6 +21,7 @@
import com.google.common.base.Throwables;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableSet;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.util.concurrent.ListeningScheduledExecutorService;
import com.google.common.util.concurrent.MoreExecutors;
import com.google.devtools.build.lib.actions.ActionInput;
@@ -79,13 +80,11 @@
import java.util.List;
import java.util.Optional;
import java.util.concurrent.Executors;
-import java.util.logging.Level;
-import java.util.logging.Logger;
/** RemoteModule provides distributed cache and remote execution for Bazel. */
public final class RemoteModule extends BlazeModule {
- private static final Logger logger = Logger.getLogger(RemoteModule.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private AsynchronousFileOutputStream rpcLogFile;
@@ -514,7 +513,7 @@
try {
closeRpcLogFile();
} catch (IOException e) {
- logger.log(Level.WARNING, "Partially wrote rpc log file", e);
+ logger.atWarning().withCause(e).log("Partially wrote rpc log file");
failure = e;
}
@@ -551,10 +550,8 @@
try {
file.delete();
} catch (IOException e) {
- logger.log(
- Level.SEVERE,
- String.format("Failed to delete remote output '%s' from the " + "output base.", file),
- e);
+ logger.atSevere().withCause(e).log(
+ "Failed to delete remote output '%s' from the output base.", file);
deletionFailure = e;
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
index d76e9fa..1df9fa7 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandDispatcher.java
@@ -22,6 +22,7 @@
import com.google.common.cache.LoadingCache;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableSet;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.io.Flushables;
import com.google.common.util.concurrent.UncheckedExecutionException;
import com.google.devtools.build.lib.analysis.NoBuildEvent;
@@ -62,7 +63,6 @@
import java.util.List;
import java.util.Optional;
import java.util.logging.Level;
-import java.util.logging.Logger;
/**
* Dispatches to the Blaze commands; that is, given a command line, this abstraction looks up the
@@ -70,7 +70,7 @@
* Also, this object provides the runtime state (BlazeRuntime) to the commands.
*/
public class BlazeCommandDispatcher implements CommandDispatcher {
- private static final Logger logger = Logger.getLogger(BlazeCommandDispatcher.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final ImmutableList<String> HELP_COMMAND = ImmutableList.of("help");
@@ -573,7 +573,7 @@
e.printStackTrace();
BugReport.printBug(outErr, e, commonOptions.oomMessage);
bugReporter.sendBugReport(e, args);
- logger.log(Level.SEVERE, "Shutting down due to exception", e);
+ logger.atSevere().withCause(e).log("Shutting down due to exception");
result = BlazeCommandResult.createShutdown(e);
return result;
} finally {
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java b/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java
index ead6763..f3b4bc8 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/BuildSummaryStatsModule.java
@@ -17,6 +17,7 @@
import com.google.common.eventbus.AllowConcurrentEvents;
import com.google.common.eventbus.EventBus;
import com.google.common.eventbus.Subscribe;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.ActionKeyContext;
import com.google.devtools.build.lib.actions.ActionResultReceivedEvent;
import com.google.devtools.build.lib.buildtool.BuildRequest;
@@ -37,14 +38,13 @@
import java.nio.charset.StandardCharsets;
import java.util.ArrayList;
import java.util.List;
-import java.util.logging.Logger;
/**
* Blaze module for the build summary message that reports various stats to the user.
*/
public class BuildSummaryStatsModule extends BlazeModule {
- private static final Logger logger = Logger.getLogger(BuildSummaryStatsModule.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private ActionKeyContext actionKeyContext;
private CriticalPathComputer criticalPathComputer;
@@ -129,10 +129,10 @@
event.getResult().getBuildToolLogCollection()
.addDirectValue(
"critical path", criticalPath.toString().getBytes(StandardCharsets.UTF_8));
- logger.info(criticalPath.toString());
- logger.info(
- "Slowest actions:\n "
- + Joiner.on("\n ").join(criticalPathComputer.getSlowestComponents()));
+ logger.atInfo().log(criticalPath.toString());
+ logger.atInfo().log(
+ "Slowest actions:\n %s",
+ Joiner.on("\n ").join(criticalPathComputer.getSlowestComponents()));
// We reverse the critical path because the profiler expect events ordered by the time
// when the actions were executed while critical path computation is stored in the reverse
// way.
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java b/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java
index 00987ae9..520e02c 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/CacheFileDigestsModule.java
@@ -16,16 +16,16 @@
import com.google.common.base.Preconditions;
import com.google.common.cache.CacheStats;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.cache.DigestUtils;
import com.google.devtools.build.lib.buildtool.BuildRequest;
import com.google.devtools.build.lib.exec.ExecutionOptions;
import com.google.devtools.build.lib.exec.ExecutorBuilder;
-import java.util.logging.Logger;
/** Enables the caching of file digests in {@link DigestUtils}. */
public class CacheFileDigestsModule extends BlazeModule {
- private static final Logger logger = Logger.getLogger(CacheFileDigestsModule.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/** Stats gathered at the beginning of a command, to compute deltas on completion. */
private CacheStats stats;
@@ -45,16 +45,9 @@
* @param stats the cache statistics to be logged
*/
private static void logStats(String message, CacheStats stats) {
- logger.info(
- message
- + ": hit count="
- + stats.hitCount()
- + ", miss count="
- + stats.missCount()
- + ", hit rate="
- + stats.hitRate()
- + ", eviction count="
- + stats.evictionCount());
+ logger.atInfo().log(
+ "%s: hit count=%d, miss count=%d, hit rate=%g, eviction count=%d",
+ message, stats.hitCount(), stats.missCount(), stats.hitRate(), stats.evictionCount());
}
@Override
@@ -62,14 +55,15 @@
ExecutionOptions options = request.getOptions(ExecutionOptions.class);
if (lastKnownCacheSize == null
|| options.cacheSizeForComputedFileDigests != lastKnownCacheSize) {
- logger.info("Reconfiguring cache with size=" + options.cacheSizeForComputedFileDigests);
+ logger.atInfo().log(
+ "Reconfiguring cache with size=%d", options.cacheSizeForComputedFileDigests);
DigestUtils.configureCache(options.cacheSizeForComputedFileDigests);
lastKnownCacheSize = options.cacheSizeForComputedFileDigests;
}
if (options.cacheSizeForComputedFileDigests == 0) {
stats = null;
- logger.info("Disabled cache");
+ logger.atInfo().log("Disabled cache");
} else {
stats = DigestUtils.getCacheStats();
logStats("Accumulated cache stats before command", stats);
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/LoadingPhaseThreadsOption.java b/src/main/java/com/google/devtools/build/lib/runtime/LoadingPhaseThreadsOption.java
index 087a37e6..2962e44 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/LoadingPhaseThreadsOption.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/LoadingPhaseThreadsOption.java
@@ -13,6 +13,7 @@
// limitations under the License.
package com.google.devtools.build.lib.runtime;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.LocalHostCapacity;
import com.google.devtools.build.lib.util.ResourceConverter;
import com.google.devtools.common.options.Option;
@@ -20,12 +21,11 @@
import com.google.devtools.common.options.OptionEffectTag;
import com.google.devtools.common.options.OptionsBase;
import com.google.devtools.common.options.OptionsParsingException;
-import java.util.logging.Logger;
/** Defines the --loading_phase_threads option which is used by multiple commands. */
public class LoadingPhaseThreadsOption extends OptionsBase {
- private static final Logger logger = Logger.getLogger(LoadingPhaseThreadsOption.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
@Option(
name = "loading_phase_threads",
@@ -63,7 +63,7 @@
// TODO(jmmv): If tests care about this, it's them who should be setting a cap.
if (System.getenv("TEST_TMPDIR") != null) {
value = Math.min(20, value);
- logger.info("Running under a test; loading_phase_threads capped at " + value);
+ logger.atInfo().log("Running under a test; loading_phase_threads capped at %d", value);
}
return super.checkAndLimit(value);
}
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java b/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
index 87ad079..8a5c44c 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
@@ -17,6 +17,7 @@
import com.google.common.collect.ImmutableSet;
import com.google.common.eventbus.AllowConcurrentEvents;
import com.google.common.eventbus.Subscribe;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.primitives.Bytes;
import com.google.common.util.concurrent.Uninterruptibles;
import com.google.devtools.build.lib.actions.ActionCompletionEvent;
@@ -71,12 +72,11 @@
import java.util.concurrent.atomic.AtomicReference;
import java.util.concurrent.locks.Lock;
import java.util.concurrent.locks.ReentrantLock;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/** An experimental new output stream. */
public class UiEventHandler implements EventHandler {
- private static final Logger logger = Logger.getLogger(UiEventHandler.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/** Latest refresh of the progress bar, if contents other than time changed */
static final long MAXIMAL_UPDATE_DELAY_MILLIS = 200L;
/** Minimal rate limiting (in ms), if the progress bar cannot be updated in place */
@@ -335,7 +335,7 @@
didFlush = true;
}
} catch (IOException e) {
- logger.warning("IO Error writing to output stream: " + e);
+ logger.atWarning().withCause(e).log("IO Error writing to output stream");
}
return didFlush;
}
@@ -504,7 +504,7 @@
}
}
} catch (IOException e) {
- logger.warning("IO Error writing to output stream: " + e);
+ logger.atWarning().withCause(e).log("IO Error writing to output stream");
}
}
@@ -530,8 +530,7 @@
} else {
message = reference.getFinalBytes(MAXIMAL_MESSAGE_LENGTH);
if (message.length == MAXIMAL_MESSAGE_LENGTH) {
- logger.warning(
- String.format("truncated message longer than %d bytes", MAXIMAL_MESSAGE_LENGTH));
+ logger.atWarning().log("truncated message longer than %d bytes", MAXIMAL_MESSAGE_LENGTH);
}
}
int eolIndex = Bytes.lastIndexOf(message, (byte) '\n');
@@ -750,7 +749,7 @@
}
terminal.flush();
} catch (IOException e) {
- logger.warning("IO Error writing to output stream: " + e);
+ logger.atWarning().withCause(e).log("IO Error writing to output stream");
}
}
}
@@ -786,7 +785,7 @@
terminal.resetTerminal();
terminal.flush();
} catch (IOException e) {
- logger.warning("IO Error writing to user terminal: " + e);
+ logger.atWarning().withCause(e).log("IO Error writing to user terminal");
}
}
@@ -897,7 +896,7 @@
}
terminal.flush();
} catch (IOException e) {
- logger.warning("IO Error writing to output stream: " + e);
+ logger.atWarning().withCause(e).log("IO Error writing to output stream");
}
} else {
refresh();
@@ -976,7 +975,7 @@
}
}
} catch (IOException e) {
- logger.warning("IO Error writing to output stream: " + e);
+ logger.atWarning().withCause(e).log("IO Error writing to output stream");
} finally {
updateLock.unlock();
}
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/commands/CleanCommand.java b/src/main/java/com/google/devtools/build/lib/runtime/commands/CleanCommand.java
index 21532cf..36d5288 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/commands/CleanCommand.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/commands/CleanCommand.java
@@ -14,6 +14,7 @@
package com.google.devtools.build.lib.runtime.commands;
import com.google.common.annotations.VisibleForTesting;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.ExecException;
import com.google.devtools.build.lib.analysis.NoBuildEvent;
import com.google.devtools.build.lib.buildtool.BuildRequestOptions;
@@ -40,7 +41,6 @@
import java.io.FileOutputStream;
import java.io.IOException;
import java.util.logging.LogManager;
-import java.util.logging.Logger;
/** Implements 'blaze clean'. */
@Command(
@@ -120,7 +120,7 @@
this.os = os;
}
- private static final Logger logger = Logger.getLogger(CleanCommand.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
@Override
public BlazeCommandResult exec(CommandEnvironment env, OptionsParsingResult options) {
@@ -190,7 +190,7 @@
"exec >&- 2>&- <&- && (/usr/bin/setsid /bin/rm -rf %s &)&",
ShellEscaper.escapeString(tempPath.getPathString()));
- logger.info("Executing shell command " + ShellEscaper.escapeString(command));
+ logger.atInfo().log("Executing shell command %s", ShellEscaper.escapeString(command));
// Doesn't throw iff command exited and was successful.
new CommandBuilder()
@@ -212,7 +212,7 @@
}
env.getBlazeWorkspace().clearCaches();
if (expunge && !async) {
- logger.info("Expunging...");
+ logger.atInfo().log("Expunging...");
runtime.prepareForAbruptShutdown();
// Close java.log.
LogManager.getLogManager().reset();
@@ -234,15 +234,15 @@
outputBase.deleteTreesBelow();
outputBase.deleteTree();
} else if (expunge && async) {
- logger.info("Expunging asynchronously...");
+ logger.atInfo().log("Expunging asynchronously...");
runtime.prepareForAbruptShutdown();
asyncClean(env, outputBase, "Output base");
} else {
- logger.info("Output cleaning...");
+ logger.atInfo().log("Output cleaning...");
env.getBlazeWorkspace().resetEvaluator();
Path execroot = outputBase.getRelative("execroot");
if (execroot.exists()) {
- logger.finest("Cleaning " + execroot + (async ? " asynchronously..." : ""));
+ logger.atFinest().log("Cleaning %s%s", execroot, async ? " asynchronously..." : "");
if (async) {
asyncClean(env, execroot, "Output tree");
} else {
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/commands/InfoItem.java b/src/main/java/com/google/devtools/build/lib/runtime/commands/InfoItem.java
index 9697e88..a0e4e11 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/commands/InfoItem.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/commands/InfoItem.java
@@ -21,6 +21,7 @@
import com.google.common.base.Supplier;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.Iterables;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.analysis.BlazeVersionInfo;
import com.google.devtools.build.lib.analysis.config.BuildConfiguration;
import com.google.devtools.build.lib.cmdline.RepositoryName;
@@ -61,8 +62,6 @@
import java.util.List;
import java.util.Map;
import java.util.Optional;
-import java.util.logging.Level;
-import java.util.logging.Logger;
/**
* An item that is returned by <code>blaze info</code>.
@@ -285,7 +284,7 @@
/** Info item for server_log path. */
public static class ServerLogInfoItem extends InfoItem {
- private static final Logger logger = Logger.getLogger(ServerLogInfoItem.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* Constructs an info item for the server log path.
@@ -303,7 +302,7 @@
Optional<Path> path = env.getRuntime().getServerLogPath();
return print(path.map(Path::toString).orElse(""));
} catch (IOException e) {
- logger.log(Level.WARNING, "Failed to determine server log location", e);
+ logger.atWarning().withCause(e).log("Failed to determine server log location");
return print("UNKNOWN LOG LOCATION");
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/sandbox/AbstractContainerizingSandboxedSpawn.java b/src/main/java/com/google/devtools/build/lib/sandbox/AbstractContainerizingSandboxedSpawn.java
index 27f6691..9128729 100644
--- a/src/main/java/com/google/devtools/build/lib/sandbox/AbstractContainerizingSandboxedSpawn.java
+++ b/src/main/java/com/google/devtools/build/lib/sandbox/AbstractContainerizingSandboxedSpawn.java
@@ -16,6 +16,7 @@
import com.google.common.base.Preconditions;
import com.google.common.collect.Iterables;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.exec.TreeDeleter;
import com.google.devtools.build.lib.sandbox.SandboxHelpers.SandboxInputs;
import com.google.devtools.build.lib.sandbox.SandboxHelpers.SandboxOutputs;
@@ -29,7 +30,6 @@
import java.util.Map;
import java.util.Set;
import java.util.concurrent.atomic.AtomicBoolean;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -38,8 +38,7 @@
*/
public abstract class AbstractContainerizingSandboxedSpawn implements SandboxedSpawn {
- private static final Logger logger =
- Logger.getLogger(AbstractContainerizingSandboxedSpawn.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final AtomicBoolean warnedAboutMovesBeingCopies = new AtomicBoolean(false);
@@ -193,13 +192,11 @@
target.getParentDirectory().createDirectoryAndParents();
if (FileSystemUtils.moveFile(source, target).equals(MoveResult.FILE_COPIED)) {
if (warnedAboutMovesBeingCopies.compareAndSet(false, true)) {
- logger.warning(
- "Moving files out of the sandbox (e.g. from "
- + source
- + " to "
- + target
+ logger.atWarning().log(
+ "Moving files out of the sandbox (e.g. from %s to %s"
+ ") had to be done with a file copy, which is detrimental to performance; are "
- + " the two trees in different file systems?");
+ + " the two trees in different file systems?",
+ source, target);
}
}
} else if (source.isDirectory()) {
diff --git a/src/main/java/com/google/devtools/build/lib/sandbox/BUILD b/src/main/java/com/google/devtools/build/lib/sandbox/BUILD
index b7cac33..dff9604 100644
--- a/src/main/java/com/google/devtools/build/lib/sandbox/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/sandbox/BUILD
@@ -37,6 +37,7 @@
"//src/main/java/com/google/devtools/build/lib/vfs:pathfragment",
"//src/main/java/com/google/devtools/common/options",
"//third_party:auto_value",
+ "//third_party:flogger",
"//third_party:gson",
"//third_party:guava",
"//third_party:jsr305",
diff --git a/src/main/java/com/google/devtools/build/lib/sandbox/RealSandboxfsProcess.java b/src/main/java/com/google/devtools/build/lib/sandbox/RealSandboxfsProcess.java
index 8972a6d..2616a94 100644
--- a/src/main/java/com/google/devtools/build/lib/sandbox/RealSandboxfsProcess.java
+++ b/src/main/java/com/google/devtools/build/lib/sandbox/RealSandboxfsProcess.java
@@ -17,6 +17,7 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableMap;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.shell.Subprocess;
import com.google.devtools.build.lib.shell.SubprocessBuilder;
import com.google.devtools.build.lib.util.OS;
@@ -26,7 +27,6 @@
import com.google.devtools.build.lib.vfs.Path;
import com.google.devtools.build.lib.vfs.PathFragment;
import java.io.IOException;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -39,7 +39,7 @@
*/
abstract class RealSandboxfsProcess implements SandboxfsProcess {
- private static final Logger log = Logger.getLogger(RealSandboxfsProcess.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* Contains the {@code --allow} flag to pass to sandboxfs.
@@ -81,8 +81,9 @@
try {
this.destroy();
} catch (Exception e) {
- log.warning("Failed to destroy running sandboxfs instance; mount point may have "
- + "been left behind: " + e);
+ logger.atWarning().withCause(e).log(
+ "Failed to destroy running sandboxfs instance; mount point may have "
+ + "been left behind");
}
});
Runtime.getRuntime().addShutdownHook(shutdownHook);
@@ -105,7 +106,7 @@
*/
static SandboxfsProcess mount(PathFragment binary, Path mountPoint, Path logFile)
throws IOException {
- log.info("Mounting sandboxfs (" + binary + ") onto " + mountPoint);
+ logger.atInfo().log("Mounting sandboxfs (%s) onto %s", binary, mountPoint);
GnuVersionParser<SemVer> parser = new GnuVersionParser<>("sandboxfs", SemVer::parse);
SemVer version;
@@ -172,13 +173,13 @@
try {
process.getOutputStream().close();
} catch (IOException e) {
- log.warning("Failed to close sandboxfs's stdin pipe: " + e);
+ logger.atWarning().withCause(e).log("Failed to close sandboxfs's stdin pipe");
}
try {
process.getInputStream().close();
} catch (IOException e) {
- log.warning("Failed to close sandboxfs's stdout pipe: " + e);
+ logger.atWarning().withCause(e).log("Failed to close sandboxfs's stdout pipe");
}
process.destroyAndWait();
diff --git a/src/main/java/com/google/devtools/build/lib/sandbox/SandboxfsSandboxedSpawn.java b/src/main/java/com/google/devtools/build/lib/sandbox/SandboxfsSandboxedSpawn.java
index f7a454e..6ec3fc6 100644
--- a/src/main/java/com/google/devtools/build/lib/sandbox/SandboxfsSandboxedSpawn.java
+++ b/src/main/java/com/google/devtools/build/lib/sandbox/SandboxfsSandboxedSpawn.java
@@ -18,6 +18,7 @@
import static com.google.common.base.Preconditions.checkNotNull;
import com.google.common.base.Joiner;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.exec.TreeDeleter;
import com.google.devtools.build.lib.sandbox.SandboxHelpers.SandboxInputs;
import com.google.devtools.build.lib.sandbox.SandboxHelpers.SandboxOutputs;
@@ -31,7 +32,6 @@
import java.util.Map;
import java.util.Set;
import java.util.concurrent.atomic.AtomicInteger;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -39,7 +39,7 @@
* FUSE filesystem on the provided path.
*/
class SandboxfsSandboxedSpawn implements SandboxedSpawn {
- private static final Logger log = Logger.getLogger(SandboxfsSandboxedSpawn.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/** Sequence number to assign a unique subtree to each action within the mount point. */
private static final AtomicInteger lastId = new AtomicInteger();
@@ -216,7 +216,7 @@
// We use independent subdirectories for each action, so a failure to unmap one, while
// annoying, is not a big deal. The sandboxfs instance will be unmounted anyway after
// the build, which will cause these to go away anyway.
- log.warning("Cannot unmap " + sandboxName + ": " + e);
+ logger.atWarning().withCause(e).log("Cannot unmap %s", sandboxName);
}
sandboxIsMapped = false;
}
diff --git a/src/main/java/com/google/devtools/build/lib/sandbox/WindowsSandboxUtil.java b/src/main/java/com/google/devtools/build/lib/sandbox/WindowsSandboxUtil.java
index 93a0696..19d742e 100644
--- a/src/main/java/com/google/devtools/build/lib/sandbox/WindowsSandboxUtil.java
+++ b/src/main/java/com/google/devtools/build/lib/sandbox/WindowsSandboxUtil.java
@@ -17,6 +17,7 @@
import com.google.common.base.Preconditions;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableSet;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.io.ByteStreams;
import com.google.devtools.build.lib.shell.Subprocess;
import com.google.devtools.build.lib.shell.SubprocessBuilder;
@@ -32,11 +33,10 @@
import java.util.Map;
import java.util.Set;
import java.util.TreeMap;
-import java.util.logging.Logger;
/** Utility functions for the {@code windows-sandbox}. */
public final class WindowsSandboxUtil {
- private static final Logger log = Logger.getLogger(WindowsSandboxUtil.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* Checks if the given Windows sandbox binary is available and is valid.
@@ -55,7 +55,8 @@
.setWorkingDirectory(new File("."))
.start();
} catch (IOException e) {
- log.warning("Windows sandbox binary at " + binary + " seems to be missing; got error: " + e);
+ logger.atWarning().withCause(e).log(
+ "Windows sandbox binary at %s seems to be missing", binary);
return false;
}
@@ -79,13 +80,9 @@
// the DottedVersion logic from the Apple rules.
return true;
} else {
- log.warning(
- "Windows sandbox binary at "
- + binary
- + " returned non-zero exit code "
- + exitCode
- + " and output "
- + outErr);
+ logger.atWarning().log(
+ "Windows sandbox binary at %s returned non-zero exit code %d and output %s",
+ binary, exitCode, outErr);
return false;
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/server/CommandManager.java b/src/main/java/com/google/devtools/build/lib/server/CommandManager.java
index f133ce9..04f079c 100644
--- a/src/main/java/com/google/devtools/build/lib/server/CommandManager.java
+++ b/src/main/java/com/google/devtools/build/lib/server/CommandManager.java
@@ -16,6 +16,7 @@
import com.google.common.base.Preconditions;
import com.google.common.collect.ImmutableSet;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.server.CommandProtos.CancelRequest;
import com.google.devtools.build.lib.util.ThreadUtils;
import java.util.Collections;
@@ -23,12 +24,11 @@
import java.util.Map;
import java.util.UUID;
import java.util.concurrent.atomic.AtomicLong;
-import java.util.logging.Logger;
import javax.annotation.concurrent.GuardedBy;
/** Helper class for commands that are currently running on the server. */
class CommandManager {
- private static final Logger logger = Logger.getLogger(CommandManager.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
@GuardedBy("runningCommandsMap")
private final Map<String, RunningCommand> runningCommandsMap = new HashMap<>();
@@ -58,14 +58,13 @@
synchronized (runningCommandsMap) {
RunningCommand pendingCommand = runningCommandsMap.get(request.getCommandId());
if (pendingCommand != null) {
- logger.info(
- String.format(
- "Interrupting command %s on thread %s",
- request.getCommandId(), pendingCommand.thread.getName()));
+ logger.atInfo().log(
+ "Interrupting command %s on thread %s",
+ request.getCommandId(), pendingCommand.thread.getName());
pendingCommand.thread.interrupt();
startSlowInterruptWatcher(ImmutableSet.of(request.getCommandId()));
} else {
- logger.info("Cannot find command " + request.getCommandId() + " to interrupt");
+ logger.atInfo().log("Cannot find command %s to interrupt", request.getCommandId());
}
}
}
@@ -98,8 +97,7 @@
runningCommandsMap.put(command.id, command);
runningCommandsMap.notify();
}
- logger.info(
- String.format("Starting command %s on thread %s", command.id, command.thread.getName()));
+ logger.atInfo().log("Starting command %s on thread %s", command.id, command.thread.getName());
return command;
}
@@ -166,7 +164,7 @@
runningCommandsMap.notify();
}
- logger.info(String.format("Finished command %s on thread %s", id, thread.getName()));
+ logger.atInfo().log("Finished command %s on thread %s", id, thread.getName());
}
String getId() {
diff --git a/src/main/java/com/google/devtools/build/lib/server/GrpcServerImpl.java b/src/main/java/com/google/devtools/build/lib/server/GrpcServerImpl.java
index b95ece0..66cf5c9 100644
--- a/src/main/java/com/google/devtools/build/lib/server/GrpcServerImpl.java
+++ b/src/main/java/com/google/devtools/build/lib/server/GrpcServerImpl.java
@@ -17,6 +17,7 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.Preconditions;
import com.google.common.collect.ImmutableList;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.net.InetAddresses;
import com.google.common.util.concurrent.ThreadFactoryBuilder;
import com.google.common.util.concurrent.Uninterruptibles;
@@ -66,7 +67,6 @@
import java.util.concurrent.Executors;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
-import java.util.logging.Logger;
/**
* gRPC server class.
@@ -99,7 +99,7 @@
* which results in the main thread of the command being interrupted.
*/
public class GrpcServerImpl extends CommandServerGrpc.CommandServerImplBase implements RPCServer {
- private static final Logger logger = Logger.getLogger(GrpcServerImpl.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final boolean shutdownOnLowSysMem;
/**
@@ -292,21 +292,23 @@
String pidFileContents = new String(FileSystemUtils.readContentAsLatin1(pidFile));
ok = pidFileContents.equals(pidInFile);
} catch (IOException e) {
- logger.info("Cannot read PID file: " + e.getMessage());
+ logger.atInfo().log("Cannot read PID file: %s", e.getMessage());
// Handled by virtue of ok not being set to true
}
if (!ok) {
synchronized (PidFileWatcherThread.this) {
if (shuttingDown) {
- logger.warning("PID file deleted or overwritten but shutdown is already in progress");
+ logger.atWarning().log(
+ "PID file deleted or overwritten but shutdown is already in progress");
break;
}
shuttingDown = true;
// Someone overwrote the PID file. Maybe it's another server, so shut down as quickly
// as possible without even running the shutdown hooks (that would delete it)
- logger.severe("PID file deleted or overwritten, exiting as quickly as possible");
+ logger.atSevere().log(
+ "PID file deleted or overwritten, exiting as quickly as possible");
Runtime.getRuntime().halt(ExitCode.BLAZE_INTERNAL_ERROR.getNumericExitCode());
}
}
@@ -535,7 +537,7 @@
printErr.println("=======[BAZEL SERVER: ENCOUNTERED IO EXCEPTION]=======");
e.printStackTrace(printErr);
printErr.println("=====================================================");
- logger.severe(err.toString());
+ logger.atSevere().log(err.toString());
}
private void executeCommand(RunRequest request, BlockingStreamObserver<RunResponse> observer) {
@@ -547,7 +549,7 @@
.build());
observer.onCompleted();
} catch (StatusRuntimeException e) {
- logger.info("Client cancelled command while rejecting it: " + e.getMessage());
+ logger.atInfo().withCause(e).log("Client cancelled command while rejecting it");
}
return;
}
@@ -580,8 +582,8 @@
.setCommandId(commandId)
.build());
} catch (StatusRuntimeException e) {
- logger.info(
- "The client cancelled the command before receiving the command id: " + e.getMessage());
+ logger.atInfo().withCause(e).log(
+ "The client cancelled the command before receiving the command id");
}
OutErr rpcOutErr =
@@ -598,7 +600,7 @@
.collect(ImmutableList.toImmutableList());
InvocationPolicy policy = InvocationPolicyParser.parsePolicy(request.getInvocationPolicy());
- logger.info(BlazeRuntime.getRequestLogString(args));
+ logger.atInfo().log(BlazeRuntime.getRequestLogString(args));
result =
dispatcher.exec(
policy,
@@ -643,8 +645,8 @@
observer.onNext(response.build());
observer.onCompleted();
} catch (StatusRuntimeException e) {
- logger.info(
- "The client cancelled the command before receiving the command id: " + e.getMessage());
+ logger.atInfo().withCause(e).log(
+ "The client cancelled the command before receiving the command id");
}
if (result.shutdown()) {
@@ -679,7 +681,7 @@
@Override
public void cancel(
final CancelRequest request, final StreamObserver<CancelResponse> streamObserver) {
- logger.info(String.format("Got CancelRequest for command id %s", request.getCommandId()));
+ logger.atInfo().log("Got CancelRequest for command id %s", request.getCommandId());
if (!request.getCookie().equals(requestCookie)) {
streamObserver.onCompleted();
return;
@@ -697,7 +699,8 @@
streamObserver.onCompleted();
} catch (StatusRuntimeException e) {
// There is no one to report the failure to
- logger.info("Client cancelled RPC of cancellation request for " + request.getCommandId());
+ logger.atInfo().log(
+ "Client cancelled RPC of cancellation request for %s", request.getCommandId());
}
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/server/IdleServerTasks.java b/src/main/java/com/google/devtools/build/lib/server/IdleServerTasks.java
index 82cb7b6..4d286e3 100644
--- a/src/main/java/com/google/devtools/build/lib/server/IdleServerTasks.java
+++ b/src/main/java/com/google/devtools/build/lib/server/IdleServerTasks.java
@@ -15,6 +15,7 @@
package com.google.devtools.build.lib.server;
import com.google.common.base.Preconditions;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.util.concurrent.ThreadFactoryBuilder;
import com.google.devtools.build.lib.profiler.AutoProfiler;
import com.google.devtools.build.lib.profiler.GoogleAutoProfilerUtils;
@@ -25,7 +26,6 @@
import java.util.concurrent.Future;
import java.util.concurrent.ScheduledThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
-import java.util.logging.Logger;
/**
* Run cleanup-related tasks during idle periods in the server.
@@ -33,7 +33,7 @@
*/
class IdleServerTasks {
private final ScheduledThreadPoolExecutor executor;
- private static final Logger logger = Logger.getLogger(IdleServerTasks.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/** Must be called from the main thread. */
public IdleServerTasks() {
@@ -59,13 +59,12 @@
System.gc();
}
MemoryUsage after = memBean.getHeapMemoryUsage();
- logger.info(
- String.format(
- "[Idle GC] used: %s -> %s, committed: %s -> %s",
- StringUtilities.prettyPrintBytes(before.getUsed()),
- StringUtilities.prettyPrintBytes(after.getUsed()),
- StringUtilities.prettyPrintBytes(before.getCommitted()),
- StringUtilities.prettyPrintBytes(after.getCommitted())));
+ logger.atInfo().log(
+ "[Idle GC] used: %s -> %s, committed: %s -> %s",
+ StringUtilities.prettyPrintBytes(before.getUsed()),
+ StringUtilities.prettyPrintBytes(after.getUsed()),
+ StringUtilities.prettyPrintBytes(before.getCommitted()),
+ StringUtilities.prettyPrintBytes(after.getCommitted()));
},
10,
TimeUnit.SECONDS);
diff --git a/src/main/java/com/google/devtools/build/lib/server/ServerWatcherRunnable.java b/src/main/java/com/google/devtools/build/lib/server/ServerWatcherRunnable.java
index ac98ddd..b896d97 100644
--- a/src/main/java/com/google/devtools/build/lib/server/ServerWatcherRunnable.java
+++ b/src/main/java/com/google/devtools/build/lib/server/ServerWatcherRunnable.java
@@ -17,14 +17,13 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.Preconditions;
import com.google.common.base.Verify;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.clock.BlazeClock;
import com.google.devtools.build.lib.unix.ProcMeminfoParser;
import com.google.devtools.build.lib.util.OS;
import io.grpc.Server;
import java.io.IOException;
import java.time.Duration;
-import java.util.logging.Level;
-import java.util.logging.Logger;
/**
* Runnable that checks to see if a {@link Server} server has been idle for too long and shuts down
@@ -33,7 +32,7 @@
* <p>TODO(bazel-team): Implement the memory checking aspect.
*/
class ServerWatcherRunnable implements Runnable {
- private static final Logger logger = Logger.getLogger(ServerWatcherRunnable.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final Duration IDLE_MEMORY_CHECK_INTERVAL = Duration.ofSeconds(5);
private static final Duration TIME_IDLE_BEFORE_MEMORY_CHECK = Duration.ofMinutes(5);
private static final long FREE_MEMORY_KB_ABSOLUTE_THRESHOLD = 1L << 20;
@@ -88,7 +87,7 @@
if (idle) {
Verify.verify(shutdownTimeNanos > 0);
if (shutdownOnLowSysMem && exitOnLowMemoryCheck(lastIdleTimeNanos)) {
- logger.log(Level.SEVERE, "Available RAM is low. Shutting down idle server...");
+ logger.atSevere().log("Available RAM is low. Shutting down idle server...");
break;
}
// Re-run the check every 5 seconds if no other commands have been sent to the server.
@@ -103,7 +102,7 @@
wasIdle = idle;
idle = commandManager.isEmpty();
if (wasIdle && idle && BlazeClock.nanoTime() >= shutdownTimeNanos) {
- logger.info("About to shutdown due to idleness");
+ logger.atInfo().log("About to shutdown due to idleness");
break;
}
}
@@ -134,7 +133,7 @@
return fractionRamFree < FREE_MEMORY_PERCENTAGE_THRESHOLD
&& freeRamKb < FREE_MEMORY_KB_ABSOLUTE_THRESHOLD;
} catch (IOException e) {
- logger.log(Level.WARNING, "Unable to read memory info.", e);
+ logger.atWarning().withCause(e).log("Unable to read memory info.");
return false;
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java b/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java
index bbf13fe..347c5f5 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/ActionMetadataHandler.java
@@ -20,6 +20,7 @@
import com.google.common.collect.ImmutableSet;
import com.google.common.collect.Maps;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.io.BaseEncoding;
import com.google.devtools.build.lib.actions.ActionInput;
import com.google.devtools.build.lib.actions.ActionInputHelper;
@@ -55,7 +56,6 @@
import java.util.Map;
import java.util.Set;
import java.util.concurrent.atomic.AtomicBoolean;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -80,7 +80,7 @@
@VisibleForTesting
public final class ActionMetadataHandler implements MetadataHandler {
- private static final Logger logger = Logger.getLogger(ActionMetadataHandler.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* Data for input artifacts. Immutable.
@@ -177,7 +177,8 @@
} catch (IOException e) {
// If we cannot get the FileArtifactValue, then we will make a FileSystem call to get the
// digest, so it is okay to skip and continue here.
- logger.warning("Could not properly get digest for " + entry.getKey().getExecPath());
+ logger.atWarning().log(
+ "Could not properly get digest for %s", entry.getKey().getExecPath());
continue;
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/DiffAwarenessManager.java b/src/main/java/com/google/devtools/build/lib/skyframe/DiffAwarenessManager.java
index 9714601..ed56b41 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/DiffAwarenessManager.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/DiffAwarenessManager.java
@@ -15,6 +15,7 @@
import com.google.common.collect.ImmutableList;
import com.google.common.collect.Maps;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.events.EventHandler;
import com.google.devtools.build.lib.skyframe.DiffAwareness.View;
@@ -22,7 +23,6 @@
import com.google.devtools.build.lib.vfs.Root;
import com.google.devtools.common.options.OptionsProvider;
import java.util.Map;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -31,7 +31,7 @@
*/
public final class DiffAwarenessManager {
- private static final Logger logger = Logger.getLogger(DiffAwarenessManager.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
// The manager attempts to instantiate these in the order in which they are passed to the
// constructor; this is critical in the case where a factory always succeeds.
@@ -97,14 +97,14 @@
View baselineView = diffAwarenessState.baselineView;
if (baselineView == null) {
- logger.info("Initial baseline view for " + pathEntry + " is " + newView);
+ logger.atInfo().log("Initial baseline view for %s is %s", pathEntry, newView);
diffAwarenessState.baselineView = newView;
return BrokenProcessableModifiedFileSet.INSTANCE;
}
ModifiedFileSet diff;
- logger.info(
- "About to compute diff between " + baselineView + " and " + newView + " for " + pathEntry);
+ logger.atInfo().log(
+ "About to compute diff between %s and %s for %s", baselineView, newView, pathEntry);
try {
diff = diffAwareness.getDiff(baselineView, newView);
} catch (BrokenDiffAwarenessException e) {
@@ -122,7 +122,7 @@
private void handleBrokenDiffAwareness(
EventHandler eventHandler, Root pathEntry, BrokenDiffAwarenessException e) {
currentDiffAwarenessStates.remove(pathEntry);
- logger.info("Broken diff awareness for " + pathEntry + ": " + e);
+ logger.atInfo().withCause(e).log("Broken diff awareness for %s", pathEntry);
eventHandler.handle(Event.warn(e.getMessage() + "... temporarily falling back to manually "
+ "checking files for changes"));
}
@@ -140,8 +140,8 @@
for (DiffAwareness.Factory factory : diffAwarenessFactories) {
DiffAwareness newDiffAwareness = factory.maybeCreate(pathEntry);
if (newDiffAwareness != null) {
- logger.info(
- "Using " + newDiffAwareness.name() + " DiffAwareness strategy for " + pathEntry);
+ logger.atInfo().log(
+ "Using %s DiffAwareness strategy for %s", newDiffAwareness.name(), pathEntry);
diffAwarenessState = new DiffAwarenessState(newDiffAwareness, /*baselineView=*/null);
currentDiffAwarenessStates.put(pathEntry, diffAwarenessState);
return diffAwarenessState;
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/ExternalFilesHelper.java b/src/main/java/com/google/devtools/build/lib/skyframe/ExternalFilesHelper.java
index 511b72e..11e68ca 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/ExternalFilesHelper.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/ExternalFilesHelper.java
@@ -14,6 +14,7 @@
package com.google.devtools.build.lib.skyframe;
import com.google.common.base.Preconditions;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.analysis.BlazeDirectories;
import com.google.devtools.build.lib.cmdline.LabelConstants;
import com.google.devtools.build.lib.cmdline.RepositoryName;
@@ -29,13 +30,12 @@
import java.io.IOException;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicReference;
-import java.util.logging.Logger;
/** Common utilities for dealing with paths outside the package roots. */
public class ExternalFilesHelper {
private static final boolean IN_TEST = System.getenv("TEST_TMPDIR") != null;
- private static final Logger logger = Logger.getLogger(ExternalFilesHelper.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final AtomicReference<PathPackageLocator> pkgLocator;
private final ExternalFileAction externalFileAction;
@@ -284,7 +284,7 @@
break;
case EXTERNAL:
if (numExternalFilesLogged.incrementAndGet() < maxNumExternalFilesToLog) {
- logger.info("Encountered an external path " + rootedPath);
+ logger.atInfo().log("Encountered an external path %s", rootedPath);
}
// fall through
case OUTPUT:
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/FilesystemValueChecker.java b/src/main/java/com/google/devtools/build/lib/skyframe/FilesystemValueChecker.java
index 9ddce19..3c28996 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/FilesystemValueChecker.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/FilesystemValueChecker.java
@@ -23,6 +23,7 @@
import com.google.common.collect.ImmutableSortedSet;
import com.google.common.collect.Range;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.util.concurrent.ThreadFactoryBuilder;
import com.google.devtools.build.lib.actions.Artifact;
import com.google.devtools.build.lib.actions.FileArtifactValue;
@@ -64,10 +65,8 @@
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;
-import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -76,7 +75,7 @@
*/
public class FilesystemValueChecker {
- private static final Logger logger = Logger.getLogger(FilesystemValueChecker.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final Predicate<SkyKey> ACTION_FILTER =
SkyFunctionName.functionIs(SkyFunctions.ACTION_EXECUTION);
@@ -178,10 +177,10 @@
boolean trustRemoteArtifacts)
throws InterruptedException {
if (modifiedOutputFiles == ModifiedFileSet.NOTHING_MODIFIED) {
- logger.info("Not checking for dirty actions since nothing was modified");
+ logger.atInfo().log("Not checking for dirty actions since nothing was modified");
return ImmutableList.of();
}
- logger.info("Accumulating dirty actions");
+ logger.atInfo().log("Accumulating dirty actions");
final int numOutputJobs = Runtime.getRuntime().availableProcessors() * 4;
final Set<SkyKey> actionSkyKeys = new HashSet<>();
try (SilentCloseable c = Profiler.instance().profile("getDirtyActionValues.filter_actions")) {
@@ -197,7 +196,7 @@
for (SkyKey key : actionSkyKeys) {
outputShards.add(Pair.of(key, (ActionExecutionValue) valuesMap.get(key)));
}
- logger.info("Sharded action values for batching");
+ logger.atInfo().log("Sharded action values for batching");
ExecutorService executor = Executors.newFixedThreadPool(
numOutputJobs,
@@ -252,7 +251,7 @@
interrupted = ExecutorUtil.interruptibleShutdown(executor);
}
Throwables.propagateIfPossible(wrapper.getFirstThrownError());
- logger.info("Completed output file stat checks");
+ logger.atInfo().log("Completed output file stat checks");
if (interrupted) {
throw new InterruptedException();
}
@@ -303,7 +302,7 @@
} catch (IOException e) {
// Batch stat did not work. Log an exception and fall back on system calls.
LoggingUtil.logToRemote(Level.WARNING, "Unable to process batch stat", e);
- logger.log(Level.WARNING, "Unable to process batch stat", e);
+ logger.atWarning().withCause(e).log("Unable to process batch stat");
outputStatJob(
dirtyKeys,
shard,
@@ -528,12 +527,9 @@
ElapsedTimeReceiver elapsedTimeReceiver =
elapsedTimeNanos -> {
if (elapsedTimeNanos > 0) {
- logger.info(
- String.format(
- "Spent %d ms checking %d filesystem nodes (%d scanned)",
- TimeUnit.MILLISECONDS.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS),
- numKeysChecked.get(),
- keys.size()));
+ logger.atInfo().log(
+ "Spent %d nanoseconds checking %d filesystem nodes (%d scanned)",
+ elapsedTimeNanos, numKeysChecked.get(), keys.size());
}
};
try (AutoProfiler prof = AutoProfiler.create(elapsedTimeReceiver)) {
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/GraphBackedRecursivePackageProvider.java b/src/main/java/com/google/devtools/build/lib/skyframe/GraphBackedRecursivePackageProvider.java
index 133c7a6..1d0713c 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/GraphBackedRecursivePackageProvider.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/GraphBackedRecursivePackageProvider.java
@@ -21,6 +21,7 @@
import com.google.common.collect.Iterables;
import com.google.common.collect.Sets;
import com.google.common.collect.Sets.SetView;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.InconsistentFilesystemException;
import com.google.devtools.build.lib.cmdline.PackageIdentifier;
import com.google.devtools.build.lib.cmdline.RepositoryName;
@@ -45,7 +46,6 @@
import java.util.List;
import java.util.Map;
import java.util.Set;
-import java.util.logging.Logger;
/**
* A {@link com.google.devtools.build.lib.pkgcache.RecursivePackageProvider} backed by a {@link
@@ -60,8 +60,7 @@
private final RootPackageExtractor rootPackageExtractor;
private final ImmutableList<TargetPattern> universeTargetPatterns;
- private static final Logger logger =
- Logger.getLogger(GraphBackedRecursivePackageProvider.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
public GraphBackedRecursivePackageProvider(
WalkableGraph graph,
@@ -111,13 +110,9 @@
SetView<SkyKey> unknownKeys = Sets.difference(pkgKeys, packages.keySet());
if (!Iterables.isEmpty(unknownKeys)) {
- logger.warning(
- "Unable to find "
- + unknownKeys
- + " in the batch lookup of "
- + pkgKeys
- + ". Successfully looked up "
- + packages.keySet());
+ logger.atWarning().log(
+ "Unable to find %s in the batch lookup of %s. Successfully looked up %s",
+ unknownKeys, pkgKeys, packages.keySet());
}
for (Map.Entry<SkyKey, Exception> missingOrExceptionEntry :
graph.getMissingAndExceptions(unknownKeys).entrySet()) {
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java
index f85a3f2..f55d13f 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SequencedSkyframeExecutor.java
@@ -24,6 +24,7 @@
import com.google.common.collect.Maps;
import com.google.common.collect.Range;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.ActionKeyContext;
import com.google.devtools.build.lib.actions.ArtifactRoot;
import com.google.devtools.build.lib.actions.CommandLineExpansionException;
@@ -113,7 +114,6 @@
import java.util.UUID;
import java.util.concurrent.Callable;
import java.util.function.Consumer;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -122,7 +122,7 @@
*/
public final class SequencedSkyframeExecutor extends SkyframeExecutor {
- private static final Logger logger = Logger.getLogger(SequencedSkyframeExecutor.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* If false, the graph will not store state useful for incremental builds, saving memory but
@@ -386,7 +386,7 @@
* FileStateValues and DirectoryStateValues should be injected.
*/
private void invalidateCachedWorkspacePathsStates() {
- logger.info(
+ logger.atInfo().log(
"Invalidating cached packages and paths states"
+ " because managed directories configuration has changed.");
invalidate(SkyFunctionName.functionIsIn(PACKAGE_LOCATOR_DEPENDENT_VALUES));
@@ -501,9 +501,9 @@
FileType.OUTPUT)
: EnumSet.of(
FileType.EXTERNAL, FileType.EXTERNAL_REPO, FileType.EXTERNAL_IN_MANAGED_DIRECTORY);
- logger.info(
- "About to scan skyframe graph checking for filesystem nodes of types "
- + Iterables.toString(fileTypesToCheck));
+ logger.atInfo().log(
+ "About to scan skyframe graph checking for filesystem nodes of types %s",
+ Iterables.toString(fileTypesToCheck));
ImmutableBatchDirtyResult batchDirtyResult;
try (SilentCloseable c = Profiler.instance().profile("fsvc.getDirtyKeys")) {
batchDirtyResult =
@@ -596,7 +596,7 @@
}
}
- logger.info(result.toString());
+ logger.atInfo().log(result.toString());
}
private static int getNumberOfModifiedFiles(Iterable<SkyKey> modifiedValues) {
@@ -654,7 +654,7 @@
// Now check if it is necessary to wipe the previous state. We do this if either the previous
// or current incrementalStateRetentionStrategy requires the build to have been isolated.
if (oldValueOfTrackIncrementalState != trackIncrementalState) {
- logger.info("Set incremental state to " + trackIncrementalState);
+ logger.atInfo().log("Set incremental state to %b", trackIncrementalState);
evaluatorNeedsReset = true;
} else if (!trackIncrementalState) {
evaluatorNeedsReset = true;
@@ -722,7 +722,7 @@
modifiedFiles += fsvc.getNumberOfModifiedOutputFiles();
outputDirtyFiles += fsvc.getNumberOfModifiedOutputFiles();
modifiedFilesDuringPreviousBuild += fsvc.getNumberOfModifiedOutputFilesDuringPreviousBuild();
- logger.info(String.format("Found %d modified files from last build", modifiedFiles));
+ logger.atInfo().log("Found %d modified files from last build", modifiedFiles);
long stopTime = System.nanoTime();
Profiler.instance()
.logSimpleTask(startTime, stopTime, ProfilerTask.INFO, "detectModifiedOutputFiles");
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 61c4f9e..cc0fa15 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
@@ -21,6 +21,7 @@
import com.google.common.collect.ImmutableSortedMap;
import com.google.common.collect.Maps;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.util.concurrent.ListenableFuture;
import com.google.common.util.concurrent.Striped;
import com.google.devtools.build.lib.actions.Action;
@@ -111,8 +112,6 @@
import java.util.concurrent.atomic.AtomicReference;
import java.util.concurrent.locks.Lock;
import java.util.function.Supplier;
-import java.util.logging.Level;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -135,7 +134,7 @@
SUPPRESS
}
- private static final Logger logger = Logger.getLogger(SkyframeActionExecutor.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
// Used to prevent check-then-act races in #createOutputDirectories. See the comment there for
// more detail.
@@ -805,6 +804,7 @@
this.postprocessing = postprocessing;
}
+ @SuppressWarnings("LogAndThrow") // Thrown exception shown in user output, not info logs.
@Override
public ActionStepOrResult run(SkyFunction.Environment env) throws InterruptedException {
// There are three ExtendedEventHandler instances available while this method is running.
@@ -856,11 +856,8 @@
// keep previous outputs in place.
action.prepare(actionExecutionContext.getExecRoot());
} catch (IOException e) {
- logger.log(
- Level.WARNING,
- String.format(
- "failed to delete output files before executing action: '%s'", action),
- e);
+ logger.atWarning().withCause(e).log(
+ "failed to delete output files before executing action: '%s'", action);
throw toActionExecutionException(
"failed to delete output files before executing action", e, action, null);
}
@@ -981,6 +978,7 @@
}
}
+ @SuppressWarnings("LogAndThrow") // Thrown exception shown in user output, not info logs.
private ActionExecutionValue actuallyCompleteAction(
ExtendedEventHandler eventHandler, ActionResult actionResult)
throws ActionExecutionException, InterruptedException {
@@ -1024,7 +1022,7 @@
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);
+ logger.atWarning().withCause(e).log("unable to finalize action: '%s'", action);
throw toActionExecutionException("unable to finalize action", e, action, fileOutErr);
}
}
@@ -1356,13 +1354,9 @@
Action action, Artifact output, Reporter reporter, boolean isSymlink, IOException exception) {
boolean genrule = action.getMnemonic().equals("Genrule");
String prefix = (genrule ? "declared output '" : "output '") + output.prettyPrint() + "' ";
- logger.warning(
- String.format(
- "Error creating %s%s%s: %s",
- isSymlink ? "symlink " : "",
- prefix,
- genrule ? " by genrule" : "",
- exception.getMessage()));
+ logger.atWarning().log(
+ "Error creating %s%s%s: %s",
+ isSymlink ? "symlink " : "", prefix, genrule ? " by genrule" : "", exception.getMessage());
if (isSymlink) {
String msg = prefix + "is a dangling symbolic link";
reporter.handle(Event.error(action.getOwner().getLocation(), msg));
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java
index 59b69e5..90455f9 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeExecutor.java
@@ -36,6 +36,7 @@
import com.google.common.collect.Range;
import com.google.common.collect.Sets;
import com.google.common.eventbus.EventBus;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.ActionAnalysisMetadata;
import com.google.devtools.build.lib.actions.ActionCacheChecker;
import com.google.devtools.build.lib.actions.ActionExecutionStatusReporter;
@@ -210,7 +211,6 @@
import java.util.concurrent.atomic.AtomicReference;
import java.util.function.Consumer;
import java.util.function.Supplier;
-import java.util.logging.Logger;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import javax.annotation.Nullable;
@@ -223,7 +223,7 @@
* the build.
*/
public abstract class SkyframeExecutor implements WalkableGraphFactory {
- private static final Logger logger = Logger.getLogger(SkyframeExecutor.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
// We delete any value that can hold an action -- all subclasses of ActionLookupKey.
// Also remove ArtifactNestedSetValues to prevent memory leak (b/143940221).
@@ -831,7 +831,7 @@
/** Clear any configured target data stored outside Skyframe. */
public void handleAnalysisInvalidatingChange() {
- logger.info("Dropping configured target data");
+ logger.atInfo().log("Dropping configured target data");
analysisCacheDiscarded = true;
clearTrimmingCache();
skyframeBuildView.clearInvalidatedConfiguredTargets();
@@ -1275,7 +1275,7 @@
// information here, so we compute it ourselves.
// TODO(bazel-team): Fancy filesystems could provide it with a hypothetically modified
// DiffAwareness interface.
- logger.info(
+ logger.atInfo().log(
"About to recompute filesystem nodes corresponding to files that are known to have "
+ "changed");
FilesystemValueChecker fsvc =
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/StarlarkImportLookupFunction.java b/src/main/java/com/google/devtools/build/lib/skyframe/StarlarkImportLookupFunction.java
index 97fe7e4..2df045c 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/StarlarkImportLookupFunction.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/StarlarkImportLookupFunction.java
@@ -24,6 +24,7 @@
import com.google.common.collect.ImmutableMap;
import com.google.common.collect.Lists;
import com.google.common.collect.Maps;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.InconsistentFilesystemException;
import com.google.devtools.build.lib.cmdline.Label;
import com.google.devtools.build.lib.cmdline.LabelConstants;
@@ -63,7 +64,6 @@
import java.util.List;
import java.util.Map;
import java.util.Set;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -86,8 +86,7 @@
cachedStarlarkImportLookupValueAndDepsBuilderFactory =
new CachedStarlarkImportLookupValueAndDepsBuilderFactory();
- private static final Logger logger =
- Logger.getLogger(StarlarkImportLookupFunction.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
public StarlarkImportLookupFunction(
RuleClassProvider ruleClassProvider, PackageFactory packageFactory) {
@@ -223,9 +222,9 @@
public void resetCache() {
if (starlarkImportLookupValueCache != null) {
- logger.info(
- "Starlark inlining cache stats from earlier build: "
- + starlarkImportLookupValueCache.stats());
+ logger.atInfo().log(
+ "Starlark inlining cache stats from earlier build: %s",
+ starlarkImportLookupValueCache.stats());
}
cachedStarlarkImportLookupValueAndDepsBuilderFactory =
new CachedStarlarkImportLookupValueAndDepsBuilderFactory();
diff --git a/src/main/java/com/google/devtools/build/lib/util/BUILD b/src/main/java/com/google/devtools/build/lib/util/BUILD
index 121a26c..6256d3d 100644
--- a/src/main/java/com/google/devtools/build/lib/util/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/util/BUILD
@@ -152,6 +152,7 @@
"//src/main/java/com/google/devtools/common/options",
"//third_party:checker_framework_annotations",
"//third_party:error_prone_annotations",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
],
diff --git a/src/main/java/com/google/devtools/build/lib/util/PersistentMap.java b/src/main/java/com/google/devtools/build/lib/util/PersistentMap.java
index 04cd488..e83ac86 100644
--- a/src/main/java/com/google/devtools/build/lib/util/PersistentMap.java
+++ b/src/main/java/com/google/devtools/build/lib/util/PersistentMap.java
@@ -15,6 +15,7 @@
package com.google.devtools.build.lib.util;
import com.google.common.collect.ForwardingMap;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.io.ByteStreams;
import com.google.devtools.build.lib.vfs.FileSystemUtils;
import com.google.devtools.build.lib.vfs.Path;
@@ -29,7 +30,6 @@
import java.util.Hashtable;
import java.util.LinkedHashMap;
import java.util.Map;
-import java.util.logging.Logger;
/**
* A map that is backed by persistent storage. It uses two files on disk for
@@ -71,7 +71,7 @@
private static final int ENTRY_MAGIC = 0xfe;
private static final int MIN_MAPFILE_SIZE = 16;
private static final int MAX_ARRAY_SIZE = Integer.MAX_VALUE - 8;
- private static final Logger logger = Logger.getLogger(PersistentMap.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private final int version;
private final Path mapFile;
@@ -388,7 +388,7 @@
in.close();
}
- logger.info(String.format("Loaded cache '%s' [%s bytes]", mapFile, fileSize));
+ logger.atInfo().log("Loaded cache '%s' [%d bytes]", mapFile, fileSize);
}
/**
diff --git a/src/main/java/com/google/devtools/build/lib/util/ThreadUtils.java b/src/main/java/com/google/devtools/build/lib/util/ThreadUtils.java
index cec0a97..977fcd8 100644
--- a/src/main/java/com/google/devtools/build/lib/util/ThreadUtils.java
+++ b/src/main/java/com/google/devtools/build/lib/util/ThreadUtils.java
@@ -13,30 +13,29 @@
// limitations under the License.
package com.google.devtools.build.lib.util;
+import com.google.common.flogger.GoogleLogger;
import java.util.Map;
import java.util.logging.Level;
-import java.util.logging.Logger;
/**
* Utility methods relating to threads and stack traces.
*/
public class ThreadUtils {
- private static final Logger logger = Logger.getLogger(ThreadUtils.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private ThreadUtils() {
}
/** Write a thread dump to the blaze.INFO log if interrupt took too long. */
public static synchronized void warnAboutSlowInterrupt() {
- logger.warning("Interrupt took too long. Dumping thread state.");
+ logger.atWarning().log("Interrupt took too long. Dumping thread state.");
for (Map.Entry <Thread, StackTraceElement[]> e : Thread.getAllStackTraces().entrySet()) {
Thread t = e.getKey();
- logger.warning(
- "\"" + t.getName() + "\"" + " " + " Thread id=" + t.getId() + " " + t.getState());
+ logger.atWarning().log("\"%s\" Thread id=%d %s", t.getName(), t.getId(), t.getState());
for (StackTraceElement line : e.getValue()) {
- logger.warning("\t" + line);
+ logger.atWarning().log("\t%s", line);
}
- logger.warning("");
+ logger.atWarning().log("");
}
LoggingUtil.logToRemote(Level.WARNING, "Slow interrupt", new SlowInterruptException());
}
diff --git a/src/main/java/com/google/devtools/build/lib/util/io/AnsiTerminalPrinter.java b/src/main/java/com/google/devtools/build/lib/util/io/AnsiTerminalPrinter.java
index e1dd5e5..98e4d7b 100644
--- a/src/main/java/com/google/devtools/build/lib/util/io/AnsiTerminalPrinter.java
+++ b/src/main/java/com/google/devtools/build/lib/util/io/AnsiTerminalPrinter.java
@@ -14,12 +14,12 @@
package com.google.devtools.build.lib.util.io;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.concurrent.ThreadSafety.ThreadCompatible;
import java.io.IOException;
import java.io.OutputStream;
import java.io.PrintWriter;
import java.util.EnumSet;
-import java.util.logging.Logger;
import java.util.regex.Pattern;
/**
@@ -63,7 +63,7 @@
}
}
- private static final Logger logger = Logger.getLogger(AnsiTerminalPrinter.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final EnumSet<Mode> MODES = EnumSet.allOf(Mode.class);
private static final Pattern PATTERN = Pattern.compile(MODE_PATTERN);
@@ -148,7 +148,7 @@
} catch (IOException e) {
// AnsiTerminal state is now considered to be inconsistent - coloring
// should be disabled to prevent future use of AnsiTerminal instance.
- logger.warning("Disabling coloring due to " + e.getMessage());
+ logger.atWarning().withCause(e).log("Disabling coloring due to exception");
useColor = false;
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/util/io/BUILD b/src/main/java/com/google/devtools/build/lib/util/io/BUILD
index 50aa114..7c7a55d 100644
--- a/src/main/java/com/google/devtools/build/lib/util/io/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/util/io/BUILD
@@ -31,6 +31,7 @@
"//src/main/java/com/google/devtools/build/lib/profiler",
"//src/main/java/com/google/devtools/build/lib/vfs",
"//src/main/java/com/google/devtools/build/lib/vfs:pathfragment",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party/protobuf:protobuf_java",
"//third_party/protobuf:protobuf_java_util",
diff --git a/src/main/java/com/google/devtools/build/lib/util/io/TimestampGranularityMonitor.java b/src/main/java/com/google/devtools/build/lib/util/io/TimestampGranularityMonitor.java
index 2e5a2bc..fc056f8 100644
--- a/src/main/java/com/google/devtools/build/lib/util/io/TimestampGranularityMonitor.java
+++ b/src/main/java/com/google/devtools/build/lib/util/io/TimestampGranularityMonitor.java
@@ -14,13 +14,13 @@
package com.google.devtools.build.lib.util.io;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.clock.Clock;
import com.google.devtools.build.lib.concurrent.ThreadSafety.ThreadCompatible;
import com.google.devtools.build.lib.concurrent.ThreadSafety.ThreadSafe;
import com.google.devtools.build.lib.profiler.Profiler;
import com.google.devtools.build.lib.profiler.ProfilerTask;
import com.google.devtools.build.lib.vfs.PathFragment;
-import java.util.logging.Logger;
/**
* A utility class for dealing with filesystem timestamp granularity issues.
@@ -74,8 +74,7 @@
*/
@ThreadCompatible
public class TimestampGranularityMonitor {
- private static final Logger logger =
- Logger.getLogger(TimestampGranularityMonitor.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* The time of the start of the current Blaze command,
@@ -128,13 +127,14 @@
public void notifyDependenceOnFileTime(PathFragment path, long ctimeMillis) {
if (!this.waitAMillisecond && ctimeMillis == this.commandStartTimeMillis) {
if (path != null) {
- logger.info("Will have to wait for a millisecond on completion because of " + path);
+ logger.atInfo().log(
+ "Will have to wait for a millisecond on completion because of %s", path);
}
this.waitAMillisecond = true;
}
if (!this.waitASecond && ctimeMillis == this.commandStartTimeMillisRounded) {
if (path != null) {
- logger.info("Will have to wait for a second on completion because of " + path);
+ logger.atInfo().log("Will have to wait for a second on completion because of %s", path);
}
this.waitASecond = true;
}
@@ -191,11 +191,8 @@
Profiler.instance().logSimpleTask(startedWaiting, ProfilerTask.WAIT,
"Timestamp granularity");
- logger.info(
- "Waited for "
- + (clock.currentTimeMillis() - before)
- + "ms for file system"
- + " to catch up");
+ logger.atInfo().log(
+ "Waited for %dms for file system to catch up", clock.currentTimeMillis() - before);
}
}
diff --git a/src/main/java/com/google/devtools/build/lib/worker/BUILD b/src/main/java/com/google/devtools/build/lib/worker/BUILD
index 487aa93..f082eb6 100644
--- a/src/main/java/com/google/devtools/build/lib/worker/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/worker/BUILD
@@ -28,6 +28,7 @@
"//src/main/protobuf:worker_protocol_java_proto",
"//third_party:apache_commons_pool2",
"//third_party:auto_value",
+ "//third_party:flogger",
"//third_party:guava",
"//third_party:jsr305",
"//third_party/protobuf:protobuf_java",
diff --git a/src/main/java/com/google/devtools/build/lib/worker/WorkerMultiplexer.java b/src/main/java/com/google/devtools/build/lib/worker/WorkerMultiplexer.java
index 536088e..75b218d 100644
--- a/src/main/java/com/google/devtools/build/lib/worker/WorkerMultiplexer.java
+++ b/src/main/java/com/google/devtools/build/lib/worker/WorkerMultiplexer.java
@@ -15,6 +15,7 @@
package com.google.devtools.build.lib.worker;
import com.google.common.collect.ImmutableList;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.shell.Subprocess;
import com.google.devtools.build.lib.shell.SubprocessBuilder;
import com.google.devtools.build.lib.vfs.Path;
@@ -30,11 +31,10 @@
import java.util.List;
import java.util.Map;
import java.util.concurrent.Semaphore;
-import java.util.logging.Logger;
/** An intermediate worker that sends request and receives response from the worker process. */
public class WorkerMultiplexer extends Thread {
- private static final Logger logger = Logger.getLogger(WorkerMultiplexer.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
/**
* WorkerMultiplexer is running as a thread on its own. When worker process returns the
* WorkResponse, it is stored in this map and wait for WorkerProxy to retrieve the response.
@@ -210,16 +210,16 @@
} catch (IOException e) {
isUnparseable = true;
releaseAllSemaphores();
- logger.warning(
+ logger.atWarning().withCause(e).log(
"IOException was caught while waiting for worker response. "
+ "It could because the worker returned unparseable response.");
} catch (InterruptedException e) {
- logger.warning(
+ logger.atWarning().withCause(e).log(
"InterruptedException was caught while waiting for worker response. "
+ "It could because the multiplexer was interrupted.");
}
}
- logger.warning(
+ logger.atWarning().log(
"Multiplexer thread has been terminated. It could because the memory is running low on"
+ " your machine. There may be other reasons.");
}
diff --git a/src/main/java/com/google/devtools/build/lib/worker/WorkerProxy.java b/src/main/java/com/google/devtools/build/lib/worker/WorkerProxy.java
index 30e7192..d7c3044 100644
--- a/src/main/java/com/google/devtools/build/lib/worker/WorkerProxy.java
+++ b/src/main/java/com/google/devtools/build/lib/worker/WorkerProxy.java
@@ -14,6 +14,7 @@
package com.google.devtools.build.lib.worker;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.actions.UserExecException;
import com.google.devtools.build.lib.sandbox.SandboxHelpers.SandboxInputs;
import com.google.devtools.build.lib.sandbox.SandboxHelpers.SandboxOutputs;
@@ -24,11 +25,10 @@
import java.io.IOException;
import java.io.InputStream;
import java.util.Set;
-import java.util.logging.Logger;
/** A proxy that talks to the multiplexer */
final class WorkerProxy extends Worker {
- private static final Logger logger = Logger.getLogger(WorkerProxy.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private WorkerMultiplexer workerMultiplexer;
private String recordingStreamMessage;
@@ -65,11 +65,11 @@
try {
WorkerMultiplexerManager.removeInstance(workerKey.hashCode());
} catch (InterruptedException e) {
- logger.warning(
+ logger.atWarning().withCause(e).log(
"InterruptedException was caught while destroying multiplexer. "
+ "It could because the multiplexer was interrupted.");
} catch (UserExecException e) {
- logger.warning(e.toString());
+ logger.atWarning().withCause(e).log("Exception");
}
}
@@ -85,7 +85,7 @@
* override. InterruptedException will happen when Bazel is waiting for semaphore but user
* terminates the process, so we do nothing here.
*/
- logger.warning(
+ logger.atWarning().withCause(e).log(
"InterruptedException was caught while sending worker request. "
+ "It could because the multiplexer was interrupted.");
}
@@ -111,7 +111,7 @@
* override. InterruptedException will happen when Bazel is waiting for semaphore but user
* terminates the process, so we do nothing here.
*/
- logger.warning(
+ logger.atWarning().withCause(e).log(
"InterruptedException was caught while waiting for work response. "
+ "It could because the multiplexer was interrupted.");
}
diff --git a/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java b/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
index e062264..c687f8a 100644
--- a/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
+++ b/src/main/java/com/google/devtools/build/skyframe/AbstractExceptionalParallelEvaluator.java
@@ -18,6 +18,7 @@
import com.google.common.collect.ImmutableMap;
import com.google.common.collect.ImmutableSet;
import com.google.common.collect.Iterables;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.collect.nestedset.NestedSet;
import com.google.devtools.build.lib.concurrent.ThreadSafety.ThreadCompatible;
import com.google.devtools.build.lib.events.ExtendedEventHandler;
@@ -41,7 +42,6 @@
import java.util.Set;
import java.util.concurrent.ExecutorService;
import java.util.function.Supplier;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -80,8 +80,7 @@
*/
public abstract class AbstractExceptionalParallelEvaluator<E extends Exception>
extends AbstractParallelEvaluator {
- private static final Logger logger =
- Logger.getLogger(AbstractExceptionalParallelEvaluator.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
AbstractExceptionalParallelEvaluator(
ProcessableGraph graph,
@@ -407,19 +406,10 @@
}
SkyKey parent = Preconditions.checkNotNull(Iterables.getFirst(reverseDeps, null));
if (bubbleErrorInfo.containsKey(parent)) {
- logger.info(
- "Bubbled into a cycle. Don't try to bubble anything up. Cycle detection will kick in. "
- + parent
- + ": "
- + errorEntry
- + ", "
- + bubbleErrorInfo
- + ", "
- + leafFailure
- + ", "
- + roots
- + ", "
- + rdepsToBubbleUpTo);
+ logger.atInfo().log(
+ "Bubbled into a cycle. Don't try to bubble anything up. Cycle detection will kick in."
+ + " %s: %s, %s, %s, %s, %s",
+ parent, errorEntry, bubbleErrorInfo, leafFailure, roots, rdepsToBubbleUpTo);
return null;
}
NodeEntry parentEntry =
@@ -532,16 +522,10 @@
if (completedRun
&& error.getException() != null
&& error.getException() instanceof IOException) {
- logger.info(
- "SkyFunction did not rethrow error, may be a bug that it did not expect one: "
- + errorKey
- + " via "
- + childErrorKey
- + ", "
- + error
- + " ("
- + bubbleErrorInfo
- + ")");
+ logger.atInfo().log(
+ "SkyFunction did not rethrow error, may be a bug that it did not expect one: %s"
+ + " via %s, %s (%s)",
+ errorKey, childErrorKey, error, bubbleErrorInfo);
}
// Builder didn't throw its own exception, so just propagate this one up.
Pair<NestedSet<TaggedEvents>, NestedSet<Postable>> eventsAndPostables =
diff --git a/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java b/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java
index a10e7f9..b0d2466 100644
--- a/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java
+++ b/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java
@@ -20,6 +20,7 @@
import com.google.common.collect.ImmutableSet;
import com.google.common.collect.Iterables;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.common.graph.ImmutableGraph;
import com.google.common.graph.Traverser;
import com.google.common.util.concurrent.ListenableFuture;
@@ -54,7 +55,6 @@
import java.util.concurrent.ForkJoinPool;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.function.Supplier;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -66,7 +66,7 @@
* result. Derived classes should do this.
*/
abstract class AbstractParallelEvaluator {
- private static final Logger logger = Logger.getLogger(AbstractParallelEvaluator.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
final ProcessableGraph graph;
final ParallelEvaluatorContext evaluatorContext;
@@ -472,10 +472,8 @@
// with the first error.
return;
} else {
- logger.warning(
- String.format(
- "Aborting evaluation due to %s while evaluating %s",
- builderException, skyKey));
+ logger.atWarning().withCause(builderException).log(
+ "Aborting evaluation while evaluating %s", skyKey);
}
}
diff --git a/src/main/java/com/google/devtools/build/skyframe/SimpleCycleDetector.java b/src/main/java/com/google/devtools/build/skyframe/SimpleCycleDetector.java
index 5605f08..385d010 100644
--- a/src/main/java/com/google/devtools/build/skyframe/SimpleCycleDetector.java
+++ b/src/main/java/com/google/devtools/build/skyframe/SimpleCycleDetector.java
@@ -22,6 +22,7 @@
import com.google.common.collect.Iterables;
import com.google.common.collect.Maps;
import com.google.common.collect.Sets;
+import com.google.common.flogger.GoogleLogger;
import com.google.devtools.build.lib.bugreport.BugReport;
import com.google.devtools.build.lib.profiler.AutoProfiler;
import com.google.devtools.build.lib.profiler.GoogleAutoProfilerUtils;
@@ -39,7 +40,6 @@
import java.util.List;
import java.util.Map;
import java.util.Set;
-import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -47,7 +47,7 @@
* completed with at least one root unfinished.
*/
public class SimpleCycleDetector implements CycleDetector {
- private static final Logger logger = Logger.getLogger(SimpleCycleDetector.class.getName());
+ private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
private static final Duration MIN_LOGGING = Duration.ofMillis(10);
@Override
@@ -193,7 +193,7 @@
// Found a cycle!
cyclesFound++;
Iterable<SkyKey> cycle = graphPath.subList(cycleStart, graphPath.size());
- logger.info("Found cycle : " + cycle + " from " + graphPath);
+ logger.atInfo().log("Found cycle : %s from %s", cycle, graphPath);
// Put this node into a consistent state for building if it is dirty.
if (entry.isDirty()) {
// If this loop runs more than once, we are in the peculiar position of entry not needing
@@ -285,19 +285,14 @@
ImmutableSet<SkyKey> childrenSet = ImmutableSet.copyOf(children);
Set<SkyKey> missingChildren = Sets.difference(childrenSet, childrenNodes.keySet());
if (missingChildren.isEmpty()) {
- logger.warning(
- "Mismatch for children?? "
- + childrenNodes.size()
- + ", "
- + temporaryDirectDeps.numElements()
- + ", "
- + childrenSet
- + ", "
- + childrenNodes
- + ", "
- + key
- + ", "
- + entry);
+ logger.atWarning().log(
+ "Mismatch for children?? %d, %d, %s, %s, %s, %s",
+ childrenNodes.size(),
+ temporaryDirectDeps.numElements(),
+ childrenSet,
+ childrenNodes,
+ key,
+ entry);
} else {
evaluatorContext
.getGraphInconsistencyReceiver()
@@ -554,7 +549,7 @@
}
/**
- * If child is not done, removes {@param inProgressParent} from {@param child}'s reverse deps.
+ * If child is not done, removes {@code inProgressParent} from {@code child}'s reverse deps.
* Returns whether child should be removed from inProgressParent's entry's direct deps.
*/
private static boolean removeIncompleteChildForCycle(
