revisiting MDC in slf4j broken because of CompletableFuture

[Ralph Goers]

Log4j 2 supports a ThreadContext which is analogous to the SLF4J MDC. Both are based on ThreadLocal variables. If I understand what you are saying, the problem is that ThreadLocals do not work as you you would expect when using CompleteableFutures?

Ralph

> On Mar 22, 2018, at 7:05 AM, Dean Hiller <dhiller at twitter.com> wrote:
> 
> slf4j is pretty much the defacto logging standard these days allowing one
> to bring in libraries using any logging framework.  (commons logging fell
> short and had classloading bugs).
> 
> Summary: MDC works fine in twitter scala Futures but not java
> CompletableFutures.
> 
> Unfortunately, one of the best features(brought over from log4j which is
> also broken now) is the MDC. The MDC no longer works with
> CompletableFutures so people will have to move to scala where it does work.
> 
> Documentation on MDC if you don't know what that is....
> https://logback.qos.ch/manual/mdc.html
> 
> or for a more concrete example, as a developer a request comes in and you
> set MDC.put("requestId", requestId) and now whenever you log, that request
> id is added to your log line.  No developer has to 'remember' to add it
> every time he adds a log statement.
> 
> This is due to the lack of Local.java file that should exist and transfer
> context over the .thenApply/.thenCompose methods like twitter Futures has
> in scala land. (see Local.scala in twitter Futures and the twitter Future
> code for how this works)
> 
> In scala, it works and we have all the same methods as CompletableFuture
> for the most part and yes, we can't transfer the context over some methods,
> but at least our MDC in scala servers is not broken.
> 
> Lack of this feature is forcing our hand to code in scala where it is not
> broken.  ie. we need logging and we definitely need the request id or
> client id or whatever attached automatically to every log(as humans have
> trouble remembering to add it themselves every single time).
> 
> thanks for reconsidering,
> Dean
> 
> On Tue, May 23, 2017 at 10:20 AM, Dean Hiller <dhiller at twitter.com> wrote:
> 
>> All, this post is all about 3rd party code that I do not control so
>> therefore the solutions above do not work as those libraries may predate my
>> library.  more specifically.....
>> 
>> Martin,
>>   If I roll my own slf4j MDC only works in my code and stops working in
>> 3rd party code!  because the 3rd party code does not transfer the context.
>> 
>> Viktor,
>>  You hit the head on the nail with "It's easy to lose context when
>> intermediate libraries/Executors".  This is solved on twitter futures until
>> we hit libraries not using twitter futures because no matter the executor,
>> the future transfers the context for us the way it was written.
>> 
>>   "It's unclear what fan-in behaviors like zip, merge etc mean in terms
>> of what the local values should be?"
>> This is a very good question.  I wonder what twitter futures do here.  I
>> would be ok with dropping the context in this case or combining it.  I do
>> not really care yet here since I have not run into it but it is a very good
>> question and would need a lot of thought
>> 
>> Josh,
>>   I cannot expect all 3rd party libraries that are brought in will be
>> using ContextPropagatingExecutor so that solution breaks down as Viktor
>> eludes to.
>> 
>> Alex,
>>   tuples do not solve the issue.  in fact twitter futures have a
>> Local.scala file that does solve the issue.  The main issue is 3rd party
>> code and having the context continue into "unknown code" using
>> CompletableFuture.  I cannot control that code BUT want every log.info in
>> that code to use and log the request id.  it is awesome at twitter as I can
>> just follow that request id in the logs.  If CompletableFuture had such a
>> context, I could transfer this info into it and into the 3rd party java
>> libraries.
>> 
>> I am writing a webserver for fun based on CompletableFutures and therefore
>> cannot control the controllers as the app developer writes that and the
>> request id stops getting logged on the request path which is mostly
>> .thenApply and .thenCompose.  even if the Controllers do you my future,
>> they will bring in libraries NOT using my future :(
>> 
>> thanks
>> Dean
>> 
>> 
>> 
>> 
>> 
>> On Tue, May 23, 2017 at 3:12 AM, Alex Otenko <oleksandr.otenko at gmail.com>
>> wrote:
>> 
>>> Why would someone want to rely on state they cannot control?
>>> 
>>> Is the idea to subvert some API that does not provide a way to pass
>>> state? This is strange especially in the context of Scala, where you can
>>> easily form tuples.
>>> 
>>> Alex
>>> 
>>> On 22 May 2017, at 20:44, Martin Buchholz <martinrb at google.com> wrote:
>>> 
>>> There's not likely to be any support for local context anywhere in
>>> java.util.concurrent, but it seems not too hard to roll your own support
>>> with a custom executor to be used with CompletableFuture that kept track of
>>> any local context.
>>> 
>>> On Fri, May 19, 2017 at 1:16 PM, Pavel Rappo <pavel.rappo at oracle.com>
>>> wrote:
>>> 
>>>> General questions on concurrency in Java should be asked here:
>>>> 
>>>>   http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest
>>>> 
>>>>> On 18 May 2017, at 21:57, Dean Hiller <dhiller at twitter.com> wrote:
>>>>> 
>>>>> Way more detail here...
>>>>> 
>>>>> http://stackoverflow.com/questions/37933713/does-completable
>>>> future-have-a-corresponding-local-context
>>>>> 
>>>>> So I was wondering if this was going to be added at some point to the
>>>> jdk
>>>>> as I could not figure out how to set something so it was still
>>>> available on
>>>>> the thread at a later time when traversing async thenCompose,
>>>> thenAccept.
>>>>> 
>>>>> thanks,
>>>>> Dean
>>>> 
>>>> 
>>> _______________________________________________
>>> Concurrency-interest mailing list
>>> Concurrency-interest at cs.oswego.edu
>>> http://cs.oswego.edu/mailman/listinfo/concurrency-interest
>>> 
>>> 
>>> 
>> 
>