Thank you very much, Remko. So I ran both tests on my machine and got the numbers below. I am interested in the latency numbers and throughput when we have one (i.e. threadCount 1 ?) asynchronous logger thread using disruptor. Can you point me out to these numbers on my results below? Not sure what I am getting when I run RunLog4j2 because the average is much higher than when I run PerfTestDriver. Also what is the difference between the five runs on PerfTestDriver? Are they the same thing executed 5 times?
java -Dlog4j.configurationFile=perf3PlainNoLoc.xml -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -cp target/classes:target/test-classes:lib/disruptor-3.2.1.jar:../log4j-api/target/classes org.apache.logging.log4j.core.async.perftest.PerfTest org.apache.logging.log4j.core.async.perftest.RunLog4j2 blah blah.log 1 -verbose Starting PerfTest blah (1)... Warming up the JVM... Warmup complete in 24.1 seconds Waiting 10 seconds for buffers to drain warmup data... Starting the main test... avg=1250 99%=2048 99.99%=16384 sampleCount=5000000 2587352 operations/second java -Dlog4j.configurationFile=perf3PlainNoLoc.xml -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -cp target/classes:target/test-classes:lib/disruptor-3.2.1.jar:../log4j-api/target/classes org.apache.logging.log4j.core.async.perftest.PerfTestDriver Log4j2: Loggers all async (single thread) (1/5)... (2/5)... (3/5)... (4/5)... (5/5)... took 319.3 seconds avg=102 99%=256 99.99%=1024 sampleCount=5000000 4080781 operations/second avg=168 99%=256 99.99%=1024 sampleCount=5000000 3376301 operations/second avg=103 99%=256 99.99%=2048 sampleCount=5000000 8383943 operations/second avg=102 99%=256 99.99%=2048 sampleCount=5000000 3500849 operations/second avg=65 99%=256 99.99%=2048 sampleCount=5000000 3143970 operations/second throughput: 4,497,168 ops/sec. latency(ns): avg=108.0 99% < 256.0 99.99% < 1638.4 (25000000 samples) ----- Log4j2: Loggers mixed sync/async (single thread) (1/5)... (2/5)... (3/5)... (4/5)... (5/5)... took 322.6 seconds avg=214 99%=512 99.99%=2048 sampleCount=5000000 4257812 operations/second avg=217 99%=256 99.99%=2048 sampleCount=5000000 3027177 operations/second avg=271 99%=512 99.99%=2048 sampleCount=5000000 4304127 operations/second avg=217 99%=512 99.99%=2048 sampleCount=5000000 3008435 operations/second avg=223 99%=512 99.99%=2048 sampleCount=5000000 5430000 operations/second throughput: 4,005,510 ops/sec. latency(ns): avg=228.4 99% < 460.8 99.99% < 2048.0 (25000000 samples) ----- On Sat, Mar 29, 2014 at 3:46 AM, Remko Popma <remko.po...@gmail.com> wrote: > Hi Becky, > > The performance test code is a bit messy. Apologies for that. > > To answer your questions: I used the longer message for throughput tests, > and the shorter message for latency tests. > PerfTest parameters: > [0] = runner class (like org.apache.logging.log4j.core. > async.perftest.RunLog4j2) > [1] = (blah) is the test name (like "Loggers all async") printed to the > console when a test is started. > [2] = file name to write results to > [3] = thread count (default=3) > followed by optional parameters -verbose and -throughput. > > The current implementation of PerfTest runs one throughput and one latency > test, regardless of whether -throughput is specified. > > The PerfTestDriver class is the start point for all tests. It sets up > various things like classpath, and system properties to control various > things for different tests. If you use the PerfTest class directly you need > to set up these parameters manually: > -Dlog4j.configurationFile=perf3PlainNoLoc.xml > > -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector > > The perf3PlainNoLoc.xml config determines the log file. > The PerfTestDriver would automatically delete this file after each run, you > probably want to do this manually. > > Hope this helps, > Remko > > > > On Sat, Mar 29, 2014 at 12:03 PM, Rebecca Ahlvarsson > <rahlvars...@gmail.com>wrote: > > > I am trying to run the async performance tests described on the link > below > > on my machine. > > > > > > > http://logging.apache.org/log4j/2.x/manual/async.html#Asynchronous_Logging_Performance > > > > I am not an expert with log4j, so here is how far I got after building > > log4j with maven: > > > > java -cp > > > > > target/classes:target/test-classes:lib/disruptor-3.2.1.jar:../log4j-api/target/classes > > org.apache.logging.log4j.core.async.perftest.PerfTest > > org.apache.logging.log4j.core.async.perftest.RunLog4j2 blah blah.log 1 > > -verbose > > > > Then I get this in the output: > > > > avg=17 99%=32 99.99%=64 sampleCount=5000000 > > 9962247 operations/second > > > > The questions I have are: > > > > 1. It looks like the source code IPerfTestRunner uses a much shorter > > message "Short Msg" instead of the 500 characters message stated in the > > link above. Is that intentional or is it a bug? Do we want to test the > > latency with the 500-character message or just a short message? > > > > 2. I notice that my logs are NOT going to any file. I am probably > > misconfiguring something with log4j. How do I generate a file with the > > messages from the performance test? > > > > 3. I just want to test with one asynchronous logging thread, so I am > > passing threadCount 1 above. What does the second parameter 'blah' mean? > > > > 4. Not sure why I get operations/seconds if I am not passing -throughput > in > > the command-line. I just want to get the latency numbers for now. After > > that I will worry about throughput. > > > > So basically I just want to run the same test you run to see those great > > numbers on my production machine. > > > > Thanks for the help! > > > > -Becky > > > -- -Becky
