[ 
https://issues.apache.org/jira/browse/LOG4J2-467?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Remko Popma updated LOG4J2-467:
-------------------------------

    Attachment: PerfTestDriver.java

Gary, I've tested the performance difference like you asked. I used the 
existing benchmark test that I used to generate the performance numbers for 
Async Loggers: org.apache.logging.log4j.core.async.perftest.*
I modified the PerfTestDriver class to comment out all tests except for 
"Loggers all async", and tested for 1, 2 and 4 threads. Here are the results:

{code}
Cached thread name (AsyncLogger line 203: info.cachedThreadName)
1 thread : throughput: 4,380,953 ops/sec. (avg of 5 runs)
2 threads: throughput: 2,481,713 ops/sec. (avg of 5 runs)
4 threads: throughput: 5,712,182 ops/sec. (avg of 3 runs)

Thread.currentThread().getName() (AsyncLogger line 202)
1 thread : throughput: 3,762,280 ops/sec. (avg of 5 runs)
2 threads: throughput: 2,805,796 ops/sec. (avg of 5 runs)
4 threads: throughput: 2,193,664 ops/sec. (avg of 3 runs)
{code}

I conclude that caching the thread name gives a significant performance benefit.

I attached the PerfTestDriver class so you can run the tests yourself to verify 
these results if you want. Each run takes about 30 minutes. To toggle between 
Thread.currentThread().getName() and the cached thread name, you need to modify 
AsyncLogger and recompile.

> Thread name caching in async logger incompatible with use of Thread.setName()
> -----------------------------------------------------------------------------
>
>                 Key: LOG4J2-467
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-467
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.0-beta9
>         Environment: Debian Squeeze amd64
> OpenJDK 7u25
>            Reporter: Anthony Baldocchi
>         Attachments: PerfTestDriver.java
>
>
> AsyncLogger caches a thread's name in a thread-local info variable.  I make 
> use of a thread pool where the submitted Runnables call Thread.setName() at 
> the beginning of their task and the thread name is included in the log 
> message.  For an example of this behavior, see 
> org.jboss.netty.util.ThreadRenamingRunnable in Netty 3.x.  With the cached 
> thread name, the log messages will contain whatever name the thread had when 
> it logged for the first time and so long as the thread doesn't terminate 
> (such as in a core pool thread), all log messages involving this thread will 
> be erroneous.  If Thread.getName has a significant performance impact for 
> async logging, I would be satisfied if this behavior were configurable, 
> perhaps on a per-logger basis, so that the penalty only needs to be taken by 
> users who make use of Thread.setName()



--
This message was sent by Atlassian JIRA
(v6.1.5#6160)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org

Reply via email to