talsma-ict / context-propagation

Propagate snapshots of ThreadLocal values to another thread
Apache License 2.0
18 stars 8 forks source link

Java 11 ServiceLoader and ForkJoinPool.commonPool() problem #94

Closed hanson76 closed 5 years ago

hanson76 commented 5 years ago

Expected Behavior

snapshot.reactivate() works from withing ForkJoinPool.commonPool() threads

Actual Behavior

snapshot.reactivate() throws exception: Context manager "com.wirelesscar.componentbase.RequestContextManager" not found in service loader! Cannot reactivate: com.....

Java 9 has introduced more class loaders. It now exists three class loaders. Bootstrap, Platform and System. https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/ClassLoader.html

ForkJoinPool.commonPool is created in a static block in ForkJoinPool with the Platform classloader, that Thread pool will have Platform as context class loader.

Spring boot has it's LaunchedURLClassLoader that inherits from System class loader.

The cache in PriorityServiceLoader is using Thread.currentThread().getContextClassLoader() to load classes. This is not working with currentThread == commonPool.

I've verified that it works if I change line 108 in PriorityServiceLoader to read final ClassLoader contextClassLoader = serviceType.getClassLoader();

I'm thinking of adding a check that does something similair to contextClassLoader = Thread.currentThread().getContextClassLoader(); if (contextClassLoader.getName().contains("Platform") { contextClassLoader = serviceType.getClassLoader(); }

My guess is that Jakarta EE etc still need to use the context class loader...

Steps to Reproduce the Problem

  1. Create spring application that uses ContextAwareCompletableFuture
  2. Compile and run it with java 11

Specifications

sjoerdtalsma commented 5 years ago

Thank you for reporting this! The context classloader for threads within the common ForkJoinPool indeed seems to be the Platform classloader. It is also correct that it probably will not know about your own context manager.

I'll have to think about a solution for this.

hanson76 commented 5 years ago

I've done some more investigation and it looks to me as the ForkJorkPool.makeCommonPool() is executed at different times in Java 8 and java 9+. In Java8 it's executed deep inside Spring when a CompletableFuture is used for the first time. In Java9+ (Testing with 11) it's created before my entrypoint. I'm not even able to get the debugger to stop at my breakpoint when running with 11.

I will dig some more. Not sure if it's just a startup difference that I can work around or if it is classloader changes that creates this behavior.

hanson76 commented 5 years ago

I've done some more digging around and managed to have the debugger stop in ForkJoin. It looks like Java 9+ has some changes done on how the class loaders work. I get the following result when stopping the application in PriorityServiceLoader and looking at the result of final ClassLoader contextClassLoader = Thread.currentThread().getContextClassLoader();

java 8: java -jar appl.jar: LaunchedURLClassLoader

spring-boot:run
    ClassLoaders$AppClassLoader

java 11: java -jar appl.jar: LaunchedURLClassLoader ClassLoaders$AppClassLoader

spring-boot:run
    ClassLoaders$AppClassLoader

The difference is the "ClassLoaders$AppClassLoader" in the "java11 -jar " example, that is the result when the call originate from the common ForkJoinPool. Trying to figure out why it does not happen in the java 8 example.

The ForkJoinPool class has been refactored in java 9+. The default ForkJoinWorkerThreadFactory that is created is different... Java 8 has static final class DefaultForkJoinWorkerThreadFactory implements ForkJoinWorkerThreadFactory { public final ForkJoinWorkerThread newThread(ForkJoinPool pool) { return new ForkJoinWorkerThread(pool); } }

while Java 11 has private static final class DefaultForkJoinWorkerThreadFactory implements ForkJoinWorkerThreadFactory { private static final AccessControlContext ACC = contextWithPermissions( new RuntimePermission("getClassLoader"), new RuntimePermission("setContextClassLoader"));

    public final ForkJoinWorkerThread newThread(ForkJoinPool pool) {
        return AccessController.doPrivileged(
            new PrivilegedAction<>() {
                public ForkJoinWorkerThread run() {
                    return new ForkJoinWorkerThread(
                        pool, ClassLoader.getSystemClassLoader()); }},
            ACC);
    }
}

The difference is that the ForkJoinWorkerThread gest the ClassLoader.getSystemClassLoader()) in Java 11!

hanson76 commented 5 years ago

I've also created an issuse for Spring Boot because I think that root cause might be the way Spring boot "shaded" jars work isn't supported in java11

https://github.com/spring-projects/spring-boot/issues/15737

sjoerdtalsma commented 5 years ago

Thank you for the investigation so far. :+1:

I will look into spring-boot and JDK11 combination as well, as I have not used that combination yet. Do you have a testproject (zip or github) I can use to reproduce this issue? If not, I'll create my own.

hanson76 commented 5 years ago

I've found a workaround but it is somewhat ugly. Have to add a custom ForkJoinWorkerThreadFactory returns a custom ForkJoinWorkerThread that sets the context class loader. I then have to use antrun maven plugin to inject that class to the jar file that spring boot maven plugin creates.

hanson76 commented 5 years ago

I've created a small test project showing the problem. can provide a working example later (probably early next week)

test-project.zip

sjoerdtalsma commented 5 years ago

I think a viable fix for this would be to still use the context classloader to lookup the ContextManager instances for the application (after all, you're propagating the context from the application thread).

The most simple solution I can think of is to keep a hard reference to the ContextManager in the snapshot. I don't think that would increase the risk of memory leaks, as you should not keep snapshots around for longer than propagation needs anyway.

Serialization of the snapshot may then become an issue, but that is probably a more niche use-case than being compatible with the standard fork-join threadpool!

sjoerdtalsma commented 5 years ago

@hanson76 Do you have a chance to test with the code in #95 (branch fix-94)?

hanson76 commented 5 years ago

It looks like the code in #95 works, I've built branch fix-94 locally and ran some test against it.

hanson76 commented 5 years ago

Ops, looks Like I spoke too soon. I've just encountered a case were a createSnapshot is done within a ForkJoinPool thread. I have a feeling that there is no easy fix and we have to live with the ugly workaround in Spring Boot where you inject your own ThreadPoolFactory.

16:45:40.889 [43 ] [I] [ ] [context.ContextManagers ] \| Context snapshot was created but no ContextManagers were found! Current thread: Thread[ForkJoinPool.commonPool-worker-3,5,main] nl.talsmasoftware.context.ContextManagers$NoContextManagersFound: Context snapshot was created but no ContextManagers were found! Current thread: Thread[ForkJoinPool.commonPool-worker-3,5,main] at nl.talsmasoftware.context.ContextManagers.createContextSnapshot(ContextManagers.java:100) ~[context-propagation-1.0.4-SNAPSHOT.jar!/:?] at nl.talsmasoftware.context.executors.ContextAwareExecutorService.map(ContextAwareExecutorService.java:52) ~[context-propagation-1.0.4-SNAPSHOT.jar!/:?] at nl.talsmasoftware.context.delegation.CallMappingExecutorService.wrap(CallMappingExecutorService.java:59) ~[context-propagation-1.0.4-SNAPSHOT.jar!/:?] at nl.talsmasoftware.context.delegation.CallMappingExecutorService.wrap(CallMappingExecutorService.java:75) ~[context-propagation-1.0.4-SNAPSHOT.jar!/:?] at nl.talsmasoftware.context.delegation.DelegatingExecutorService.execute(DelegatingExecutorService.java:152) ~[context-propagation-1.0.4-SNAPSHOT.jar!/:?] at java.util.concurrent.CompletableFuture$UniCompletion.claim(CompletableFuture.java:568) ~[?:?] at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:638) ~[?:?] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?] at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073) ~[?:?] at nl.talsmasoftware.context.futures.ContextAwareCompletableFuture.lambda$wrap$0(ContextAwareCompletableFuture.java:209) ~[context-propagation-java8-1.0.4-SNAPSHOT.jar!/:?] at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?] at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) ~[?:?] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?] at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1705) ~[?:?] at java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1692) ~[?:?] at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) ~[?:?] at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020) ~[?:?] at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656) ~[?:?] at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594) ~[?:?] at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177) ~[?:?]

hanson76 commented 5 years ago

Noticed that the zip file I uploaded was more or less empty! Here is a new one that is working. mvn package will create a jar file that uses default ForkJoinPoolThreadFactory mvn package -Pworkaround creates a jar file that uses a custom ForkJoinPoolThreadFactory

test-project.zip

sjoerdtalsma commented 5 years ago

Just out of curiosity, what is your use-case for taking a snapshot from inside the fork-join pool?

My guess is, the more common scenario would be the other way round; propagating a context into a background thread.

sjoerdtalsma commented 5 years ago

I think I'll merge #95 either way, but reopen this issue when it auto-closes so we can discuss further.

hanson76 commented 5 years ago

Just out of curiosity, what is your use-case for taking a snapshot from inside the fork-join pool?

My guess is, the more common scenario would be the other way round; propagating a context into a background thread.

I'm not entirely sure why it happens in this case. Our applications are async and nonblocking and it Might be that we have some code that is doing something strange, but it happens in more than one of our applications. I'll have to dig some more to figure it out. It might be a bug in our small framework ontop of Spring boot...

sjoerdtalsma commented 5 years ago

I'll have to dig some more to figure it out.

I just noticed that ContextAwareCompletableFuture.runAsync() (and supplyAsync) takes a new snapshot after the call within the call's context.
This is undocumented and in the bulk of the cases a wasted snapshot. In previous changes, the takeNewSnapshot functionality (to propagate threadlocal changes from one completion stage to the next) was made optional, but I forgot to update the runAsync and supplyAsync method variants.

sjoerdtalsma commented 5 years ago

The test project you provided no longer logs problems about empty snapshots or missing ContextManager implementations if I use the version from #96. Can you confirm?

I will not put effort into the corner-case of propagating context changes from one fork-join thread into another, I'd rather have current (predictable) behaviour where an initial caller's ContextSnapshot propagates accross all the completion stages of ContextAwareCompletableFuture by default.

Please let me know if you run into that situation though, maybe we can find a more elegant workaround by then...

hanson76 commented 5 years ago

Yes, #96 looks better. I still have the corner case but I think I know why. We have some code that sometimes starts a CompletableFuture chain with a new ContextAwareCompletableFuture() that will be completed from a different thread. But sometimes the same chain is started with CompletableFuture.completedFuture(value) .

It's when we use CompletableFuture.completedFuture() that we get the corner case.

My guess is that we somewhere manage to do a thenApplyAsync() with a ForkJoinPool that is not wrapped because we created a CompletableFuture instead of ContextAwareCompletableFuture at the start.

I might provide a pull request later today that adds the following static methods to ContextAwareCompletableFuture (those exists in CompletableFuture for Java 11)

static  ContextAwareCompletableFuturecompletedFuture​(U value) static  ContextAwareCompletionStagecompletedStage​(U value)

static  ContextAwareCompletableFuturefailedFuture​(Throwable ex) static  ContextAwareCompletionStagefailedStage​(Throwable ex)

sjoerdtalsma commented 5 years ago

Good to hear that it looks better. I will merge this and push out a new release (at the latest end of this week)

If you have more to share about your corner cases, please feel free to add a new issue.

Thank you very much @hanson76 for helping making this library better!

sjoerdtalsma commented 5 years ago

Version 1.0.4 is available in Maven Central.

Thanks again!