[
https://issues.apache.org/jira/browse/LOG4J2-1349?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15431155#comment-15431155
]
Remko Popma edited comment on LOG4J2-1349 at 8/22/16 4:59 PM:
--------------------------------------------------------------
This is now available for review in branch {{LOG4J2-1349-gcfree-threadcontext}}.
* Moved ContextData and related interfaces to org.apache.logging.log4j.spi
package in log4j-api
* There are two implementations: ArrayContextData and OpenHashMapContextData
(also in the spi package)
*Benchmarks*
For benchmarking purposes, I created a copy-on-write ContextData-based and a
garbage-free ContextData-based ThreadContextMap implementation for each of
these data structures. These are compared against the current
java.util.HashMap-based ThreadContextMap. See
{{org.apache.logging.log4j.perf.jmh.ThreadContextBenchmark}}.
!ThreadContextPut.png!
This benchmark compares how fast data can be put into the thread context for
each of the data structures. The 5, 50, 500 is the number of key-value pairs we
put in the context. "Default" is the current copy-on-write HashMap<String,
String> implementation that is in master. Note that the default implementation
becomes very slow if we put hundreds of key-value pairs in the context.
!InjectWithoutConfigProperties.png!
Injecting is the operation of copying data from the thread context to a log
event. "Inject without config properties" is the happy case where there are no
{{List<Property>}} key-value pairs from the configuration. For the
copy-on-write thread context we can use the current thread context snapshot
without any further modifications. This is very fast. (The "Default" current
copy-on-write HashMap<String, String> implementation is not fast any more now
that the LogEvent has a ContextData object instead of a Map, so we need to copy
the key-value pairs.)
The ArrayContextData data structure is optimized for fast copy and this works
quite well; the Garbage-free ArrayContextData-based thread context performs
good enough for smallish (less than 100 items) data sets.
!InjectWithConfigProperties.png!
The other inject case is where we need to copy data from _both_ the thread
context _and_ the configuration's {{List<Property>}} key-value pairs. Here we
cannot just use the reference; we need to do some additional copying even if
the thread context is copy-on-write. The ArrayContextData data structure (being
optimized for fast copy) performs best here.
*Data structure basic operations*
This benchmark and the next zoom in on the underlying data structure and
compare the performance of ArrayContextData, OpenHashMapContextData and
java.util.HashMap for a number of basic operations:
* creating a copy ("clone" invokes the copy constructor)
* putAll on an empty instance
* put a single key-value pair
* get a single value for a specified key
* iterate over all key-value pairs. For the ContextData this is done with the
BiConsumer and TriConsumer interface. For java.util.HashMap this is done with
the standard Iterator.
See {{org.apache.logging.log4j.perf.jmh.ArrayContextDataVsHashMapBenchmark}}.
!DataStructOpsPerfSmallDataSet.png!
The above benchmark is for a small data set of 5 items.
!DataStructOpsPerfMediumDataSet.png!
This graph shows the results of the same test for a medium size data set of 500
items. This shows that the ArrayContextData is optimized for fast iteration and
fast initialization/copy. Getting and putting single values is not as fast as
with a hash map. For our use case (less than 100 items) the difference is
acceptable.
*Conclusion*
When the configuration does not declare any {{<Property>}} elements, the
copy-on-write thread context is faster, otherwise the garbage-free thread
context is faster.
Either way, an ArrayContextData-based thread context performs much better than
the current java.util.HashMap-based implementation (now that LogEvents use
ContextData instead of Map<String, String>).
*ThreadContext API*
No changes are required to the public ThreadContext API. I added a
package-protected method {{ThreadContext::getThreadContextMap}} which will not
be visible to user code.
was (Author: [email protected]):
This is now available for review in branch {{LOG4J2-1349-gcfree-threadcontext}}.
* Moved ContextData and related interfaces to org.apache.logging.log4j.spi
package in log4j-api
* There are two implementations: ArrayContextData and OpenHashMapContextData
(also in the spi package)
*Benchmarks*
For benchmarking purposes, I created a copy-on-write ContextData-based and a
garbage-free ContextData-based ThreadContextMap implementation for each of
these data structures. These are compared against the current
java.util.HashMap-based ThreadContextMap.
!ThreadContextPut.png!
This benchmark compares how fast data can be put into the thread context for
each of the data structures. The 5, 50, 500 is the number of key-value pairs we
put in the context. "Default" is the current copy-on-write HashMap<String,
String> implementation that is in master. Note that the default implementation
becomes very slow if we put hundreds of key-value pairs in the context.
!InjectWithoutConfigProperties.png!
Injecting is the operation of copying data from the thread context to a log
event. "Inject without config properties" is the happy case where there are no
{{List<Property>}} key-value pairs from the configuration. For the
copy-on-write thread context we can use the current thread context snapshot
without any further modifications. This is very fast. (The "Default" current
copy-on-write HashMap<String, String> implementation is not fast any more now
that the LogEvent context data is a ContextData object and not a Map any more,
so we need to copy the key-value pairs.)
The ArrayContextData data structure is optimized for fast copy and this works
quite well; the Garbage-free ArrayContextData-based thread context performs
good enough for smallish (less than 100 items) data sets.
!InjectWithConfigProperties.png!
The other inject case is where we need to copy data from _both_ the thread
context _and_ the configuration's {{List<Property>}} key-value pairs. Here we
cannot just use the reference; we need to do some additional copying even if
the thread context is copy-on-write. The ArrayContextData data structure (being
optimized for fast copy) performs best here.
!DataStructOpsPerfSmallDataSet.png!
This benchmark and the next compare the performance of ArrayContextData,
OpenHashMapContextData and java.util.HashMap for a number of basic operations:
* creating a copy ("clone" invokes the copy constructor)
* putAll on an empty instance
* put a single key-value pair
* get a single value for a specified key
* iterate over all key-value pairs. For the ContextData this is done with the
BiConsumer and TriConsumer interface. For java.util.HashMap this is done with
the standard Iterator.
The above benchmark is for a small data set of 5 items.
!DataStructOpsPerfMediumDataSet.png!
This graph shows the results of the same test for a medium size data set of 500
items. This shows that the ArrayContextData is optimized for fast iteration and
fast initialization/copy. Getting and putting single values is not as fast as
with a hash map. For our use case (less than 100 items) the difference is
acceptable.
*Conclusion*
When the configuration does not declare any {{<Property>}} elements, the
copy-on-write thread context is faster, otherwise the garbage-free thread
context is faster.
Either way, an ArrayContextData-based thread context performs much better than
the current java.util.HashMap-based implementation (now that LogEvents use
ContextData instead of Map<String, String>).
*ThreadContext API*
No changes are required to the public ThreadContext API. I added a
package-protected method {{ThreadContext::getThreadContextMap}} which will not
be visible to user code.
> Garbage-free ThreadContext map
> ------------------------------
>
> Key: LOG4J2-1349
> URL: https://issues.apache.org/jira/browse/LOG4J2-1349
> Project: Log4j 2
> Issue Type: Improvement
> Components: API
> Affects Versions: 2.5
> Reporter: Remko Popma
> Assignee: Remko Popma
> Fix For: 2.7
>
> Attachments: DataStructOpsPerfMediumDataSet.png,
> DataStructOpsPerfSmallDataSet.png, InjectWithConfigProperties.png,
> InjectWithoutConfigProperties.png, ThreadContextPut.png
>
>
> The current ThreadContext map and stack implementations allocate temporary
> objects. This ticket is to investigate and track the work for alternative
> implementations that are garbage-free.
> Both DefaultThreadContextMap and DefaultThreadContextStack are copy-on-write
> data structures: each modification replaces the ThreadLocal object with a
> modified copy. The advantage of this approach is that there is no need to
> make a copy for each LogEvent.
> Also, DefaultThreadContextMap uses a JDK map, the JDK collections tend to
> allocate a lot of temporary objects.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
