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-1349) Garbage-free ThreadContext map
Date Tue, 23 Aug 2016 15:08:22 GMT

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

Remko Popma edited comment on LOG4J2-1349 at 8/23/16 3:07 PM:
--------------------------------------------------------------

h1. Corrected & Additional Benchmarks

!v2_ThreadContextPut.png!
How long it takes to add a single key-value pair in a ThreadContext that already contains
5, 50 or 500 elements.

!v2_ThreadContextGet.png!
How long it takes to get a single key-value pair from a ThreadContext that contains 5, 50
or 500 elements.

!v2_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 a copy-on-write thread context we can use the current thread
context snapshot without any further modifications. This is very fast.

"Legacy" means the Log4jLogEvent::createMap implementation that is in current master (copy
from the ThreadContext's Map<String,String> to the LogEvent's Map<String,String>
context map).

"Default" means the ThreadContext uses a Map<String, String> but the LogEvent has a
ContextData field.

"CopyOpenHash" and "CopySortedArray" are copy-on-write ThreadContextMap implementations.

"NoGcOpenHash" and "NoGcSortedArray" are ThreadContextMap implementations that avoid creating
temporary objects.

!v2_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.

Here also, "Legacy" means the Log4jLogEvent::createMap implementation that is in current master
(copy from the ThreadContext's Map<String,String> to the LogEvent's Map<String,String>
context map), and "Default" means the ThreadContext uses a Map<String, String> but the
LogEvent has a ContextData field.

"CopyOpenHash" and "CopySortedArray" are copy-on-write ThreadContextMap implementations. "NoGcOpenHash"
and "NoGcSortedArray" are ThreadContextMap implementations that avoid creating temporary objects.

!v2_DataStructOpsPerfSmallDataSet.png!
Fixed benchmark to measure a single put and a single get operation against a data structure
containing 5 items.

!v2_DataStructOpsPerfMediumDataSet.png!
Fixed benchmark to measure a single put and a single get operation against a data structure
containing 500 items.

The performance of the "get" operation is important, but a common use case is also to iterate
over _all_ elements in the LogEvent's context data, so iteration performance is also noteworthy.

h3. Conclusion

If we agree to use ContextData in LogEvents (LOG4J2-1447, to allow non-String values in the
context data), then having a ThreadContextMap based on the same data structure gives significantly
better performance when putting values into the ThreadContext and when copying data into the
LogEvent. 

When it comes to using a copy-on-write ThreadContextMap or a garbage-free implementation,
the first consideration is whether the configuration declares <Property> values or not,
the second consideration is how often the application puts new key-value pairs in the ThreadContext.
We can make copy-on-write the default and provide an option for applications to configure
a garbage-free ThreadContextMap.

Finally, ArrayContextData vs OpenHashContextData: the hash-based data structure give slightly
better {{get}} performance, but the array-based structure gives _much_ better performance
when the configuration declares <Property> values, so overall I think ArrayContextData
is the better choice.


was (Author: remkop@yahoo.com):
*Corrected & Additional Benchmarks*

!v2_ThreadContextPut.png!
How long it takes to add a single key-value pair in a ThreadContext that already contains
5, 50 or 500 elements.

!v2_ThreadContextGet.png!
How long it takes to get a single key-value pair from a ThreadContext that contains 5, 50
or 500 elements.

!v2_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 a copy-on-write thread context we can use the current thread
context snapshot without any further modifications. This is very fast.

"Legacy" means the Log4jLogEvent::createMap implementation that is in current master (copy
from the ThreadContext's Map<String,String> to the LogEvent's Map<String,String>
context map).

"Default" means the ThreadContext uses a Map<String, String> but the LogEvent has a
ContextData field.

!v2_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.

Here also, "Legacy" means the Log4jLogEvent::createMap implementation that is in current master
(copy from the ThreadContext's Map<String,String> to the LogEvent's Map<String,String>
context map), and "Default" means the ThreadContext uses a Map<String, String> but the
LogEvent has a ContextData field.

!v2_DataStructOpsPerfSmallDataSet.png!
Fixed benchmark to measure a single put and a single get operation against a data structure
containing 5 items.

!v2_DataStructOpsPerfMediumDataSet.png!
Fixed benchmark to measure a single put and a single get operation against a data structure
containing 500 items.


> 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, v2_DataStructOpsPerfMediumDataSet.png,
v2_DataStructOpsPerfSmallDataSet.png, v2_InjectWithConfigProperties.png, v2_InjectWithoutConfigProperties.png,
v2_ThreadContextGet.png, v2_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: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message