View Javadoc

    1   /**
    2    * Copyright (c) 2004-2011 QOS.ch
    3    * All rights reserved.
    4    *
    5    * Permission is hereby granted, free  of charge, to any person obtaining
    6    * a  copy  of this  software  and  associated  documentation files  (the
    7    * "Software"), to  deal in  the Software without  restriction, including
    8    * without limitation  the rights to  use, copy, modify,  merge, publish,
    9    * distribute,  sublicense, and/or sell  copies of  the Software,  and to
    10   * permit persons to whom the Software  is furnished to do so, subject to
    11   * the following conditions:
    12   *
    13   * The  above  copyright  notice  and  this permission  notice  shall  be
    14   * included in all copies or substantial portions of the Software.
    15   *
    16   * THE  SOFTWARE IS  PROVIDED  "AS  IS", WITHOUT  WARRANTY  OF ANY  KIND,
    17   * EXPRESS OR  IMPLIED, INCLUDING  BUT NOT LIMITED  TO THE  WARRANTIES OF
    18   * MERCHANTABILITY,    FITNESS    FOR    A   PARTICULAR    PURPOSE    AND
    19   * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE
    20   * LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION
    21   * OF CONTRACT, TORT OR OTHERWISE,  ARISING FROM, OUT OF OR IN CONNECTION
    22   * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
    23   *
    24   */
    25  package org.slf4j.profiler;
    26
    27  import static org.junit.Assert.assertEquals;
    28  import static org.junit.Assert.assertNotNull;
    29  import static org.junit.Assert.assertNull;
    30
    31  import org.junit.Test;
    32  import org.slf4j.Logger;
    33  import org.slf4j.LoggerFactory;
    34
    35  public class ProfilerTest {
    36
    37      Logger logger = LoggerFactory.getLogger(ProfilerTest.class);
    38
    39      @Test
    40      public void testSmoke() {
    41          Profiler profiler = new Profiler("SMOKE");
    42          profiler.stop();
    43          StopWatch gSW = profiler.globalStopWatch;
    44
    45          // verify
    46          profiler.sanityCheck();
    47          assertEquals(TimeInstrumentStatus.STOPPED, gSW.status);
    48          assertEquals(0, profiler.childTimeInstrumentList.size());
    49          assertNull(profiler.getLastTimeInstrument());
    50      }
    51
    52      @Test
    53      public void testBasicProfiling() {
    54          Profiler profiler = new Profiler("BAS");
    55
    56          profiler.start("doX");
    57          doX(1);
    58
    59          profiler.start("doY");
    60          doY(10);
    61
    62          profiler.start("doZ");
    63          doZ(2);
    64          profiler.stop();
    65
    66          // verify
    67          profiler.sanityCheck();
    68          StopWatch gSW = profiler.globalStopWatch;
    69          assertEquals(TimeInstrumentStatus.STOPPED, gSW.status);
    70          assertEquals(3, profiler.childTimeInstrumentList.size());
    71          assertNotNull(profiler.getLastTimeInstrument());
    72          assertEquals("doZ", profiler.getLastTimeInstrument().getName());
    73      }
    74
    75      // + Profiler [BAS]
    76      // |-- elapsed time [doX] 1.272 milliseconds.
    77      // |-- elapsed time [doYYYYY] 25.398 milliseconds.
    78      // |--+ Profiler [subtask]
    79      // |-- elapsed time [n1] 1.434 milliseconds.
    80      // |-- elapsed time [n2] 5.855 milliseconds.
    81      // |-- Total elapsed time [subtask] 7.321 milliseconds.
    82      // |-- elapsed time [doZ] 3.211 milliseconds.
    83      // |-- Total elapsed time [BAS] 30.317 milliseconds.
    84      @Test
    85      public void testNestedProfiling() {
    86
    87          Profiler profiler = new Profiler("BAS");
    88          profiler.setLogger(logger);
    89          profiler.start("doX");
    90          doX(1);
    91
    92          profiler.start("doYYYYY");
    93          for (int i = 0; i < 5; i++) {
    94              doY(i);
    95          }
    96          Profiler nested = profiler.startNested("subtask");
    97          doSubtask(nested);
    98          profiler.start("doZ");
    99          doZ(2);
    100         profiler.stop();
    101
    102         // verify
    103         profiler.sanityCheck();
    104         StopWatch gSW = profiler.globalStopWatch;
    105         assertEquals(TimeInstrumentStatus.STOPPED, gSW.status);
    106         // assertEquals(3, profiler.stopwatchList.size());
    107         assertEquals(4, profiler.childTimeInstrumentList.size());
    108         assertNotNull(profiler.getLastTimeInstrument());
    109         assertEquals("doZ", profiler.getLastTimeInstrument().getName());
    110
    111     }
    112
    113     private void doX(int millis) {
    114         delay(millis);
    115     }
    116
    117     private void doY(int millis) {
    118         delay(millis);
    119     }
    120
    121     private void doZ(int millis) {
    122         delay(millis);
    123     }
    124
    125     public void doSubtask(Profiler nested) {
    126         nested.start("n1");
    127         doX(1);
    128
    129         nested.start("n2");
    130         doX(5);
    131         nested.stop();
    132     }
    133
    134     void delay(int millis) {
    135         try {
    136             Thread.sleep(millis);
    137         } catch (InterruptedException e) {
    138         }
    139     }
    140 }