Permalink
Browse files

Screenshot from Caliper, accurate test results

  • Loading branch information...
1 parent 5f74ef5 commit 6bfeac3856888e7c0ff72fcf7e244d9444202f6d @nurkiewicz committed Jan 12, 2013
Showing with 8 additions and 5 deletions.
  1. +8 −5 README.md
  2. BIN src/main/docs/caliper.png
View
@@ -208,11 +208,14 @@ I hope you are still following our experiment. We are now going to execute `Calc
benchmark ns linear runtime
NoCaching 1.77 =
- ManualCaching 23.70 =
- CacheableWithCglib 1584.21 ==============================
- CacheableWithJdkProxy 1522.35 ============================
- CacheableWithAspectJWeaving 1511.04 ============================
- AspectJCustom 19.86 =
+ ManualCaching 23.84 =
+ CacheableWithCglib 1576.42 ==============================
+ CacheableWithJdkProxy 1551.03 =============================
+ CacheableWithAspectJWeaving 1514.83 ============================
+ AspectJCustom 22.98 =
+
+![Caliper](tree/master/src/main/docs/caliper.png)
+
## Interpretation
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.

5 comments on commit 6bfeac3

@sbrannen

Nice blog post!

BTW, I didn't see a way to comment on your blog, so I'm commenting here...

I found that the results for the AspectJ variants can vary widely across runs, for example...

Run #1: (mvn clean test)

 0% Scenario{vm=java, trial=0, benchmark=NoCaching} 0.56 ns; σ=0.00 ns @ 3 trials
17% Scenario{vm=java, trial=0, benchmark=ManualCaching} 14.62 ns; σ=0.22 ns @ 10 trials
33% Scenario{vm=java, trial=0, benchmark=CacheableWithCglib} 649.68 ns; σ=16.95 ns @ 10 trials
50% Scenario{vm=java, trial=0, benchmark=CacheableWithJdkProxy} 917.76 ns; σ=19.73 ns @ 10 trials
67% Scenario{vm=java, trial=0, benchmark=CacheableWithAspectJWeaving} 636.14 ns; σ=16.85 ns @ 10 trials
83% Scenario{vm=java, trial=0, benchmark=AspectJCustom} 10.34 ns; σ=0.15 ns @ 10 trials

                  benchmark      ns linear runtime
                  NoCaching   0.556 =
              ManualCaching  14.623 =
         CacheableWithCglib 649.675 =====================
      CacheableWithJdkProxy 917.764 ==============================
CacheableWithAspectJWeaving 636.145 ====================
              AspectJCustom  10.340 =

Run #2: (mvn test)

 0% Scenario{vm=java, trial=0, benchmark=NoCaching} 0.57 ns; σ=0.02 ns @ 10 trials
17% Scenario{vm=java, trial=0, benchmark=ManualCaching} 15.09 ns; σ=0.12 ns @ 3 trials
33% Scenario{vm=java, trial=0, benchmark=CacheableWithCglib} 681.09 ns; σ=14.95 ns @ 10 trials
50% Scenario{vm=java, trial=0, benchmark=CacheableWithJdkProxy} 953.89 ns; σ=8.94 ns @ 3 trials
67% Scenario{vm=java, trial=0, benchmark=CacheableWithAspectJWeaving} 0.57 ns; σ=0.01 ns @ 10 trials
83% Scenario{vm=java, trial=0, benchmark=AspectJCustom} 0.57 ns; σ=0.01 ns @ 10 trials

                  benchmark      ns linear runtime
                  NoCaching   0.572 =
              ManualCaching  15.094 =
         CacheableWithCglib 681.086 =====================
      CacheableWithJdkProxy 953.894 ==============================
CacheableWithAspectJWeaving   0.574 =
              AspectJCustom   0.566 =

Run #3: (mvn test)

 0% Scenario{vm=java, trial=0, benchmark=NoCaching} 0.55 ns; σ=0.00 ns @ 3 trials
17% Scenario{vm=java, trial=0, benchmark=ManualCaching} 15.24 ns; σ=1.08 ns @ 10 trials
33% Scenario{vm=java, trial=0, benchmark=CacheableWithCglib} 700.08 ns; σ=19.94 ns @ 10 trials
50% Scenario{vm=java, trial=0, benchmark=CacheableWithJdkProxy} 695.43 ns; σ=22.82 ns @ 10 trials
67% Scenario{vm=java, trial=0, benchmark=CacheableWithAspectJWeaving} 0.55 ns; σ=0.00 ns @ 3 trials
83% Scenario{vm=java, trial=0, benchmark=AspectJCustom} 0.55 ns; σ=0.00 ns @ 3 trials

                  benchmark      ns linear runtime
                  NoCaching   0.552 =
              ManualCaching  15.238 =
         CacheableWithCglib 700.085 ==============================
      CacheableWithJdkProxy 695.435 =============================
CacheableWithAspectJWeaving   0.554 =
              AspectJCustom   0.553 =

Run #4: (mvn clean test)

 0% Scenario{vm=java, trial=0, benchmark=NoCaching} 0.57 ns; σ=0.01 ns @ 10 trials
17% Scenario{vm=java, trial=0, benchmark=ManualCaching} 14.92 ns; σ=0.43 ns @ 10 trials
33% Scenario{vm=java, trial=0, benchmark=CacheableWithCglib} 944.27 ns; σ=39.90 ns @ 10 trials
50% Scenario{vm=java, trial=0, benchmark=CacheableWithJdkProxy} 707.75 ns; σ=64.84 ns @ 10 trials
67% Scenario{vm=java, trial=0, benchmark=CacheableWithAspectJWeaving} 664.62 ns; σ=41.29 ns @ 10 trials
83% Scenario{vm=java, trial=0, benchmark=AspectJCustom} 10.48 ns; σ=0.40 ns @ 10 trials

                  benchmark      ns linear runtime
                  NoCaching   0.566 =
              ManualCaching  14.922 =
         CacheableWithCglib 944.274 ==============================
      CacheableWithJdkProxy 707.755 ======================
CacheableWithAspectJWeaving 664.623 =====================
              AspectJCustom  10.476 =

Run #5: (mvn test)

 0% Scenario{vm=java, trial=0, benchmark=NoCaching} 0.58 ns; σ=0.02 ns @ 10 trials
17% Scenario{vm=java, trial=0, benchmark=ManualCaching} 15.21 ns; σ=0.60 ns @ 10 trials
33% Scenario{vm=java, trial=0, benchmark=CacheableWithCglib} 901.60 ns; σ=27.78 ns @ 10 trials
50% Scenario{vm=java, trial=0, benchmark=CacheableWithJdkProxy} 750.62 ns; σ=45.00 ns @ 10 trials
67% Scenario{vm=java, trial=0, benchmark=CacheableWithAspectJWeaving} 0.55 ns; σ=0.00 ns @ 3 trials
83% Scenario{vm=java, trial=0, benchmark=AspectJCustom} 0.56 ns; σ=0.00 ns @ 3 trials

                  benchmark      ns linear runtime
                  NoCaching   0.579 =
              ManualCaching  15.215 =
         CacheableWithCglib 901.600 ==============================
      CacheableWithJdkProxy 750.615 ========================
CacheableWithAspectJWeaving   0.551 =
              AspectJCustom   0.557 =

Notably, the AspectJ variants are insanely faster for the mvn test builds in contrast to the mvn clean test builds.

Regards,

Sam

@nurkiewicz
Owner

Thank you so much for your experiments! I actually discovered the same phenomena while building this project on Travis (that runs mvn twice). But the AspectJ code is fine, it's the benchmark (or rather the configuration) that has some bug. Please run the following after first mvn clean test:

javap -c -p target/classes/com/blogspot/nurkiewicz/cacheable/calculator/ManuallyInstrumentedCalculator.class

You'll notice plenty of AspectJ references in bytecode. However running mvn test again and the command above after that and you won't see any AspectJ code. For some reason second build erases AspectJ instrumented code. This explains why AspectJ benchmarks in second run are so similar to raw NoCaching bechmark.

I should have added some sanity check to make sure I always run benchmarks on top of instrumented classes. Also there is probably some bug in pom.xml that causes weaving to be discarded during second mvn test.

Thank you for pointing this out. And I apologize for missing comments, they are enabled but comment box is not visible on some browsers/sometimes. Not sure why :-(.

@sbrannen

Aha. It all makes sense now. Thanks for digging deeper and sharing your findings!

@sbrannen

In which browsers does the comments box appear?

I've tried it in Firefox 18.0, Chrome 24.0.1312.52, and Safari 6.0.2 all on Mac OS X 10.8.2, and I don't see a comments box in any of those browsers.

@nurkiewicz
Owner

Thank you for your tests. In my experience the comment panel sometimes appears in Google Chrome and Firefox. I am not a web expert and I'm afraid it might be some bug with Blogger dynamic layout. I filed a bug in a feedback box, I miss comments as well...

Thank you very much again for your valuable input!

Please sign in to comment.