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); + } +}