logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (LOG4J2-1611) Improve performance of ThreadContextDataInjector.ForDefaultThreadContextMap
Date Sat, 24 Sep 2016 18:15:20 GMT

    [ https://issues.apache.org/jira/browse/LOG4J2-1611?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15519381#comment-15519381
] 

Remko Popma edited comment on LOG4J2-1611 at 9/24/16 6:14 PM:
--------------------------------------------------------------

When I ran the JMH ThreadContextBenchmark I found a performance problem when merging context
data with properties. This is now addressed. Updated benchmark results follow below.

----
!InjectWithoutProperties.png!
5: context data has 5 elements
50: context data has 50 elements
500: context data has 500 elements
"Default (map to ctxtdata)" is the JdkMapAdapterStringMap wrapper around the Map<String,String>
thread context copy. This is much faster than previously when the Map was copied into a SortedArray
data structure (see below).

The "Copy" variants are fast because they already copied the data structure on ThreadContext::put()
or ThreadContext::remove(), and now they just pass a reference. The NoGc variants need to
copy the data structure. SortedArray benefits from being compact.

h3. Old version (before the fix)
!https://issues.apache.org/jira/secure/attachment/12825061/12825061_v2_InjectWithoutConfigProperties.png!
----
!InjectWithProperties.png!
Same as above, with 5 properties that need to be merged with the context data.
"Default (map to ctxtdata)" creates a mutable copy of the Map<String,String> thread
context and wraps it in a JdkMapAdapterStringMap before adding the property key-values. (Previously
the implementation copied from the Map into a SortedArray, which was _slow_ because the Map
iterator does not return the keys in alphabetic order.)

(Please ignore the CopyOpenHash result; this data structure is only for benchmarking. It demonstrates
how slow it can be to copy unsorted data in a SortedArray.)

----
!ThreadContext-PutAndRemove.png!
5: put one new key-value pair, then remove it from a ThreadContext with 5 elements
50: put one new key-value pair, then remove it from a ThreadContext with 50 elements
500: put one new key-value pair, then remove it from a ThreadContext with 500 elements

Put and remove is expensive for the SortedArray variants because the remainder of the array
needs to be copied one position to the left or right, but this is cheap compared to the copy-on-write
map implementations that need to copy the whole data structure. 

----
!ThreadContext-Get.png!
SortedArray uses binary search which is a bit slower than the hash-based data structures.
I am looking at speeding this up (LOG4J2-1607) by maintaining an additional hash index in
SortedArrayStringMap.


was (Author: remkop@yahoo.com):
When I ran the JMH ThreadContextBenchmark I found a performance problem when merging context
data with properties. This is now addressed. Updated benchmark results follow below.

----
!InjectWithoutProperties.png!
5: context data has 5 elements
50: context data has 50 elements
500: context data has 500 elements
"Default (map to ctxtdata)" is the JdkMapAdapterStringMap wrapper around the Map<String,String>
thread context copy. This is much faster than previously when the Map was copied into a SortedArray
data structure (see below).

The "Copy" variants are fast because they already copied the data structure on ThreadContext::put()
or ThreadContext::remove(), and now they just pass a reference. The NoGc variants need to
copy the data structure. SortedArray benefits from being compact.

*Old version*
!https://issues.apache.org/jira/secure/attachment/12825061/12825061_v2_InjectWithoutConfigProperties.png!
----
!InjectWithProperties.png!
Same as above, with 5 properties that need to be merged with the context data.
"Default (map to ctxtdata)" creates a mutable copy of the Map<String,String> thread
context and wraps it in a JdkMapAdapterStringMap before adding the property key-values. (Previously
the implementation copied from the Map into a SortedArray, which was _slow_ because the Map
iterator does not return the keys in alphabetic order.)

(Please ignore the CopyOpenHash result; this data structure is only for benchmarking. It demonstrates
how slow it can be to copy unsorted data in a SortedArray.)

----
!ThreadContext-PutAndRemove.png!
5: put one new key-value pair, then remove it from a ThreadContext with 5 elements
50: put one new key-value pair, then remove it from a ThreadContext with 50 elements
500: put one new key-value pair, then remove it from a ThreadContext with 500 elements

Put and remove is expensive for the SortedArray variants because the remainder of the array
needs to be copied one position to the left or right, but this is cheap compared to the copy-on-write
map implementations that need to copy the whole data structure. 

----
!ThreadContext-Get.png!
SortedArray uses binary search which is a bit slower than the hash-based data structures.
I am looking at speeding this up (LOG4J2-1607) by maintaining an additional hash index in
SortedArrayStringMap.

> Improve performance of ThreadContextDataInjector.ForDefaultThreadContextMap
> ---------------------------------------------------------------------------
>
>                 Key: LOG4J2-1611
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1611
>             Project: Log4j 2
>          Issue Type: Improvement
>          Components: Core
>    Affects Versions: 2.7
>            Reporter: Remko Popma
>            Assignee: Remko Popma
>             Fix For: 2.7
>
>         Attachments: InjectWithProperties.png, InjectWithoutProperties.png, ThreadContext-Get.png,
ThreadContext-PutAndRemove.png
>
>
> Current implementation of {{ThreadContextDataInjector.ForDefaultThreadContextMap::injectContextData}}
always copies all elements from the ThreadContext into the reused StringMap of the LogEvent.
> Since the DefaultThreadContextMap is used in web applications (when non-JDK thread-locals
are not available and Log4j is not garbage-free), we don't need to worry about creating additional
objects. We can speed up the {{injectContextData}} method by wrapping the context data {{Map<String,
String>}} in a decorator object that implements the {{StringMap}} interface.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

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


Mime
View raw message