revisiting MDC in slf4j broken because of CompletableFuture

Dean Hiller dhiller at twitter.com
Thu Mar 22 18:32:27 UTC 2018


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