diff options
Diffstat (limited to 'src/main/java/com/google/devtools')
4 files changed, 119 insertions, 5 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java index 80f04cedd2..88634d4e63 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java @@ -30,7 +30,10 @@ import java.io.BufferedOutputStream; import java.io.DataOutputStream; import java.io.IOException; import java.io.OutputStream; +import java.io.OutputStreamWriter; +import java.io.Writer; import java.nio.ByteBuffer; +import java.nio.charset.StandardCharsets; import java.time.Duration; import java.util.ArrayList; import java.util.IdentityHashMap; @@ -138,7 +141,8 @@ public final class Profiler { /** File format enum. */ public static enum Format { - BINARY_BAZEL_FORMAT; + BINARY_BAZEL_FORMAT, + JSON_TRACE_FILE_FORMAT; } /** A task that was very slow. */ @@ -408,6 +412,17 @@ public final class Profiler { } }, + /** A set of tasks that's useful for the Json trace output. */ + ALL_FOR_TRACE { + @Override + boolean isProfiling(ProfilerTask type) { + return !type.isVfs() + // Exclude the critical path - it's not useful in the Json trace output. + && type != ProfilerTask.CRITICAL_PATH + && type != ProfilerTask.CRITICAL_PATH_COMPONENT; + } + }, + /** * Profile all tasks. * @@ -551,6 +566,9 @@ public final class Profiler { if (format == Format.BINARY_BAZEL_FORMAT) { writer = new BinaryFormatWriter(stream, profileStartTime, comment); writer.start(); + } else if (format == Format.JSON_TRACE_FILE_FORMAT) { + writer = new JsonTraceFileWriter(stream, profileStartTime); + writer.start(); } } this.writerRef.set(writer); @@ -949,4 +967,81 @@ public final class Profiler { } } } + + /** Writes the profile in Json Trace file format. */ + private static class JsonTraceFileWriter extends FileWriter { + private final Writer out; + private final long profileStartTimeNanos; + + JsonTraceFileWriter( + OutputStream out, + long profileStartTimeNanos) { + this.out = + // The buffer size of 262144 is chosen at random. We might also want to use compression + // in the future. + new OutputStreamWriter(new BufferedOutputStream(out, 262144), StandardCharsets.UTF_8); + this.profileStartTimeNanos = profileStartTimeNanos; + } + + /** + * Saves all gathered information from taskQueue queue to the file. + * Method is invoked internally by the Timer-based thread and at the end of + * profiling session. + */ + @Override + public void run() { + try { + boolean receivedPoisonPill = false; + try { + out.append("["); + boolean first = true; + TaskData data; + while ((data = queue.take()) != POISON_PILL) { + if (data.duration == 0) { + continue; + } + if (first) { + first = false; + } else { + out.append(","); + } + char eventType = data.duration == 0 ? 'i' : 'X'; + out.append("{"); + out.append("\"name\":\"").append(data.description).append("\","); + out.append("\"ph\":\"").append(eventType).append("\","); + out.append("\"ts\":") + .append( + Long.toString( + TimeUnit.NANOSECONDS.toMicros(data.startTimeNanos - profileStartTimeNanos))) + .append(","); + if (data.duration != 0) { + out.append("\"dur\":") + .append(Long.toString(TimeUnit.NANOSECONDS.toMicros(data.duration))) + .append(","); + } + out.append("\"pid\":1,"); + out.append("\"tid\":").append(Long.toString(data.threadId)); + out.append("}\n"); + } + receivedPoisonPill = true; + out.append("]"); + out.close(); + } catch (IOException e) { + this.savedException = e; + try { + out.close(); + } catch (IOException e2) { + // ignore it + } + if (!receivedPoisonPill) { + while (queue.take() != POISON_PILL) { + // We keep emptying the queue, but we can't write anything. + } + } + } + } catch (InterruptedException e) { + // Exit silently. + } + } + } } diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java index a7b1a96a0c..cb7dd06472 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeRuntime.java @@ -272,7 +272,15 @@ public final class BlazeRuntime { ProfiledTaskKinds profiledTasks = ProfiledTaskKinds.NONE; try { - if (options.profilePath != null) { + if (options.enableTracer) { + Path profilePath = options.profilePath != null + ? env.getWorkspace().getRelative(options.profilePath) + : env.getOutputBase().getRelative("command.profile"); + recordFullProfilerData = false; + out = profilePath.getOutputStream(); + env.getReporter().handle(Event.info("Writing tracer profile to '" + profilePath + "'")); + profiledTasks = ProfiledTaskKinds.ALL_FOR_TRACE; + } else if (options.profilePath != null) { Path profilePath = env.getWorkspace().getRelative(options.profilePath); recordFullProfilerData = options.recordFullProfilerData; diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java b/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java index 6e9ba86492..923ebe6693 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/CommonCommandOptions.java @@ -194,6 +194,17 @@ public class CommonCommandOptions extends OptionsBase { public String buildRequestId; @Option( + name = "experimental_generate_json_trace_profile", + defaultValue = "false", + documentationCategory = OptionDocumentationCategory.LOGGING, + effectTags = {OptionEffectTag.AFFECTS_OUTPUTS, OptionEffectTag.BAZEL_MONITORING}, + help = + "If enabled, Bazel profiles the build and writes a JSON-format profile into a file in the " + + "output base." + ) + public boolean enableTracer; + + @Option( name = "profile", defaultValue = "null", documentationCategory = OptionDocumentationCategory.LOGGING, 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 2373959857..0c94277a4b 100644 --- a/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java +++ b/src/main/java/com/google/devtools/build/skyframe/AbstractParallelEvaluator.java @@ -375,19 +375,19 @@ public abstract class AbstractParallelEvaluator { state); SkyValue value = null; - long startTime = BlazeClock.instance().nanoTime(); + long startTimeNanos = BlazeClock.instance().nanoTime(); try { try { evaluatorContext.getProgressReceiver().stateStarting(skyKey, NodeState.COMPUTE); value = factory.compute(skyKey, env); } finally { - long elapsedTimeNanos = BlazeClock.instance().nanoTime() - startTime; + long elapsedTimeNanos = BlazeClock.instance().nanoTime() - startTimeNanos; if (elapsedTimeNanos > 0) { evaluatorContext.getProgressReceiver().stateEnding(skyKey, NodeState.COMPUTE, elapsedTimeNanos); Profiler.instance() .logSimpleTaskDuration( - startTime, + startTimeNanos, Duration.ofNanos(elapsedTimeNanos), ProfilerTask.SKYFUNCTION, skyKey.functionName().getName()); |