Tapestry Training -- From The Source

Let me help you get your team up to speed in Tapestry ... fast. Visit howardlewisship.com for details on training, mentoring and support!

Friday, September 12, 2003

Sometimes testing numbers just don't make sense

Based on what I did yesterday, I thought I'd see if I could improve the efficiency of the LoggingInterceptor by directly invoking methods on the commons-logging wrapper class, rather the the Log interface. Fortunately, I decided to do some tests to see about relative costs. I don't fully understand the results (Windows XP, Sun JDK 1.4, Hotspot server) ... obviously, Hotspot is doing something interesting to the code.

Run Log4J Direct Jakarta (Interface) Jakarta (Impl)
Run #1 741 711 701
Run #2 1622 671 551
Run #3 661 521 541
Run #4 641 540 571
Run #5 621 541 551
Run #6 610 521 551
Run #7 611 531 560
Run #8 611 531 551
Run #9 621 521 550
Run #10 611 521 551
Run #11 611 530 551
Run #12 611 521 551
Run #13 611 520 561
Run #14 611 531 550
Run #15 611 511 531
Run #16 581 510 581
Run #17 621 531 601
Run #18 631 571 570
Run #19 621 541 571
Run #20 621 541 570

The tests invoked isDebugEnabled() 50,000,000 times. I did what I could to help ensure that things didn't get unrealistically inlined.

What I don't understand is why going through the Log interface is sometimes faster than either going through the Log4J Logger class, or through the commons-logging Log4JCategoryLog class. I checked the commons-logging code ... Log4JCategoryLog is a very thin wrapper that delegates to a Logger.

Anyway, until I find better tests for figuring out performance, there's no reason to change the LoggingInterceptor code.

No comments: