[logback-dev] svn commit: r2353 - logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo

[noreply.ceki at qos.ch]

Author: ceki
Date: Wed Jul 15 13:52:32 2009
New Revision: 2353

Modified:
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java

Log:
- performance related testing of auto reconfiguration. Related to LBCORE-59

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java	Wed Jul 15 13:52:32 2009
@@ -7,6 +7,7 @@
 import java.net.MalformedURLException;
 
 import org.junit.Test;
+import org.slf4j.helpers.BogoPerf;
 
 import ch.qos.logback.classic.Level;
 import ch.qos.logback.classic.Logger;
@@ -21,18 +22,21 @@
 import ch.qos.logback.core.status.StatusChecker;
 
 public class ReconfigureOnChangeTest {
-  LoggerContext loggerContext = new LoggerContext();
-  Logger logger = loggerContext.getLogger(this.getClass());
   final static int THREAD_COUNT = 5;
+  final static int LOOP_LEN = 1000*1000;
 
-  String SCAN1_FILE_AS_STR = TeztConstants.TEST_DIR_PREFIX
+  
+  final static String SCAN1_FILE_AS_STR = TeztConstants.TEST_DIR_PREFIX
       + "input/turbo/scan1.xml";
 
   static int TOTAL_TEST_DURATION = 2000;
+
   // it actually takes time for Windows to propagate file modification changes
   // values below 100 milliseconds can be problematic
   static int SLEEP_BETWEEN_UPDATES = 300;
 
+  LoggerContext loggerContext = new LoggerContext();
+  Logger logger = loggerContext.getLogger(this.getClass());
   MultiThreadedHarness harness = new MultiThreadedHarness(TOTAL_TEST_DURATION);
 
   void configure(String file) throws JoranException {
@@ -71,38 +75,65 @@
     assertTrue((effectiveResets * 1.1) >= (expectedRreconfigurations * 1.0));
   }
 
-  @Test
-  public void perfTest() throws MalformedURLException {
+  ReconfigureOnChangeFilter initROCF() throws MalformedURLException {
     ReconfigureOnChangeFilter rocf = new ReconfigureOnChangeFilter();
     rocf.setContext(loggerContext);
     File file = new File(SCAN1_FILE_AS_STR);
     loggerContext.putObject(CoreConstants.URL_OF_LAST_CONFIGURATION_VIA_JORAN,
         file.toURI().toURL());
     rocf.start();
+    return rocf;
+  }
+  
+  @Test
+  public void directPerfTest() throws MalformedURLException {
+    ReconfigureOnChangeFilter rocf = initROCF();
     assertTrue(rocf.isStarted());
-    loggerContext.addTurboFilter(rocf);
     
-    final int loopLen = 1000*1000;
-    
-    loop(loopLen, rocf);
-    loop(loopLen, rocf);
-    double avg = loop(loopLen, rocf);
+    directLoop(rocf);
+    double avg = directLoop(rocf);
     System.out.println(avg);
-    // the reference was computed on Orion (Ceki's computer)
-    //long referencePerf = 5000;
-    //BogoPerf.assertDuration(avg, referencePerf, CoreConstants.REFERENCE_BIPS); 
+    //the reference was computed on Orion (Ceki's computer)
+    long referencePerf = 18;
+    BogoPerf.assertDuration(avg, referencePerf, CoreConstants.REFERENCE_BIPS); 
   }
 
-  public double loop(int loopLen, ReconfigureOnChangeFilter rocf) {
+  public double directLoop(ReconfigureOnChangeFilter rocf) {
     long start = System.nanoTime();
-    for (int i = 0; i < loopLen; i++) {
-        //logger.debug("hello");
+    for (int i = 0; i < LOOP_LEN; i++) {
       rocf.decide(null, logger, Level.DEBUG, " ", null, null);
     }
     long end = System.nanoTime();
-    return (end - start) / (1.0d * loopLen);
+    return (end - start) / (1.0d * LOOP_LEN);
   }
   
+
+  @Test
+  public void indirectPerfTest() throws MalformedURLException {
+    ReconfigureOnChangeFilter rocf = initROCF();
+    assertTrue(rocf.isStarted());
+    loggerContext.addTurboFilter(rocf);
+    logger.setLevel(Level.ERROR);
+    
+    indirectLoop();
+    double avg = indirectLoop();
+    System.out.println(avg);
+    //the reference was computed on Orion (Ceki's computer)
+    long referencePerf = 68;
+    BogoPerf.assertDuration(avg, referencePerf, CoreConstants.REFERENCE_BIPS); 
+  }
+
+  
+  public double indirectLoop() {
+    long start = System.nanoTime();
+    for (int i = 0; i < LOOP_LEN; i++) {
+      logger.debug("hello");
+    }
+    long end = System.nanoTime();
+    return (end - start) / (1.0d * LOOP_LEN);
+  }
+  
+  
   class Updater extends RunnableWithCounterAndDone {
     File configFile;