[logback-dev] svn commit: r1728 - in logback/trunk/logback-classic: . src/test/java/ch/qos/logback/classic src/test/java/ch/qos/logback/classic/util

noreply.ceki at qos.ch noreply.ceki at qos.ch
Mon Aug 4 19:00:41 CEST 2008


Author: ceki
Date: Mon Aug  4 19:00:40 2008
New Revision: 1728

Added:
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/util/BogoPerf.java
Modified:
   logback/trunk/logback-classic/pom.xml
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/LoggerPerfTest.java
   logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/PackageTest.java

Log:
- performance test are not adjusted according to the performance of the
  host CPU

Modified: logback/trunk/logback-classic/pom.xml
==============================================================================
--- logback/trunk/logback-classic/pom.xml	(original)
+++ logback/trunk/logback-classic/pom.xml	Mon Aug  4 19:00:40 2008
@@ -140,7 +140,6 @@
             <exclude>**/PackageTest.java</exclude>
              <exclude>**/TestConstants.java</exclude>
             <exclude>**/SerializationPerfsTest.java</exclude>
-            <exclude>**/LoggerPerfTest.java</exclude>
           </excludes>
         </configuration>
       </plugin>

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/LoggerPerfTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/LoggerPerfTest.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/LoggerPerfTest.java	Mon Aug  4 19:00:40 2008
@@ -15,54 +15,44 @@
 import junit.framework.TestCase;
 import ch.qos.logback.classic.spi.LoggingEvent;
 import ch.qos.logback.classic.turbo.NOPTurboFilter;
+import ch.qos.logback.classic.util.BogoPerf;
 import ch.qos.logback.core.appender.NOPAppender;
 
 public class LoggerPerfTest extends TestCase {
 
   final static String KAL = "kal";
   String localhostName = null;
-  static long RUN_LENGTH = 1000*1000*10;
+  static long NORMAL_RUN_LENGTH = 1000*1000;
+
+  static long REFERENCE_BIPS = 10000;
   
   public void setUp() throws Exception {
     localhostName = InetAddress.getLocalHost().getCanonicalHostName();
   }
   public void testBasic() {
-    loopBasic(RUN_LENGTH);
-    double avg = loopBasic(RUN_LENGTH); 
+    loopBasic(NORMAL_RUN_LENGTH);
+    double avg = loopBasic(NORMAL_RUN_LENGTH); 
     
-    System.out.println("Running on "+localhostName);
-    // check for performance on KAL only
-    if(KAL.equals(localhostName)) {
-      assertTrue(30 > avg);
-    }
-    System.out.println("Average log time for disabled statements: "+avg+" nanos.");
+    long referencePerf = 17;
+    BogoPerf.assertPerformance(avg, referencePerf, REFERENCE_BIPS);
+    //System.out.println("Average log time for disabled statements: "+avg+" nanos.");
   }
   
   public void testParameterized() {
-
-    loopBasic(RUN_LENGTH);
-    double avg = loopParameterized(RUN_LENGTH); 
-    
-    System.out.println("Running on "+localhostName);
-    // check for performance on KAL only
-    if(KAL.equals(localhostName)) {
-      assertTrue(30 > avg);
-    }
-    System.out.println("Average log time for disabled (parameterized) statements: "+avg+" nanos.");
+    loopBasic(NORMAL_RUN_LENGTH);
+    double avg = loopParameterized(NORMAL_RUN_LENGTH); 
+    long referencePerf = 36;
+    BogoPerf.assertPerformance(avg, referencePerf, REFERENCE_BIPS);
+    //System.out.println("Average log time for disabled (parameterized) statements: "+avg+" nanos.");
   }
   
   
   public void testNOPFilter() {
-    loopNopFilter(RUN_LENGTH);
-    double avg = loopNopFilter(RUN_LENGTH);
-    
-    System.out.println("Running on "+localhostName);
-    System.out.println("Average log time for disabled (NOPFilter) statements: "+avg+" nanos.");
-    // check for performance on KAL only
-    if(KAL.equals(localhostName)) {
-      assertTrue(80 > avg);
-    }
-
+    loopNopFilter(NORMAL_RUN_LENGTH);
+    double avg = loopNopFilter(NORMAL_RUN_LENGTH);
+    //System.out.println("Average log time for disabled (NOPFilter) statements: "+avg+" nanos.");
+    long referencePerf = 48;
+    BogoPerf.assertPerformance(avg, referencePerf, REFERENCE_BIPS);
   }
   
   double loopBasic(long len) {

Modified: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/PackageTest.java
==============================================================================
--- logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/PackageTest.java	(original)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/PackageTest.java	Mon Aug  4 19:00:40 2008
@@ -16,6 +16,7 @@
   public static Test suite() {
     TestSuite suite = new TestSuite();
     suite.addTestSuite(LoggerContextTest.class);
+    suite.addTestSuite(LoggerPerfTest.class);
     suite.addTestSuite(DynamicLoggerContextTest.class);
     suite.addTestSuite(PatternLayoutTest.class);
     suite.addTestSuite(BasicLoggerTest.class);

Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/util/BogoPerf.java
==============================================================================
--- (empty file)
+++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/util/BogoPerf.java	Mon Aug  4 19:00:40 2008
@@ -0,0 +1,88 @@
+package ch.qos.logback.classic.util;
+
+import java.util.Arrays;
+import java.util.Random;
+
+import junit.framework.AssertionFailedError;
+
+public class BogoPerf {
+
+  private static long NANOS_IN_ONE_SECOND = 1000 * 1000 * 1000;
+  private static int INITIAL_N = 1000;
+  private static int LAST_N = 100;
+  private static double INITIAL_BOGO_IPS = computeBogoIPS(INITIAL_N);
+
+  private static int SLACK = 2;
+
+  static {
+    System.out.println("Host runs at "+INITIAL_BOGO_IPS + " BIPS");
+  }
+  
+  /**
+   * compute bogoInstructions per second
+   * <p>
+   * on a 3.2 Ghz Pentium D CPU (around 2007), we obtain about 10'000 bogoIPS.
+   * 
+   * @param N
+   *                number of bogoInstructions to average over in order to
+   *                compute the result
+   * @return bogo Instructions Per Second
+   */
+  private static double computeBogoIPS(int N) {
+    long begin = System.nanoTime();
+
+    for (int i = 0; i < N; i++) {
+      bogoInstruction();
+    }
+    long end = System.nanoTime();
+
+    // duration
+    double D = end - begin;
+    // average duration per instruction
+    double avgDPIS = D / N;
+    // System.out.println(D + " nanos for " + N + " instructions");
+    // System.out.println(avgD + " nanos per instruction");
+
+    double bogoIPS = NANOS_IN_ONE_SECOND / avgDPIS;
+    // System.out.println(bogoIPS + " bogoIPS");
+
+    return bogoIPS;
+  }
+
+  private static void bogoInstruction() {
+    Random random = new Random(100);
+    int len = 500;
+    int[] intArray = new int[len];
+    for (int i = 0; i < len; i++) {
+      intArray[i] = random.nextInt();
+    }
+    Arrays.sort(intArray);
+  }
+
+  /**
+   * Computed the BogoIPS for this host CPU.
+   * 
+   * @return
+   */
+  public static double currentBIPS() {
+    double lastBogos = computeBogoIPS(LAST_N);
+    return (2 * lastBogos + INITIAL_BOGO_IPS) / 3;
+  }
+
+  public static void assertPerformance(double currentPerformance,
+      long referencePerf, double referenceBIPS)
+      throws AssertionFailedError {
+    double ajustedPerf = adjustExpectedValue(referencePerf,
+        referenceBIPS);
+    if (currentPerformance > ajustedPerf * SLACK) {
+      throw new AssertionFailedError(currentPerformance + " exceeded expected "
+          + ajustedPerf + " (adjusted), " + referencePerf + " (raw)");
+    }
+  }
+
+  private static double adjustExpectedValue(long referencePerf,
+      double referenceBIPS) {
+    double currentBIPS = currentBIPS();
+    return referencePerf * (referenceBIPS / currentBIPS);
+  }
+}


More information about the logback-dev mailing list