[
https://issues.apache.org/jira/browse/LOG4J2-467?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13862236#comment-13862236
]
Remko Popma commented on LOG4J2-467:
------------------------------------
Performance test result update:
The numbers I reported in the [comment
above|https://issues.apache.org/jira/browse/LOG4J2-467?focusedCommentId=13862126&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-13862126]
are all results for the CACHED thread name scenario. Here they are again:
*CACHED*
{code}
(1 thread) : throughput: 4,407,972 ops/sec.
(2 threads): throughput: 2,717,954 ops/sec.
(4 threads): throughput: 1,616,480 ops/sec.
(1 thread) : throughput: 4,124,748 ops/sec.
(2 threads): throughput: 1,928,624 ops/sec.
(4 threads): throughput: 3,006,960 ops/sec.
(1 thread) : throughput: 4,987,891 ops/sec.
(2 threads): throughput: 1,933,868 ops/sec.
(4 threads): throughput: 3,222,753 ops/sec.
(1 thread) : throughput: 4,670,605 ops/sec.
(2 threads): throughput: 2,215,214 ops/sec.
(4 threads): throughput: 1,154,320 ops/sec.
{code}
I've re-run the tests with the updated PerfTestDriver and the
-DAsyncLogger.ThreadNameStrategy=UNCACHED option:
*UNCACHED*
{code}
(1 thread) : throughput: 3,429,421 ops/sec.
(2 threads): throughput: 1,688,868 ops/sec.
(4 threads): throughput: 2,207,599 ops/sec.
(1 thread) : throughput: 4,684,796 ops/sec.
(2 threads): throughput: 1,232,496 ops/sec.
(4 threads): throughput: 2,906,195 ops/sec.
(1 thread) : throughput: 3,404,258 ops/sec.
(2 threads): throughput: 1,821,020 ops/sec.
(4 threads): throughput: 4,254,485 ops/sec.
{code}
(All on Windows 7 (64bit) with JDK1.7.0_45, 2-core Intel i5-3317u CPU @1.70Ghz
with hyperthreading switched on (4 virtual cores)).
Discounting the 4-thread tests (too much variance) I get these averages (in
million ops/sec):
| |Cached|Uncached|
|1 thread|4.5|3.8|
|2 thread|2.2|1.6|
I will re-run the tests on a Unix box with more cores next week (should have
less variance).
> 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
> Assignee: Remko Popma
> Fix For: 2.0-rc1
>
> Attachments: PerfTestDriver.java, 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
