aboutsummaryrefslogtreecommitdiffhomepage
path: root/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java
diff options
context:
space:
mode:
authorGravatar jmmv <jmmv@google.com>2018-06-11 13:30:38 -0700
committerGravatar Copybara-Service <copybara-piper@google.com>2018-06-11 13:32:59 -0700
commit4915e823976adf6738ec1c89abda8ed8f1f5e368 (patch)
treeb9faefc694537c68e06b00e560ea19f4b89c7326 /src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java
parentc7eef96da80ace358e1d19c7b090765747281cfd (diff)
Automated rollback of commit 15b8c259db111012b4642287172cb4d1d82151f3.
*** Reason for rollback *** Breaks internal performance tests. PiperOrigin-RevId: 200103033
Diffstat (limited to 'src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java')
-rw-r--r--src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java141
1 files changed, 67 insertions, 74 deletions
diff --git a/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java b/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java
index 60a331c890..ae1d572596 100644
--- a/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java
+++ b/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java
@@ -14,7 +14,6 @@
package com.google.devtools.build.lib.profiler;
import static com.google.common.truth.Truth.assertThat;
-import static com.google.devtools.build.lib.profiler.Profiler.Format.BINARY_BAZEL_FORMAT;
import static java.nio.charset.StandardCharsets.ISO_8859_1;
import com.google.common.collect.ImmutableList;
@@ -24,12 +23,14 @@ import com.google.devtools.build.lib.clock.Clock;
import com.google.devtools.build.lib.profiler.Profiler.ProfiledTaskKinds;
import com.google.devtools.build.lib.profiler.Profiler.SlowTask;
import com.google.devtools.build.lib.profiler.analysis.ProfileInfo;
+import com.google.devtools.build.lib.testutil.FoundationTestCase;
import com.google.devtools.build.lib.testutil.ManualClock;
import com.google.devtools.build.lib.testutil.Suite;
import com.google.devtools.build.lib.testutil.TestSpec;
import com.google.devtools.build.lib.testutil.TestUtils;
-import java.io.ByteArrayInputStream;
-import java.io.ByteArrayOutputStream;
+import com.google.devtools.build.lib.vfs.FileSystemUtils;
+import com.google.devtools.build.lib.vfs.Path;
+import java.io.InputStream;
import java.io.OutputStream;
import java.util.ArrayList;
import java.util.Arrays;
@@ -39,7 +40,6 @@ import java.util.zip.Deflater;
import java.util.zip.DeflaterOutputStream;
import java.util.zip.Inflater;
import java.util.zip.InflaterInputStream;
-import junit.framework.TestCase;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
@@ -50,28 +50,29 @@ import org.junit.runners.JUnit4;
*/
@TestSpec(size = Suite.MEDIUM_TESTS) // testConcurrentProfiling takes ~700ms, testProfiler 100ms.
@RunWith(JUnit4.class)
-public class ProfilerTest extends TestCase {
+public class ProfilerTest extends FoundationTestCase {
+ private Path cacheDir;
private Profiler profiler = Profiler.instance();
private ManualClock clock;
@Before
+ public final void createCacheDirectory() throws Exception {
+ cacheDir = scratch.dir("/tmp");
+ }
+
+ @Before
public final void setManualClock() {
clock = new ManualClock();
BlazeClock.setClock(clock);
}
- private ByteArrayOutputStream start(ProfiledTaskKinds kinds, Profiler.Format format) {
- ByteArrayOutputStream buffer = new ByteArrayOutputStream();
- profiler.start(
- kinds, buffer, format, "test", false, BlazeClock.instance(), BlazeClock.nanoTime());
- return buffer;
- }
-
@Test
public void testProfilerActivation() throws Exception {
+ Path cacheFile = cacheDir.getRelative("profile1.dat");
assertThat(profiler.isActive()).isFalse();
- start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "basic test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
assertThat(profiler.isActive()).isTrue();
profiler.stop();
@@ -80,12 +81,14 @@ public class ProfilerTest extends TestCase {
@Test
public void testTaskDetails() throws Exception {
- ByteArrayOutputStream buffer = start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ Path cacheFile = cacheDir.getRelative("profile1.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "basic test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
try (SilentCloseable c = profiler.profile(ProfilerTask.ACTION, "action task")) {
profiler.logEvent(ProfilerTask.INFO, "event");
}
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(cacheFile);
info.calculateStats();
ProfileInfo.Task task = info.allTasksById.get(0);
@@ -101,7 +104,9 @@ public class ProfilerTest extends TestCase {
@Test
public void testProfiler() throws Exception {
- ByteArrayOutputStream buffer = start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ Path cacheFile = cacheDir.getRelative("profile1.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "basic test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
profiler.logSimpleTask(BlazeClock.instance().nanoTime(),
ProfilerTask.PHASE, "profiler start");
try (SilentCloseable c = profiler.profile(ProfilerTask.ACTION, "complex task")) {
@@ -120,7 +125,7 @@ public class ProfilerTest extends TestCase {
// all other calls to profiler should be ignored
profiler.logEvent(ProfilerTask.PHASE, "should be ignored");
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(cacheFile);
info.calculateStats();
assertThat(info.allTasksById).hasSize(6); // only 5 tasks + finalization should be recorded
@@ -155,22 +160,16 @@ public class ProfilerTest extends TestCase {
@Test
public void testProfilerRecordingAllEvents() throws Exception {
- ByteArrayOutputStream buffer = new ByteArrayOutputStream();
- profiler.start(
- ProfiledTaskKinds.ALL,
- buffer,
- BINARY_BAZEL_FORMAT,
- "basic test",
- true,
- BlazeClock.instance(),
- BlazeClock.instance().nanoTime());
+ Path cacheFile = cacheDir.getRelative("profile1.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "basic test", true,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
try (SilentCloseable c = profiler.profile(ProfilerTask.ACTION, "action task")) {
// Next task takes less than 10 ms but should be recorded anyway.
clock.advanceMillis(1);
profiler.logSimpleTask(BlazeClock.instance().nanoTime(), ProfilerTask.VFS_STAT, "stat1");
}
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(cacheFile);
info.calculateStats();
assertThat(info.allTasksById).hasSize(3); // 2 tasks + finalization should be recorded
@@ -183,16 +182,10 @@ public class ProfilerTest extends TestCase {
@Test
public void testProfilerRecordingOnlySlowestEvents() throws Exception {
- ByteArrayOutputStream buffer = new ByteArrayOutputStream();
+ Path profileData = cacheDir.getRelative("foo");
- profiler.start(
- ProfiledTaskKinds.SLOWEST,
- buffer,
- BINARY_BAZEL_FORMAT,
- "test",
- true,
- BlazeClock.instance(),
- BlazeClock.instance().nanoTime());
+ profiler.start(ProfiledTaskKinds.SLOWEST, profileData.getOutputStream(), "test", true,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
profiler.logSimpleTask(10000, 20000, ProfilerTask.VFS_STAT, "stat");
profiler.logSimpleTask(20000, 30000, ProfilerTask.REMOTE_EXECUTION, "remote execution");
@@ -201,7 +194,7 @@ public class ProfilerTest extends TestCase {
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(profileData);
info.calculateStats();
assertThat(info.allTasksById).hasSize(1); // only VFS_STAT task should be recorded
@@ -214,7 +207,6 @@ public class ProfilerTest extends TestCase {
profiler.start(
ProfiledTaskKinds.SLOWEST,
ByteStreams.nullOutputStream(),
- BINARY_BAZEL_FORMAT,
"test",
/*recordAllDurations=*/ true,
BlazeClock.instance(),
@@ -287,15 +279,10 @@ public class ProfilerTest extends TestCase {
@Test
public void testProfilerRecordsNothing() throws Exception {
- ByteArrayOutputStream buffer = new ByteArrayOutputStream();
- profiler.start(
- ProfiledTaskKinds.NONE,
- buffer,
- BINARY_BAZEL_FORMAT,
- "test",
- true,
- BlazeClock.instance(),
- BlazeClock.instance().nanoTime());
+ Path profileData = cacheDir.getRelative("foo");
+
+ profiler.start(ProfiledTaskKinds.NONE, profileData.getOutputStream(), "test", true,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
profiler.logSimpleTask(10000, 20000, ProfilerTask.VFS_STAT, "stat");
assertThat(ProfilerTask.VFS_STAT.collectsSlowestInstances()).isTrue();
@@ -303,14 +290,16 @@ public class ProfilerTest extends TestCase {
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(profileData);
info.calculateStats();
assertThat(info.allTasksById).isEmpty();
}
@Test
public void testConcurrentProfiling() throws Exception {
- ByteArrayOutputStream buffer = start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ Path cacheFile = cacheDir.getRelative("profile3.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "concurrent test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
long id = Thread.currentThread().getId();
Thread thread1 = new Thread() {
@@ -340,7 +329,7 @@ public class ProfilerTest extends TestCase {
}
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(cacheFile);
info.calculateStats();
info.analyzeRelationships();
assertThat(info.allTasksById).hasSize(4 + 10000 + 10000); // total number of tasks
@@ -364,7 +353,9 @@ public class ProfilerTest extends TestCase {
@Test
public void testPhaseTasks() throws Exception {
- ByteArrayOutputStream buffer = start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ Path cacheFile = cacheDir.getRelative("profile4.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "phase test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
Thread thread1 = new Thread() {
@Override public void run() {
for (int i = 0; i < 100; i++) {
@@ -403,7 +394,7 @@ public class ProfilerTest extends TestCase {
clock.advanceMillis(1);
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(cacheFile);
info.calculateStats();
info.analyzeRelationships();
// number of tasks: INIT(1) + LOAD(1) + Thread1.TEST(100) + ANALYZE(1)
@@ -426,7 +417,9 @@ public class ProfilerTest extends TestCase {
@Test
public void testCorruptedFile() throws Exception {
- ByteArrayOutputStream buffer = start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ Path cacheFile = cacheDir.getRelative("profile5.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(), "phase test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
for (int i = 0; i < 100; i++) {
try (SilentCloseable c = profiler.profile(ProfilerTask.INFO, "outer task " + i)) {
clock.advanceMillis(1);
@@ -435,12 +428,14 @@ public class ProfilerTest extends TestCase {
}
profiler.stop();
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(cacheFile);
info.calculateStats();
assertThat(info.isCorruptedOrIncomplete()).isFalse();
- info = ProfileInfo.loadProfile(
- new ByteArrayInputStream(Arrays.copyOf(buffer.toByteArray(), 2000)));
+ Path corruptedFile = cacheDir.getRelative("profile5bad.dat");
+ FileSystemUtils.writeContent(
+ corruptedFile, Arrays.copyOf(FileSystemUtils.readContent(cacheFile), 2000));
+ info = ProfileInfo.loadProfile(corruptedFile);
info.calculateStats();
assertThat(info.isCorruptedOrIncomplete()).isTrue();
// Since root tasks will appear after nested tasks in the profile file and
@@ -452,7 +447,9 @@ public class ProfilerTest extends TestCase {
@Test
public void testUnsupportedProfilerRecord() throws Exception {
- ByteArrayOutputStream buffer = start(ProfiledTaskKinds.ALL, BINARY_BAZEL_FORMAT);
+ Path dataFile = cacheDir.getRelative("profile5.dat");
+ profiler.start(ProfiledTaskKinds.ALL, dataFile.getOutputStream(), "phase test", false,
+ BlazeClock.instance(), BlazeClock.instance().nanoTime());
try (SilentCloseable c = profiler.profile(ProfilerTask.INFO, "outer task")) {
profiler.logEvent(ProfilerTask.PHASE, "inner task");
}
@@ -462,28 +459,29 @@ public class ProfilerTest extends TestCase {
profiler.stop();
// Validate our test profile.
- ProfileInfo info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ ProfileInfo info = ProfileInfo.loadProfile(dataFile);
info.calculateStats();
assertThat(info.isCorruptedOrIncomplete()).isFalse();
assertThat(info.getStatsForType(ProfilerTask.INFO, info.rootTasksById).count).isEqualTo(3);
assertThat(info.getStatsForType(ProfilerTask.UNKNOWN, info.rootTasksById).count).isEqualTo(0);
// Now replace "TEST" type with something unsupported - e.g. "XXXX".
- byte[] deflated = ByteStreams.toByteArray(new InflaterInputStream(
- new ByteArrayInputStream(buffer.toByteArray()), new Inflater(false), 65536));
- String content = new String(deflated, ISO_8859_1);
+ InputStream in = new InflaterInputStream(dataFile.getInputStream(), new Inflater(false), 65536);
+ byte[] buffer = new byte[60000];
+ int len = in.read(buffer);
+ in.close();
+ assertThat(len).isLessThan(buffer.length); // Validate that file was completely decoded.
+ String content = new String(buffer, ISO_8859_1);
int infoIndex = content.indexOf("INFO");
assertThat(infoIndex).isGreaterThan(0);
content = content.substring(0, infoIndex) + "XXXX" + content.substring(infoIndex + 4);
-
- buffer = new ByteArrayOutputStream();
- OutputStream out =
- new DeflaterOutputStream(buffer, new Deflater(Deflater.BEST_SPEED, false), 65536);
+ OutputStream out = new DeflaterOutputStream(dataFile.getOutputStream(),
+ new Deflater(Deflater.BEST_SPEED, false), 65536);
out.write(content.getBytes(ISO_8859_1));
out.close();
// Validate that XXXX records were classified as UNKNOWN.
- info = ProfileInfo.loadProfile(new ByteArrayInputStream(buffer.toByteArray()));
+ info = ProfileInfo.loadProfile(dataFile);
info.calculateStats();
assertThat(info.isCorruptedOrIncomplete()).isFalse();
assertThat(info.getStatsForType(ProfilerTask.INFO, info.rootTasksById).count).isEqualTo(0);
@@ -507,14 +505,9 @@ public class ProfilerTest extends TestCase {
return initialNanoTime - numNanoTimeCalls.addAndGet(1);
}
};
- profiler.start(
- ProfiledTaskKinds.ALL,
- new ByteArrayOutputStream(),
- BINARY_BAZEL_FORMAT,
- "testResilenceToNonDecreasingNanoTimes",
- false,
- badClock,
- initialNanoTime);
+ Path cacheFile = cacheDir.getRelative("profile1.dat");
+ profiler.start(ProfiledTaskKinds.ALL, cacheFile.getOutputStream(),
+ "testResilenceToNonDecreasingNanoTimes", false, badClock, initialNanoTime);
profiler.logSimpleTask(badClock.nanoTime(), ProfilerTask.INFO, "some task");
profiler.stop();
}