logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Rebecca Ahlvarsson <rahlvars...@gmail.com>
Subject Re: Running disruptor async performance tests
Date Sat, 29 Mar 2014 13:46:31 GMT
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.popma@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
> <rahlvarsson@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

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message