log4j

log4j This are done using log4j version 1.2.9.

See also tests on Generating the caller class information.

Refer to the results in org.apache.log4j.performance.Logging for other tests

NullAppender tests

Configuration: JVM 1.4.2, Test class net.sf.jour.log4j.TestPerformance

Configuration files in folder test-scripts. Two JVM involved Client and Server.

  • Test 1 Local NullAppender does nothing.
  • Test 2 SocketAppender writes to Server on localhost or remote host, Server writes to NullAppender
  • Test 3 AsyncAppender writes to SocketAppender from test 2.

Experimental results average duration of call to log.debug() are listed below in units of milliseconds. Accuracy 30%.

IDSystemOS1) Local NullAppender2) SocketAppender3) AsyncAppender
PC0Intel PIII 646 MHzXP-sp20.0061.6001.800
PC0Intel PIII 646 MHzLinux FC10.0201.8001.430
PC1Intel PIII 500 MHzLinux RH 80.0102.4001.750
PC2AMD Athlon 1.2 GHzXP-sp20.0040.8001.300
PC1 -> PC2 100Base-TXRH 8 -> XP-sp2n/a1.1000.780
PC2 -> PC1 100Base-TXXP-sp2 -> RH 8n/a0.7700.580
PC3Intel P4 2.6 GHz Hyper-ThreadingXP-sp20.0050.7800.810
PC3Intel P4 2.6 GHz Hyper-ThreadingLinux FC20.0060.4900.460
PC4Intel Xeon 2CPU x 3GHzw2k0.0010.2900.240
PC4 -> PC3w2k -> XP-sp2n/a0.2000.160

Enable/Disable LocationInfo since it takes at least 10% when profiling application.

LoggingEvent size 540 and 470 bytes respectively.

When LocationInfo Disabled socketWrite takes 59% of CPU time.

IDSystemOSSocketAppenderSocketAppender no LocationInfo
PC3Intel P4 2.6 GHz HTXP-sp20.8000.220
PC3 -> PC40.3600.150

ProfilerSocketAppender tests

Sending Small net.sf.jour.log4j.ProfilerEvent over the wire.

SocketAppender is LoggingEvent with no LocationInfo.

ProfilerSocketAppender is changed version of log4j SocketAppender to send only ProfilerEvent object.

LoggingEvent size 470 bytes, ProfilerEvent size 125 bytes.

IDSystemOSSocketAppenderProfilerSocketAppenderProfilerArraySocketAppenderAsyncAppenderProfilerAsyncAppender
PC3Intel P4 2.6 GHz HTXP-sp20.2200.1200.530
PC3 -> PC40.1540.0800.0280.1300.080

Using ProfilerArraySocketAppender will work much faster for ProfilerEvent.

Conclusion

Sending default LoggingEvent from log4j over wire adds big overhead to profiler. We should consider using our own Event object and handle it differently than log4j.