diff options
author | 2018-06-11 13:30:38 -0700 | |
---|---|---|
committer | 2018-06-11 13:32:59 -0700 | |
commit | 4915e823976adf6738ec1c89abda8ed8f1f5e368 (patch) | |
tree | b9faefc694537c68e06b00e560ea19f4b89c7326 /src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java | |
parent | c7eef96da80ace358e1d19c7b090765747281cfd (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.java | 141 |
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(); } |