[jira] [Commented] (LOG4J2-2671) Improve the performance of adding and removing multiple values from the ThreadContext

["Luke Butters (Jira)" <ji...@apache.org>]

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

Luke Butters commented on LOG4J2-2671:
--------------------------------------

Hi, is silence indicative of something?

This is still a pain.

> Improve the performance of adding and removing multiple values from the ThreadContext
> -------------------------------------------------------------------------------------
>
>                 Key: LOG4J2-2671
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-2671
>             Project: Log4j 2
>          Issue Type: Improvement
>            Reporter: Luke Butters
>            Priority: Major
>         Attachments: Screenshot_20190810_090546.png, Screenshot_20190810_090710.png
>
>
> I notice in profiling that a bunch of time is spent under ThreadContext specifically in DefaultThreadContextMap.
> What my code does is put a few things into the map e.g.
> {code:java}
> ThreadContext.put("a", "b");{code}
> This actually results in [DefaultThreadContextMap|https://github.com/apache/logging-log4j2/blob/master/log4j-api/src/main/java/org/apache/logging/log4j/spi/DefaultThreadContextMap.java#L83] creating a copy of the existing map, updating that copy and setting it back. So if I want to set 5 things we end up copying the map 4 times.
>  This also happens when calling:
> {code:java}
> ThreadContext.remove("a");{code}
> What could be done instead is for {{ThreadContext}} to take multiple values similar to the existing {{putAll}} available on {{Map}} that way I can pass in all values at once avoiding making (n -1) copies of the Map. It might make sense for this method to take a {{Collection}} of {{Map.Entry}} as that way the caller doesn't need to construct a Map and can instead construct a cheaper list of Entries to be added to the map.
> some sample code of how this would look:
> {code:java}
>     public void putAll(Collection<Map.Entry<String, String>> toAdd) {
>         if (!useMap) {
>             return;
>         }
>         Map<String, String> map = localMap.get();
>         map = map == null ? new HashMap<String, String>() : new HashMap<>(map);
>         for(Map.Entry<String, String> e : toAdd) {
>             map.put(e.getKey(), e.getValue());
>         }
>         localMap.set(Collections.unmodifiableMap(map));
>     }{code}
> The remove method should also be improved to take a List entries that way we can avoid making multiple copies of the map an example of how this might look:
> {code:java}
>     public void remove(final Collection<String> keys) {
>         final Map<String, String> map = localMap.get();
>         if (map != null) {
>             final Map<String, String> copy = new HashMap<>(map);
>             for(String key : keys) {
>                 copy.remove(key);
>             }
>             localMap.set(Collections.unmodifiableMap(copy));
>         }
>     }{code}
>  
> Running a test which attempts to add 5 values and then remove those 5 values 1 million times, repeated ten times. I then averaged the results of how long that took for all ten results to come up with:
>  *current:* 1093ms
> *new:* 310ms
> Here are the visualvm profiling results of what log4j currently has:
> Adding:
> !Screenshot_20190810_090710.png!
> Removal:
> !Screenshot_20190810_090546.png!



--
This message was sent by Atlassian Jira
(v8.3.4#803005)