revisiting MDC in slf4j broken because of CompletableFuture

Dean Hiller dhiller at twitter.com
Thu Mar 22 18:43:30 UTC 2018 

sure, I 100% agree. ("it should be general enough that it can be used for
more than just CompleteableFuture").  yes, I could see someone doing a
executorService.run() and it transferring that context as well....that
would be kind of really nice actually!!!

and you do have to swap out the logback MDC impl with your own(we did at
twitter), and then it works like a charm.  ie. we only need jdk work since
logback let's you swap the MDC.

Dean


On Thu, Mar 22, 2018 at 12:38 PM, Ralph Goers <ralph.goers at dslextreme.com>
wrote:

> To be clear, SLF4J only provides an MDC API and doesn’t implement the MDC.
> It delegates that to an implementation - Log4j 2 or Logback. Obviously, my
> concern would be to get Log4j 2 to work the way it needs to. If it requires
> additional help from the JDK library then there is only so much I can do.
> But if work is being asked of the JDK then, IMO, it should be general
> enough that it can be used for more than just CompleteableFuture.
>
> Ralph
>
>
> On Mar 22, 2018, at 11:32 AM, Dean Hiller <dhiller at twitter.com> wrote:
>
> oh, I see
>
> yes, that code could be done in CompletableFuture though...Executor does
> not have to be touched based on the scala code I read.  ie. you create a
> new Runnable that reads the last Local context transferring into a
> ThreadLocal until the next transfer is needed(at each
> .thenApply/.thenCompose boundaries).
>
> There are weird methods and I would just not worry about those except as
> it relates mostly to getting slf4j's MDC to work.
>
> On Thu, Mar 22, 2018 at 12:27 PM, Ralph Goers <ralph.goers at dslextreme.com>
> wrote:
>
>> My point is that I don’t think this is the only place the problem occurs.
>> I have seen similar questions on the Log4j mailing list where users want to
>> be able to do this for thread pools they create via Executors and don’t
>> want to have to do the ThreadLocal propagation themselves. If a
>> CompleteableFuture uses an Executor under the covers then it could leverage
>> the same solution.
>>
>> Ralph
>>
>>
>> On Mar 22, 2018, at 11:21 AM, Dean Hiller <dhiller at twitter.com> wrote:
>>
>> I am basically asking for someone to copy the solution in twitter
>> Future.scala(which uses Local.scala) into CompletableFuture.java, yes.
>>
>> ie. I should be able to say Local.set("something", value) and in
>> CompletableFuture when .map is called, it will ensure the key/values are
>> transferred across threads.  Local.scala internally uses a ThreadLocal up
>> into the point of .map/.flatMap (ie. thenApply/.thenCompose).  At that
>> point, it transfers it across threads into a new ThreadLocal.
>>
>> ie. the answer on how to do it exists here(search on Locals and see it in
>> the respond method which is called by map and flatMap)..
>>
>> https://github.com/simonratner/twitter-util/blob/master/
>> util-core/src/main/scala/com/twitter/util/Future.scala
>>
>> Here is the Local class that clients use and the Future uses to transfer
>> contexts across map/flatMap
>> https://github.com/simonratner/twitter-util/blob/master/
>> util-core/src/main/scala/com/twitter/util/Local.scala
>>
>> (I do apologize if you do not read scala code, but the answer is there
>> and just in a different language)
>>
>> later,
>> Dean
>>
>>
>> On Thu, Mar 22, 2018 at 11:40 AM, Ralph Goers <ralph.goers at dslextreme.com
>> > wrote:
>>
>>> Having read several of the threads I think I have a better understanding
>>> of the problem. This sounds similar to problems that occur with any
>>> application that has a way of doing asynchronous processing with with
>>> thread pools. Java has unfortunately not provided a good way that I know of
>>> to pass a ThreadLocal from one thread to a worker thread. I am guessing
>>> that is what you are really asking for is some sort of property on the
>>> Executor that tells it to pass the ThreadLocals from one thread to the
>>> worker that performs action on its behalf.
>>>
>>> Ralph
>>>
>>> > On Mar 22, 2018, at 10:13 AM, Ralph Goers <ralph.goers at dslextreme.com>
>>> wrote:
>>> >
>>> > 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
>>> >>>>
>>> >>>>
>>> >>>>
>>> >>>
>>> >>
>>> >
>>> >
>>> >
>>>
>>>
>>>
>>
>>
>
>

More information about the core-libs-dev mailing list