Pass context to async Logger

Asked 14/11, 2016 at 11:56 Answered 18/9, 2020 at 14:12

java log4j2 apache-httpasyncclient threadcontext

I am trying to log raw request/response from a http client. I am following log4j2 configurations from these logging instructions.

HttpAsync Client Dependency :- httpasyncclient (version 4.1.1)

log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
<Appenders>
    <RollingRandomAccessFile name="app-log" fileName="${log.path}/app.log"
                             filePattern="${log.path}/app-%d{yyyy-MM-dd}.gz">
        <PatternLayout>
            <pattern>[%-5level] [%X{uuid}] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n</pattern>
        </PatternLayout>
        <Policies>
            <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
        </Policies>
    </RollingRandomAccessFile>
</Appenders>
<Loggers>
    <AsyncLogger name="org.apache.http.impl.conn.Wire" level="debug">
        <AppenderRef ref="app-log"/>
    </AsyncLogger>
    <AsyncRoot level="debug" includeLocation="true">
        <AppenderRef ref="app-log"/>
    </AsyncRoot>
</Loggers>
</Configuration>

It is printing fine but the threadcontext is not passing onto the wire logger.

Example :-

// with uuid, output of logger.debug(ThreadContext.getImmutableContext().toString());

[DEBUG] [c48b97f7-0094-44af-82af-3d6b43d76014] 2016-11-14 17:06:03.408 [http-bio-8080-exec-1] OutboundRequestHandler - {uuid=c48b97f7-0094-44af-82af-3d6b43d76014}

// without uuid
[DEBUG] [] 2016-11-14 17:06:03.440 [I/O dispatcher 1] headers - http-outgoing-0 >> POST /abcd.json HTTP/1.1
[DEBUG] [] 2016-11-14 17:06:03.441 [I/O dispatcher 1] headers - http-outgoing-0 >> Content-Length: 2
[DEBUG] [] 2016-11-14 17:06:03.441 [I/O dispatcher 1] headers - http-outgoing-0 >> Content-Type: text/plain; charset=ISO-8859-1
[DEBUG] [] 2016-11-14 17:06:03.441 [I/O dispatcher 1] headers - http-outgoing-0 >> Host: 127.0.0.1:80
[DEBUG] [] 2016-11-14 17:06:03.441 [I/O dispatcher 1] headers - http-outgoing-0 >> Connection: Keep-Alive
[DEBUG] [] 2016-11-14 17:06:03.441 [I/O dispatcher 1] headers - http-outgoing-0 >> User-Agent: Apache-HttpAsyncClient/4.1.1 (Java/1.8.0_92)

How can I pass the ThreadContext to the logger?

Thanks.

Nahum answered 14/11, 2016 at 11:56 Comment(0)

Since the thread where the UUID was set (http-bio-8080-exec-1) is different from the thread in your application that is doing the logging (I/O dispatcher 1), they have different ThreadContext maps and the 2nd thread cannot see what the 1st thread put in its map.

Since log4j 2.7 it is possible to create a custom context data injector that can get context data from other places than from a ThreadLocal map (because that is essentially what the ThreadContext is).

That does mean that you need to create a custom facade, similar to log4j's ThreadContext, where you put key-value pairs into some data structure. I am not familiar with AsyncHttpClient but I could not find a "context" concept that allows separate threads to share data associated with the same session.

Your custom context injector implementation would take a snapshot of the key-value pairs and inject that into the LogEvent for each log message.

Underwent answered 14/11, 2016 at 14:41 Comment(1)

How will, one define the scope of key or value. For example, http-bio-8080-exec-1 thread at incoming request interception will create uuid and add to MDC, also will clear in filter before writing response. Now all thread that are executing task submitted by this thread (aync model) should log uuid in logger. How will custom data injector helps here.(More generic use case for above scenario) not for any other scenario task. – Nathanielnathanil 14/11, 2016 at 15:5

I am not sure how relevant this is in 2019 as the asker will have surely moved on to other things. But still here it goes:

In log4j2 we have to use ThreadContext.put instead of MDC.put which is used for log4j. This will log everything perfectly. Rest everything remains same

Cashier answered 29/3, 2019 at 11:35 Comment(2)

I think the OP was aware of the difference between log4j 1.2 and log4j 2, given that the configuration uses log4j 2 syntax and the title mentions Async Loggers. The question was about the advanced use case of how to pass ThreadContext information to worker threads... – Underwent 31/3, 2019 at 8:51

I just implemented this and works fine for me using threadContext.put. – Cashier 31/3, 2019 at 12:24

As of v2.13.2 it is recommended to create a ContextDataProvider instead of a ContextDataInjector.

The ContextDataProvider (introduced in Log4j 2.13.2) is an interface applications and libraries can use to inject additional key-value pairs into the LogEvent's context data. Log4j's ThreadContextDataInjector uses java.util.ServiceLoader to locate and load ContextDataProvider instances. Log4j itself adds the ThreadContextData to the LogEvent using org.apache.logging.log4j.core.impl.ThreadContextDataProvider. Custom implementations should implement the org.apache.logging.log4j.core.util.ContextDataProvider interface and declare it as a service by defining the implmentation class in a file named META-INF/services/org.apache.logging.log4j.core.util.ContextDataProvider.

Deal answered 18/9, 2020 at 14:12 Comment(0)

Recommended topics

Hot tags