revisiting MDC in slf4j broken because of CompletableFuture

Ralph Goers ralph.goers at dslextreme.com
Thu Mar 22 18:27:07 UTC 2018 

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 <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 <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 <mailto: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 <mailto: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 <mailto: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 <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 <mailto: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 <http://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 <mailto: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 <mailto: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 <mailto: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 <http://altair.cs.oswego.edu/mailman/listinfo/concurrency-interest>
> >>>>>
> >>>>>> On 18 May 2017, at 21:57, Dean Hiller <dhiller at twitter.com <mailto:dhiller at twitter.com>> wrote:
> >>>>>>
> >>>>>> Way more detail here...
> >>>>>>
> >>>>>> http://stackoverflow.com/questions/37933713/does-completable <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 <mailto:Concurrency-interest at cs.oswego.edu>
> >>>> http://cs.oswego.edu/mailman/listinfo/concurrency-interest <http://cs.oswego.edu/mailman/listinfo/concurrency-interest>
> >>>>
> >>>>
> >>>>
> >>>
> >>
> >
> >
> >
> 
> 
>

More information about the core-libs-dev mailing list