[
https://issues.apache.org/jira/browse/LOG4J2-2990?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Diogo Monteiro closed LOG4J2-2990.
----------------------------------
> Make use of ThreadContext.putAll on SLF4j MDCAdapter
> ----------------------------------------------------
>
> Key: LOG4J2-2990
> URL: https://issues.apache.org/jira/browse/LOG4J2-2990
> Project: Log4j 2
> Issue Type: Improvement
> Components: SLF4J Bridge
> Affects Versions: 3.0.0, 2.14.0
> Reporter: Diogo Monteiro
> Priority: Minor
> Fix For: 2.14.1
>
>
> Hi all.
> I maintain a service that makes use of log4j2 with the SLF4j API, and, while
> load testing it, I noticed some GC pressure. Taking a closer look I could
> understand that one of the most allocated objects were maps (and their
> corresponding {{EntrySets}} and {{Entry}}), coming from the MDC
> implementation.
> We make extensive use of Kotlin and the coroutines mechanism that the
> language provides. What happens is that a coroutine can suspend its execution
> to wait for a result, freeing the underlying thread to another coroutine. If
> we want to keep a MDC context that is coroutine-local (instead of thread
> local), the coroutines implementation call {{MDC.setContextMap}} and
> {{MDC.getContextMap}} on each suspension (and wake). So, in pseudo-code
> example:
> {code:java}
> suspend onHandleRequest(request) {
> MDC.setContextMap(<initial context>)
> dbResponseAsync = async { callDatabase() }
> service1ResponseAsync = async { callService1() }
> dbResponse = dbResponseAsync.await()
> service1Response = service1ResponseAsync.await()
>
> (do something with both responses and log something here)
> }
> {code}
> The coroutine that executes {{onHandleRequest}} will suspend (and awake) two
> times in the {{await()}} function. This will call {{MDC.setContextMap}} three
> times for the same request: 1 time at the beginning, 1 time for each
> {{await()}}.
> I noticed that in the [Log4jMDCAdapter
> implementation|https://github.com/apache/logging-log4j2/blob/master/log4j-slf4j-impl/src/main/java/org/apache/logging/slf4j/Log4jMDCAdapter.java#L58],
>
> [ThreadContext.put|https://github.com/apache/logging-log4j2/blob/d9e01a981b860aeb8834eac3eed201c686884b7a/log4j-api/src/main/java/org/apache/logging/log4j/ThreadContext.java#L244]
> is called for each entry of the map, creating {{N}} unmodifiable copies of
> the context map for each entry.
> I think it's possible to just call {{ThreadContext.putAll}}, which internally
> creates only a single copy for all entries. Something like:
> {code:java}
> // Some comments here
> @Override
> @SuppressWarnings("unchecked") // nothing we can do about this,
> restricted by SLF4J API
> public void setContextMap(@SuppressWarnings("rawtypes") final Map map) {
> ThreadContext.clearMap();
> ThreadContext.putAll((Map<String, String>) map);
> }
> {code}
> In our use case this greatly reduces memory footprint and GC pressure, and
> reduces the time to call {{MDC.setContextMap}} to roughly half.
> What do you think? Do you see any drawback?
> Happy to create a PR for this in case you agree with this change.
> Thank you.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
