[play-2.5.x-java] MDC Propagation for full request throws [java.lang.SecurityException]

[Joo Joo]

I am trying to use MDC propagation for my Restful Play App so that we can use logs for tracing and audit logging

I am trying to take some leads from 

https://www.playframework.com/documentation/2.5.x/ThreadPools#Java-thread-locals

and

http://yanns.github.io/blog/2014/05/04/slf4j-mapped-diagnostic-context-mdc-with-play-framework/

RequestLoggingFilter.java

package filters;


import akka.stream.Materializer;
import com.google.common.collect.ImmutableBiMap;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import play.Configuration;
import play.libs.concurrent.HttpExecutionContext;
import play.mvc.Filter;
import play.mvc.Http;
import play.mvc.Result;

import javax.inject.Inject;
import javax.inject.Singleton;
import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.CompletionStage;
import java.util.function.Function;

/**
 * Filter to log Entry / Exits for Controller actions.
 * Here we can play around with request object and extract values and log them.
 * Created by shahb on 6/15/16.
 */
@Singleton
public class RequestLoggingFilter extends Filter {
    private static Logger LOGGER     = LoggerFactory.getLogger("http.requests");
    static         String TRACE_INFO = "http_method={} api_path={}";

    static String XTRA_LOG_INFO = "http_method={} api_path={} time_taken={} http_status={}";


    @Inject Configuration config;

    HttpExecutionContext ec;
    MdcContextExecutor   delegate;

    @Inject
    public RequestLoggingFilter(Materializer mat) {
        super(mat);
        delegate = new MdcContextExecutor();
        ec = new HttpExecutionContext(delegate);
    }

    @Override
    public CompletionStage<Result> apply(Function<Http.RequestHeader, CompletionStage<Result>> nextFilter,
                                         Http.RequestHeader requestHeader) {
        long startTime = System.currentTimeMillis();
        LOGGER.info("Logging in Filter.. !! Before MDC Setup ");

        Map<String, String> copyOfContextMap = MDC.getCopyOfContextMap();
        if(copyOfContextMap==null)
            copyOfContextMap = new HashMap<String,String>();
        String traceInfo = StringUtils.replaceEach(TRACE_INFO, new String[]{"{}", "{}"}, new String[]{requestHeader.method(), requestHeader.uri()});

        copyOfContextMap.put("traceinfo", traceInfo);

        delegate.setMdcContext(copyOfContextMap);

        LOGGER.info("Logging in Filter.. !! After MDC Setup ");

        return nextFilter.apply(requestHeader).thenApplyAsync(result -> {
            long endTime     = System.currentTimeMillis();
            long requestTime = endTime - startTime;
            return result.withHeader("Request-Time", "" + requestTime);
        }, ec.current());
    }
}

MdcContextExecutor.java

package filters;

import org.slf4j.MDC;

import java.util.Map;
import java.util.concurrent.Executor;

/**
 * Created by shahb on 7/15/16.
 */
public class MdcContextExecutor implements Executor {

    @Override
    public void execute(Runnable command) {
        Map<String, String> oldMdcContext = MDC.getCopyOfContextMap();
        try {
            command.run();
        }finally {
           //setMdcContext(oldMdcContext);
        }
        System.out.println("Test");
    }

    public void setMdcContext(Map<String, String> aContext){
        if(aContext==null){
            MDC.clear();
        }
        else{
            MDC.setContextMap(aContext);
        }
    }
}

Thrown exception

java.util.concurrent.CompletionException: java.lang.SecurityException: setContextClassLoader

        at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:273)

        at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:280)

        at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:604)

        at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)

        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)

        at java.util.concurrent.CompletableFuture.postFire(CompletableFuture.java:561)

        at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:580)

        at java.util.concurrent.CompletableFuture$Completion.exec(CompletableFuture.java:443)

        at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)

        at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)

Caused by: java.lang.SecurityException: setContextClassLoader

        at java.util.concurrent.ForkJoinWorkerThread$InnocuousForkJoinWorkerThread.setContextClassLoader(ForkJoinWorkerThread.java:244)

        at play.core.j.HttpExecutionContext$$anon$2.run(HttpExecutionContext.scala:53)

        at filters.MdcContextExecutor.execute(MdcContextExecutor.java:17)

        at scala.concurrent.impl.ExecutionContextImpl.execute(ExecutionContextImpl.scala:109)

        at play.core.j.HttpExecutionContext.execute(HttpExecutionContext.scala:48)

        at java.util.concurrent.CompletableFuture$UniCompletion.claim(CompletableFuture.java:529)

        at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:599)

        at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)

        at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)

        at java.util.concurrent.CompletableFuture.postFire(CompletableFuture.java:561)

Not sure what is going on.

Does anybody have a successful implementation MDC Logging Filter with new Play Framework 2.5.x ?