Hi Emmanuel or all, I'm working on Kerby benchmark and just converted existing benchmark tests to use JMH micro benchmark framework. A test related to ApacheDS failed as below and I'm wondering if there're some concurrency issue in the codes. Would you take a look at it if you're convenient? Thanks.
How to repeat: cd benchmark/ mvn integration-test Kind regards, Kai [INFO] [INFO] --- exec-maven-plugin:1.4.0:exec (run-benchmarks) @ benchmark --- # JMH 1.10.3 (released 3 days ago) # VM version: JDK 1.7.0_60, VM 24.60-b09 Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true # VM invoker: c:\work\jdk\jre\bin\java.exe # VM options: -Djava.net.preferIPv4Stack=true # Warmup: 2 iterations, 1 s each # Measurement: 5 iterations, 1 s each # Timeout: 10 min per iteration # Threads: 1 thread, will synchronize iterations # Benchmark mode: Average time, time/op # Benchmark: org.apache.kerby.benchmark.KrbCodecBenchmark.decodeWithApacheDS # Run progress: 0.00% complete, ETA 00:00:28 # Fork: 1 of 2 # Warmup Iteration 1: SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. <failure> org.apache.directory.api.asn1.DecoderException: ERR_00001_BAD_TRANSITION_FROM_STATE Bad transition from state START_STATE, tag 0x6E at org.apache.directory.api.asn1.ber.grammar.AbstractGrammar.executeAction(AbstractGrammar.java:125) at org.apache.directory.api.asn1.ber.Asn1Decoder.treatTLVDoneState(Asn1Decoder.java:600) at org.apache.directory.api.asn1.ber.Asn1Decoder.decode(Asn1Decoder.java:736) at org.apache.directory.shared.kerberos.codec.apReq.actions.StoreTicket.action(StoreTicket.java:83) at org.apache.directory.shared.kerberos.codec.apReq.actions.StoreTicket.action(StoreTicket.java:41) at org.apache.directory.api.asn1.ber.grammar.AbstractGrammar.executeAction(AbstractGrammar.java:136) at org.apache.directory.api.asn1.ber.Asn1Decoder.treatTLVDoneState(Asn1Decoder.java:600) at org.apache.directory.api.asn1.ber.Asn1Decoder.decode(Asn1Decoder.java:736) at org.apache.kerby.benchmark.KrbCodecBenchmark.decodeWithApacheDS(KrbCodecBenchmark.java:68) at org.apache.kerby.benchmark.generated.KrbCodecBenchmark_decodeWithApacheDS.decodeWithApacheDS_avgt_jmhStub(KrbCodecBenchmark_decodeWithApacheDS.java at org.apache.kerby.benchmark.generated.KrbCodecBenchmark_decodeWithApacheDS.decodeWithApacheDS_AverageTime(KrbCodecBenchmark_decodeWithApacheDS.java: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:430) at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:412) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true # Run progress: 25.00% complete, ETA 00:00:04 # Fork: 2 of 2 # Warmup Iteration 1: SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. <failure> org.apache.directory.api.asn1.DecoderException: ERR_00001_BAD_TRANSITION_FROM_STATE Bad transition from state START_STATE, tag 0x6E at org.apache.directory.api.asn1.ber.grammar.AbstractGrammar.executeAction(AbstractGrammar.java:125) at org.apache.directory.api.asn1.ber.Asn1Decoder.treatTLVDoneState(Asn1Decoder.java:600) at org.apache.directory.api.asn1.ber.Asn1Decoder.decode(Asn1Decoder.java:736) at org.apache.directory.shared.kerberos.codec.apReq.actions.StoreTicket.action(StoreTicket.java:83) at org.apache.directory.shared.kerberos.codec.apReq.actions.StoreTicket.action(StoreTicket.java:41) at org.apache.directory.api.asn1.ber.grammar.AbstractGrammar.executeAction(AbstractGrammar.java:136) at org.apache.directory.api.asn1.ber.Asn1Decoder.treatTLVDoneState(Asn1Decoder.java:600) at org.apache.directory.api.asn1.ber.Asn1Decoder.decode(Asn1Decoder.java:736) at org.apache.kerby.benchmark.KrbCodecBenchmark.decodeWithApacheDS(KrbCodecBenchmark.java:68) at org.apache.kerby.benchmark.generated.KrbCodecBenchmark_decodeWithApacheDS.decodeWithApacheDS_avgt_jmhStub(KrbCodecBenchmark_decodeWithApacheDS.java at org.apache.kerby.benchmark.generated.KrbCodecBenchmark_decodeWithApacheDS.decodeWithApacheDS_AverageTime(KrbCodecBenchmark_decodeWithApacheDS.java: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:430) at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:412) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true # JMH 1.10.3 (released 3 days ago) # VM version: JDK 1.7.0_60, VM 24.60-b09 Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true # VM invoker: c:\work\jdk\jre\bin\java.exe # VM options: -Djava.net.preferIPv4Stack=true # Warmup: 2 iterations, 1 s each # Measurement: 5 iterations, 1 s each # Timeout: 10 min per iteration # Threads: 1 thread, will synchronize iterations # Benchmark mode: Average time, time/op # Benchmark: org.apache.kerby.benchmark.KrbCodecBenchmark.decodeWithKerby # Run progress: 50.00% complete, ETA 00:00:02 # Fork: 1 of 2 # Warmup Iteration 1: 25545.827 ns/op # Warmup Iteration 2: 7670.003 ns/op Iteration 1: 7228.367 ns/op Iteration 2: 6854.991 ns/op Iteration 3: 6827.826 ns/op Iteration 4: 6873.941 ns/op Iteration 5: 6968.195 ns/op Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true # Run progress: 75.00% complete, ETA 00:00:03 # Fork: 2 of 2 # Warmup Iteration 1: 23219.519 ns/op # Warmup Iteration 2: 7588.838 ns/op Iteration 1: 7017.634 ns/op Iteration 2: 7084.992 ns/op Iteration 3: 6890.524 ns/op Iteration 4: 7293.447 ns/op Iteration 5: 6964.228 ns/op Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true Result "decodeWithKerby": 7000.414 ±(99.9%) 239.912 ns/op [Average] (min, avg, max) = (6827.826, 7000.414, 7293.447), stdev = 158.687 CI (99.9%): [6760.502, 7240.326] (assumes normal distribution) # Run complete. Total time: 00:00:18 Benchmark Mode Cnt Score Error Units KrbCodecBenchmark.decodeWithKerby avgt 10 7000.414 ± 239.912 ns/op Picked up _JAVA_OPTIONS: -Djava.net.preferIPv4Stack=true [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 32.830s [INFO] Finished at: Mon Jul 20 11:53:21 CST 2015 [INFO] Final Memory: 21M/365M [INFO] ------------------------------------------------------------------------ kaizhen@KAIZHEN-MOBL1 /c/work/projects/kerby/benchmark (master)
