1 /*
2  * Copyright (C) 2018 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 package android.platform.test.microbenchmark;
17 
18 import static com.google.common.truth.Truth.assertThat;
19 
20 import static org.junit.Assert.assertTrue;
21 import static org.mockito.ArgumentMatchers.any;
22 import static org.mockito.Mockito.doReturn;
23 import static org.mockito.Mockito.never;
24 import static org.mockito.Mockito.verify;
25 
26 import android.os.Bundle;
27 import android.os.SystemClock;
28 import android.platform.test.microbenchmark.Microbenchmark.TerminateEarlyException;
29 import android.platform.test.rule.TestWatcher;
30 import android.platform.test.rule.TracePointRule;
31 
32 import androidx.test.InstrumentationRegistry;
33 import androidx.test.internal.runner.TestRequestBuilder;
34 
35 import org.junit.After;
36 import org.junit.Before;
37 import org.junit.ClassRule;
38 import org.junit.Rule;
39 import org.junit.Test;
40 import org.junit.rules.TestRule;
41 import org.junit.runner.Description;
42 import org.junit.runner.JUnitCore;
43 import org.junit.runner.Request;
44 import org.junit.runner.Result;
45 import org.junit.runner.RunWith;
46 import org.junit.runner.notification.Failure;
47 import org.junit.runner.notification.RunNotifier;
48 import org.junit.runners.JUnit4;
49 import org.junit.runners.model.InitializationError;
50 import org.junit.runners.model.Statement;
51 import org.mockito.ArgumentCaptor;
52 import org.mockito.Mockito;
53 
54 import java.lang.annotation.ElementType;
55 import java.lang.annotation.Retention;
56 import java.lang.annotation.RetentionPolicy;
57 import java.lang.annotation.Target;
58 import java.util.ArrayList;
59 import java.util.List;
60 
61 /**
62  * Unit tests for the {@link Microbenchmark} runner.
63  */
64 @RunWith(JUnit4.class)
65 public final class MicrobenchmarkTest {
66     // Static logs are needed to validate dynamic rules and tests that use TestRequestBuilder, where
67     // objects are instantiated with reflection and not directly accessible.
68     private static List<String> sLogs = new ArrayList<>();
69     // Holds the state of the instrumentation args before each test for restoring after. Some tests
70     // need to manipulate the arguments directly, as the underlying object is instantiated through
71     // reflection and thus not directly manipulate-able.
72     private Bundle mArgumentsBeforeTest;
73 
74     @Before
setUp()75     public void setUp() {
76         sLogs.clear();
77         mArgumentsBeforeTest = InstrumentationRegistry.getArguments();
78     }
79 
80     @After
restoreArguments()81     public void restoreArguments() {
82         InstrumentationRegistry.registerInstance(
83                 InstrumentationRegistry.getInstrumentation(), mArgumentsBeforeTest);
84     }
85 
86     /**
87      * Tests that iterations are respected for microbenchmark tests.
88      */
89     @Test
testIterationCount()90     public void testIterationCount() throws InitializationError {
91         Bundle args = new Bundle();
92         args.putString("iterations", "10");
93         Microbenchmark microbench = new Microbenchmark(BasicTest.class, args);
94         assertThat(microbench.testCount()).isEqualTo(10);
95     }
96 
97     public static class BasicTest {
98         @Test
doNothingTest()99         public void doNothingTest() { }
100     }
101 
102     /**
103      * Tests that {@link TracePointRule} and {@link TightMethodRule}s are properly ordered.
104      *
105      * Before --> TightBefore --> Trace (begin) --> Test --> Trace(end) --> TightAfter --> After
106      */
107     @Test
testFeatureExecutionOrder()108     public void testFeatureExecutionOrder() throws InitializationError {
109         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(LoggingTest.class);
110         Result result = new JUnitCore().run(loggingRunner);
111         assertThat(result.wasSuccessful()).isTrue();
112         assertThat(sLogs)
113                 .containsExactly(
114                         "before",
115                         "tight before",
116                         "begin: testMethod("
117                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
118                                 + "LoggingTest)",
119                         "test",
120                         "end",
121                         "tight after",
122                         "after")
123                 .inOrder();
124     }
125 
126     /**
127      * Test iterations number are added to the test name with default suffix.
128      *
129      * Before --> TightBefore --> Trace (begin) with suffix @1 --> Test --> Trace(end)
130      *  --> TightAfter --> After --> Before --> TightBefore --> Trace (begin) with suffix @2
131      *  --> Test --> Trace(end) --> TightAfter --> After
132      */
133     @Test
testMultipleIterationsWithRename()134     public void testMultipleIterationsWithRename() throws InitializationError {
135         Bundle args = new Bundle();
136         args.putString("iterations", "2");
137         args.putString("rename-iterations", "true");
138         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(LoggingTest.class, args);
139         Result result = new JUnitCore().run(loggingRunner);
140         assertThat(result.wasSuccessful()).isTrue();
141         assertThat(sLogs)
142                 .containsExactly(
143                         "before",
144                         "tight before",
145                         "begin: testMethod$1("
146                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
147                                 + "LoggingTest)",
148                         "test",
149                         "end",
150                         "tight after",
151                         "after",
152                         "before",
153                         "tight before",
154                         "begin: testMethod$2("
155                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
156                                 + "LoggingTest)",
157                         "test",
158                         "end",
159                         "tight after",
160                         "after")
161                 .inOrder();
162     }
163 
164     /**
165      * Test iterations number are added to the test name with custom suffix.
166      *
167      * Before --> TightBefore --> Trace (begin) with suffix --1 --> Test --> Trace(end)
168      *  --> TightAfter --> After --> Before --> TightBefore --> Trace (begin) with suffix --2
169      *   --> Test --> Trace(end) --> TightAfter --> After
170      */
171     @Test
testMultipleIterationsWithDifferentSuffix()172     public void testMultipleIterationsWithDifferentSuffix() throws InitializationError {
173         Bundle args = new Bundle();
174         args.putString("iterations", "2");
175         args.putString("rename-iterations", "true");
176         args.putString("iteration-separator", "--");
177         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(LoggingTest.class, args);
178         Result result = new JUnitCore().run(loggingRunner);
179         assertThat(result.wasSuccessful()).isTrue();
180         assertThat(sLogs)
181                 .containsExactly(
182                         "before",
183                         "tight before",
184                         "begin: testMethod--1("
185                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
186                                 + "LoggingTest)",
187                         "test",
188                         "end",
189                         "tight after",
190                         "after",
191                         "before",
192                         "tight before",
193                         "begin: testMethod--2("
194                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
195                                 + "LoggingTest)",
196                         "test",
197                         "end",
198                         "tight after",
199                         "after")
200                 .inOrder();
201     }
202 
203     /**
204      * Test iteration number are not added to the test name when explictly disabled.
205      *
206      * Before --> TightBefore --> Trace (begin) --> Test --> Trace(end) --> TightAfter
207      *  --> After
208      */
209     @Test
testMultipleIterationsWithoutRename()210     public void testMultipleIterationsWithoutRename() throws InitializationError {
211         Bundle args = new Bundle();
212         args.putString("iterations", "1");
213         args.putString("rename-iterations", "false");
214         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(LoggingTest.class, args);
215         Result result = new JUnitCore().run(loggingRunner);
216         assertThat(result.wasSuccessful()).isTrue();
217         assertThat(sLogs)
218                 .containsExactly(
219                         "before",
220                         "tight before",
221                         "begin: testMethod("
222                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
223                                 + "$LoggingTest)",
224                         "test",
225                         "end",
226                         "tight after",
227                         "after")
228                 .inOrder();
229     }
230 
231     /**
232      * Test method iteration will iterate the inner-most test method N times.
233      *
234      * <p>Before --> TightBefore --> Trace (begin) --> Test x N --> Trace(end) --> TightAfter -->
235      * After
236      */
237     @Test
testMultipleMethodIterations()238     public void testMultipleMethodIterations() throws InitializationError {
239         Bundle args = new Bundle();
240         args.putString("iterations", "1");
241         args.putString("method-iterations", "10");
242         args.putString("rename-iterations", "false");
243         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(LoggingTest.class, args);
244         Result result = new JUnitCore().run(loggingRunner);
245         assertThat(result.wasSuccessful()).isTrue();
246         assertThat(sLogs)
247                 .containsExactly(
248                         "before",
249                         "tight before",
250                         "begin: testMethod("
251                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
252                                 + "$LoggingTest)",
253                         "test",
254                         "test",
255                         "test",
256                         "test",
257                         "test",
258                         "test",
259                         "test",
260                         "test",
261                         "test",
262                         "test",
263                         "end",
264                         "tight after",
265                         "after")
266                 .inOrder();
267     }
268 
269     /** Test that the microbenchmark will terminate if the battery is too low. */
270     @Test
testStopsEarly_ifBatteryLevelIsBelowThreshold()271     public void testStopsEarly_ifBatteryLevelIsBelowThreshold() throws InitializationError {
272         Bundle args = new Bundle();
273         args.putString(Microbenchmark.MIN_BATTERY_LEVEL_OPTION, "50");
274         args.putString(Microbenchmark.MAX_BATTERY_DRAIN_OPTION, "20");
275         Microbenchmark runner = Mockito.spy(new Microbenchmark(LoggingTest.class, args));
276         doReturn(49).when(runner).getBatteryLevel();
277 
278         RunNotifier notifier = Mockito.mock(RunNotifier.class);
279         runner.run(notifier);
280 
281         ArgumentCaptor<Failure> failureCaptor = ArgumentCaptor.forClass(Failure.class);
282         verify(notifier).fireTestFailure(failureCaptor.capture());
283 
284         Failure failure = failureCaptor.getValue();
285         Throwable throwable = failure.getException();
286         assertTrue(
287                 String.format(
288                         "Exception was not a TerminateEarlyException. Instead, it was: %s",
289                         throwable.getClass()),
290                 throwable instanceof TerminateEarlyException);
291         assertThat(throwable)
292                 .hasMessageThat()
293                 .matches("Terminating early.*battery level.*threshold.");
294     }
295 
296     /** Test that the microbenchmark will terminate if the battery is too low. */
297     @Test
testStopsEarly_ifBatteryDrainIsAboveThreshold()298     public void testStopsEarly_ifBatteryDrainIsAboveThreshold() throws InitializationError {
299         Bundle args = new Bundle();
300         args.putString(Microbenchmark.MIN_BATTERY_LEVEL_OPTION, "40");
301         args.putString(Microbenchmark.MAX_BATTERY_DRAIN_OPTION, "20");
302         Microbenchmark runner = Mockito.spy(new Microbenchmark(LoggingTest.class, args));
303         doReturn(80).doReturn(50).when(runner).getBatteryLevel();
304 
305         RunNotifier notifier = Mockito.mock(RunNotifier.class);
306         runner.run(notifier);
307 
308         ArgumentCaptor<Failure> failureCaptor = ArgumentCaptor.forClass(Failure.class);
309         verify(notifier).fireTestFailure(failureCaptor.capture());
310 
311         Failure failure = failureCaptor.getValue();
312         Throwable throwable = failure.getException();
313         assertTrue(
314                 String.format(
315                         "Exception was not a TerminateEarlyException. Instead, it was: %s",
316                         throwable.getClass()),
317                 throwable instanceof TerminateEarlyException);
318         assertThat(throwable)
319                 .hasMessageThat()
320                 .matches("Terminating early.*battery drain.*threshold.");
321     }
322 
323     /** Test that the microbenchmark will align starting with the battery charge counter. */
324     @Test
testAlignWithBatteryChargeCounter()325     public void testAlignWithBatteryChargeCounter() throws InitializationError {
326         Bundle args = new Bundle();
327         args.putString("align-with-charge-counter", "true");
328         args.putString("counter-decrement-timeout_ms", "5000");
329 
330         Microbenchmark runner = Mockito.spy(new Microbenchmark(LoggingTest.class, args));
331         doReturn(99999)
332                 .doReturn(99999)
333                 .doReturn(99999)
334                 .doReturn(88888)
335                 .when(runner)
336                 .getBatteryChargeCounter();
337         doReturn(10L).when(runner).getCounterPollingInterval();
338 
339         RunNotifier notifier = Mockito.mock(RunNotifier.class);
340 
341         Thread thread =
342                 new Thread(
343                         new Runnable() {
344                             public void run() {
345                                 runner.run(notifier);
346                             }
347                         });
348 
349         thread.start();
350         SystemClock.sleep(20);
351         verify(notifier, never()).fireTestStarted(any(Description.class));
352         SystemClock.sleep(20);
353         verify(notifier).fireTestStarted(any(Description.class));
354     }
355 
356     /** Test that the microbenchmark counter alignment will time out if there's no change. */
357     @Test
testAlignWithBatteryChargeCounter_timesOut()358     public void testAlignWithBatteryChargeCounter_timesOut() throws InitializationError {
359         Bundle args = new Bundle();
360         args.putString("align-with-charge-counter", "true");
361         args.putString("counter-decrement-timeout_ms", "30");
362 
363         Microbenchmark runner = Mockito.spy(new Microbenchmark(LoggingTest.class, args));
364         doReturn(99999).when(runner).getBatteryChargeCounter();
365         doReturn(10L).when(runner).getCounterPollingInterval();
366 
367         RunNotifier notifier = Mockito.mock(RunNotifier.class);
368 
369         Thread thread =
370                 new Thread(
371                         new Runnable() {
372                             public void run() {
373                                 runner.run(notifier);
374                             }
375                         });
376 
377         thread.start();
378         SystemClock.sleep(20);
379         verify(notifier, never()).fireTestStarted(any(Description.class));
380         SystemClock.sleep(30);
381         verify(notifier).fireTestStarted(any(Description.class));
382     }
383 
384     /**
385      * Test successive iteration will not be executed when the terminate on test fail
386      * option is enabled.
387      */
388     @Test
testTerminateOnTestFailOptionEnabled()389     public void testTerminateOnTestFailOptionEnabled() throws InitializationError {
390         Bundle args = new Bundle();
391         args.putString("iterations", "2");
392         args.putString("rename-iterations", "false");
393         args.putString("terminate-on-test-fail", "true");
394         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(
395                 LoggingFailedTest.class, args);
396         Result result = new JUnitCore().run(loggingRunner);
397         assertThat(result.wasSuccessful()).isFalse();
398         assertThat(sLogs)
399                 .containsExactly(
400                         "before",
401                         "tight before",
402                         "begin: testMethod("
403                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
404                                 + "$LoggingFailedTest)",
405                         "end",
406                         "after")
407                 .inOrder();
408     }
409 
410     /**
411      * Test successive iteration will be executed when the terminate on test fail
412      * option is disabled.
413      */
414     @Test
testTerminateOnTestFailOptionDisabled()415     public void testTerminateOnTestFailOptionDisabled() throws InitializationError {
416         Bundle args = new Bundle();
417         args.putString("iterations", "2");
418         args.putString("rename-iterations", "false");
419         args.putString("terminate-on-test-fail", "false");
420         LoggingMicrobenchmark loggingRunner = new LoggingMicrobenchmark(
421                 LoggingFailedTest.class, args);
422         Result result = new JUnitCore().run(loggingRunner);
423         assertThat(result.wasSuccessful()).isFalse();
424         assertThat(sLogs)
425                 .containsExactly(
426                         "before",
427                         "tight before",
428                         "begin: testMethod("
429                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
430                                 + "$LoggingFailedTest)",
431                         "end",
432                         "after",
433                         "before",
434                         "tight before",
435                         "begin: testMethod("
436                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
437                                 + "$LoggingFailedTest)",
438                         "end",
439                         "after")
440                 .inOrder();
441     }
442 
443     /** Test dynamic test rule injection. */
444     @Test
testDynamicTestRuleInjection()445     public void testDynamicTestRuleInjection() throws InitializationError {
446         Bundle args = new Bundle();
447         args.putString("iterations", "2");
448         args.putString("rename-iterations", "false");
449         args.putString("terminate-on-test-fail", "false");
450         args.putString(
451                 Microbenchmark.DYNAMIC_INNER_TEST_RULES_OPTION, LoggingRule1.class.getName());
452         args.putString(
453                 Microbenchmark.DYNAMIC_OUTER_TEST_RULES_OPTION, LoggingRule2.class.getName());
454         LoggingMicrobenchmark loggingRunner =
455                 new LoggingMicrobenchmark(LoggingTestWithRules.class, args);
456         new JUnitCore().run(loggingRunner);
457         assertThat(sLogs)
458                 .containsExactly(
459                         "hardcoded class rule starting",
460                         "logging rule 2 starting",
461                         "hardcoded test rule starting",
462                         "logging rule 1 starting",
463                         "before",
464                         "tight before",
465                         "begin: testMethod("
466                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
467                                 + "$LoggingTestWithRules)",
468                         "test",
469                         "end",
470                         "tight after",
471                         "after",
472                         "logging rule 1 finished",
473                         "hardcoded test rule finished",
474                         "logging rule 2 finished",
475                         "logging rule 2 starting",
476                         "hardcoded test rule starting",
477                         "logging rule 1 starting",
478                         "before",
479                         "tight before",
480                         "begin: testMethod("
481                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
482                                 + "$LoggingTestWithRules)",
483                         "test",
484                         "end",
485                         "tight after",
486                         "after",
487                         "logging rule 1 finished",
488                         "hardcoded test rule finished",
489                         "logging rule 2 finished",
490                         "hardcoded class rule finished")
491                 .inOrder();
492     }
493 
494     /** Test dynamic class rule injection. */
495     @Test
testDynamicClassRuleInjection()496     public void testDynamicClassRuleInjection() throws InitializationError {
497         Bundle args = new Bundle();
498         args.putString("iterations", "2");
499         args.putString("rename-iterations", "false");
500         args.putString("terminate-on-test-fail", "false");
501         args.putString(
502                 Microbenchmark.DYNAMIC_INNER_CLASS_RULES_OPTION, LoggingRule1.class.getName());
503         args.putString(
504                 Microbenchmark.DYNAMIC_OUTER_CLASS_RULES_OPTION, LoggingRule2.class.getName());
505         LoggingMicrobenchmark loggingRunner =
506                 new LoggingMicrobenchmark(LoggingTestWithRules.class, args);
507         new JUnitCore().run(loggingRunner);
508         assertThat(sLogs)
509                 .containsExactly(
510                         "logging rule 2 starting",
511                         "hardcoded class rule starting",
512                         "logging rule 1 starting",
513                         "hardcoded test rule starting",
514                         "before",
515                         "tight before",
516                         "begin: testMethod("
517                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
518                                 + "$LoggingTestWithRules)",
519                         "test",
520                         "end",
521                         "tight after",
522                         "after",
523                         "hardcoded test rule finished",
524                         "hardcoded test rule starting",
525                         "before",
526                         "tight before",
527                         "begin: testMethod("
528                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest"
529                                 + "$LoggingTestWithRules)",
530                         "test",
531                         "end",
532                         "tight after",
533                         "after",
534                         "hardcoded test rule finished",
535                         "logging rule 1 finished",
536                         "hardcoded class rule finished",
537                         "logging rule 2 finished")
538                 .inOrder();
539     }
540 
541     @Test
testSupportsIterationRenamingWithAndroidXClassAnnotationInclusion()542     public void testSupportsIterationRenamingWithAndroidXClassAnnotationInclusion()
543             throws Exception {
544         Bundle args = new Bundle();
545         args.putString("iterations", "2");
546         args.putString("rename-iterations", "true");
547         injectArguments(args);
548         Request request =
549                 new TestRequestBuilder()
550                         // Should run because it has the annotation.
551                         .addTestClass(
552                                 "android.platform.test.microbenchmark.MicrobenchmarkTest$"
553                                         + "AnnotatedLoggingTest")
554                         // Should not run because it does not have the annotation.
555                         .addTestClass(
556                                 "android.platform.test.microbenchmark.MicrobenchmarkTest$"
557                                         + "LoggingTest")
558                         .addAnnotationInclusionFilter(
559                                 "android.platform.test.microbenchmark.MicrobenchmarkTest$"
560                                         + "TestAnnotation")
561                         .build();
562         Result result = new JUnitCore().run(request);
563         assertThat(result.wasSuccessful()).isTrue();
564         assertThat(sLogs)
565                 .containsExactly(
566                         "before",
567                         "tight before",
568                         "begin: testMethod$1("
569                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
570                                 + "AnnotatedLoggingTest)",
571                         "test",
572                         "end",
573                         "tight after",
574                         "after",
575                         "before",
576                         "tight before",
577                         "begin: testMethod$2("
578                                 + "android.platform.test.microbenchmark.MicrobenchmarkTest$"
579                                 + "AnnotatedLoggingTest)",
580                         "test",
581                         "end",
582                         "tight after",
583                         "after")
584                 .inOrder();
585     }
586 
587     @Test
testSupportsIterationRenamingWithAndroidXClassAnnotationExclusion()588     public void testSupportsIterationRenamingWithAndroidXClassAnnotationExclusion()
589             throws Exception {
590         Bundle args = new Bundle();
591         args.putString("iterations", "2");
592         args.putString("rename-iterations", "true");
593         injectArguments(args);
594         Request request =
595                 new TestRequestBuilder()
596                         .addTestClass(
597                                 "android.platform.test.microbenchmark.MicrobenchmarkTest$"
598                                         + "AnnotatedLoggingTest")
599                         .addAnnotationExclusionFilter(
600                                 "android.platform.test.microbenchmark.MicrobenchmarkTest$"
601                                         + "TestAnnotation")
602                         .build();
603         Result result = new JUnitCore().run(request);
604         assertThat(result.wasSuccessful()).isTrue();
605         assertThat(sLogs).isEmpty();
606     }
607 
injectArguments(Bundle extra)608     private void injectArguments(Bundle extra) {
609         Bundle args = mArgumentsBeforeTest.deepCopy();
610         args.putAll(extra);
611         InstrumentationRegistry.registerInstance(
612                 InstrumentationRegistry.getInstrumentation(), args);
613     }
614 
615     /**
616      * An extensions of the {@link Microbenchmark} runner that logs the start and end of collecting
617      * traces. It also passes the operation log to the provided test {@code Class}, if it is a
618      * {@link LoggingTest}. This is used for ensuring the proper order for evaluating test {@link
619      * Statement}s.
620      */
621     public static class LoggingMicrobenchmark extends Microbenchmark {
LoggingMicrobenchmark(Class<?> klass)622         public LoggingMicrobenchmark(Class<?> klass) throws InitializationError {
623             super(klass);
624         }
625 
LoggingMicrobenchmark(Class<?> klass, Bundle arguments)626         LoggingMicrobenchmark(Class<?> klass, Bundle arguments) throws InitializationError {
627             super(klass, arguments);
628         }
629 
630         @Override
getTracePointRule()631         protected TracePointRule getTracePointRule() {
632             return new LoggingTracePointRule();
633         }
634 
635         class LoggingTracePointRule extends TracePointRule {
636             @Override
beginSection(String sectionTag)637             protected void beginSection(String sectionTag) {
638                 sLogs.add(String.format("begin: %s", sectionTag));
639             }
640 
641             @Override
endSection()642             protected void endSection() {
643                 sLogs.add("end");
644             }
645         }
646     }
647 
648     /**
649      * A test that logs {@link Before}, {@link After}, {@link Test}, and the logging {@link
650      * TightMethodRule} included, used in conjunction with {@link LoggingMicrobenchmark} to
651      * determine all {@link Statement}s are evaluated in the proper order.
652      */
653     @RunWith(LoggingMicrobenchmark.class)
654     public static class LoggingTest {
655         @Microbenchmark.TightMethodRule
656         public TightRule orderRule = new TightRule();
657 
658         @Before
beforeMethod()659         public void beforeMethod() {
660             sLogs.add("before");
661         }
662 
663         @Test
testMethod()664         public void testMethod() {
665             sLogs.add("test");
666         }
667 
668         @After
afterMethod()669         public void afterMethod() {
670             sLogs.add("after");
671         }
672 
673         class TightRule implements TestRule {
674             @Override
apply(Statement base, Description description)675             public Statement apply(Statement base, Description description) {
676                 return new Statement() {
677                     @Override
678                     public void evaluate() throws Throwable {
679                         sLogs.add("tight before");
680                         base.evaluate();
681                         sLogs.add("tight after");
682                     }
683                 };
684             }
685         }
686     }
687 
688     @Retention(RetentionPolicy.RUNTIME)
689     @Target({ElementType.TYPE, ElementType.METHOD})
690     public @interface TestAnnotation {}
691 
692     @TestAnnotation
693     @RunWith(LoggingMicrobenchmark.class)
694     public static class AnnotatedLoggingTest extends LoggingTest {}
695 
696     public static class LoggingTestWithRules extends LoggingTest {
697         @ClassRule
698         public static TestRule hardCodedClassRule =
699                 new TestWatcher() {
700                     @Override
701                     public void starting(Description description) {
702                         sLogs.add("hardcoded class rule starting");
703                     }
704 
705                     @Override
706                     public void finished(Description description) {
707                         sLogs.add("hardcoded class rule finished");
708                     }
709                 };
710 
711         @Rule
712         public TestRule hardCodedRule =
713                 new TestWatcher() {
714                     @Override
715                     public void starting(Description description) {
716                         sLogs.add("hardcoded test rule starting");
717                     }
718 
719                     @Override
720                     public void finished(Description description) {
721                         sLogs.add("hardcoded test rule finished");
722                     }
723                 };
724     }
725 
726     public static class LoggingFailedTest extends LoggingTest {
727         @Test
728         public void testMethod() {
729             throw new RuntimeException("I failed.");
730         }
731     }
732 
733     public static class LoggingRule1 extends TestWatcher {
734         @Override
735         public void starting(Description description) {
736             sLogs.add("logging rule 1 starting");
737         }
738 
739         @Override
740         public void finished(Description description) {
741             sLogs.add("logging rule 1 finished");
742         }
743     }
744 
745     public static class LoggingRule2 extends TestWatcher {
746         @Override
747         public void starting(Description description) {
748             sLogs.add("logging rule 2 starting");
749         }
750 
751         @Override
752         public void finished(Description description) {
753             sLogs.add("logging rule 2 finished");
754         }
755     }
756 }
757