spring-boot intellij-idea aspectj thread-local hibernate-filters

Threadlocal not working in Intellij within an Aspect

I have a multitenancy springboot (2.4.5) application - i store the tenantId in ThreadLocal storage. I have loadtime weaving enabled for the Hibernate filter.

Link to springboot and multitenancy

The flow, at a high level when a HTTP request comes in, is servletfilter->TenantFilterAspect( when the transaction starts) -> REST Api. The servletFiler sets the tenantId, which is accessed by the TenantFilterAspect, and then when the query is run in the REST api, hibernate applies the tenant filter.

If i run the application from the command line, everything works as expected. However if i run this from intellij (ultimate 2021.1), the threadlocal variable is null in the Aspect but correct in the REST API.

i.e i set it in the filter and immediately print the tenantId - it is correct - when printed in the aspect, it is incorrect, when printed in the REST API it is correct again.

public class JwtAuthTokenFilter extends OncePerRequestFilter {
    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
        try {
            /* Tenant ID hardcoded in the example */
               TenantContext.setCurrentTenant(2);
               SecurityContextHolder.getContext().setAuthentication(authentication);
            /* Print ThreadID and value of thread local here */
            /* thread local value is 2 */

            }
        } 
        filterChain.doFilter(request, response);
    }

@Aspect
public class TenantFilterAspect {

    @Pointcut("execution (* org.hibernate.internal.SessionFactoryImpl.SessionBuilderImpl.openSession(..))")
    public void openSession() {
    }

    @AfterReturning(pointcut = "openSession()", returning = "session")
    public void afterOpenSession(Object session) {
        if (session != null && Session.class.isInstance(session)) {
            Long currentTenant = TenantContext.getCurrentTenant(); 
            /* Thread ID is same as in the filter but thread local value is null */
            org.hibernate.Filter filter = ((Session) session).enableFilter("tenantFilter");
            filter.setParameter("tenantId", currentTenant);
        }
    }

}

/* @Transactional is at the class level - transaction is started before it gets here */ 
@PostMapping("/invoices/getPage")
public PagingDTO getInvoices(@RequestBody PagingDTO request) {
   Long currentTenant = TenantContext.getCurrentTenant();
   /* Thread ID is same as in the filter & aspect and thread local value is 2 */
   .....
}

public class TenantContext {
    private static ThreadLocal<Long> currentTenant = new InheritableThreadLocal<>();
    public static Long getCurrentTenant() {
        return currentTenant.get();
    }
    public static void setCurrentTenant(Long tenant) {
        currentTenant.set(tenant);
    }
}

The command line (with additional line feeds for readability) is

java
  -javaagent:/home/x/.m2/repository/org/aspectj/aspectjweaver/1.9.6/aspectjweaver-1.9.6.jar
  -jar target/webacc-0.0.1-SNAPSHOT.jar

In Intellij, the VM options has been set similarly

-javaagent:/home/x/.m2/repository/org/aspectj/aspectjweaver/1.9.6/aspectjweaver-1.9.6.jar

Any help on this strange behaviour will be deeply appreaciated - i am sort of clueless here. In both cases, the load time weaving appears correct (logging in the aspect is working), except that in the IntelliJ case, accessing the Threadlocal returns NULL in the aspect

Update 2

** I have added minimal code as requested to reproduce the issue at https://github.com/AnishJoseph/Threadlocal-Issue. Instructions are in the readme.

Update 3

Based on the superb analysis by kriegaex below i did some digging up on Spring classloading related to dev-tools.

Link to Spring's Customizing restart loader

Now, the fix is fairly straigtforward - i put the aspect code in a different module and excluded that jar from the reload. Now everything works perfectly.

Solution

I can reproduce the problem in IDEA. The reason seems to be the difference in how you start the application in both cases,

from an executable JAR (command line) vs.
from a classpath generated by the IDE as determined by Maven import.

If you compare the console logs in both cases, you see

in the former case that the ApsectJ weaver is registered exactly once on a LaunchedURLClassLoader, while
in the latter case it is registered 3x, first on an AppClassLoader, then RestartClassLoader, then MethodUtil.

I am not a Spring expert, so I do not know how Spring Boot fires up the application in the latter case, but I think that this difference in class-loading is the root cause of the problem. A workaround is to create a "JAR Application" type run configuration in IntelliJ IDEA and run the application that way. It behaves like from the console in that case, but of course you must make sure that the JAR is actually being built before starting it.

If I find out more, I will update the answer, but maybe this helps you a bit already.

Update: If you add System.out.println("### " + TenantContext.class.getClassLoader()); in all 3 places, you will see this console log for the executable JAR:

### org.springframework.boot.loader.LaunchedURLClassLoader@53e25b76
In Servlet Filter : Thread ID is 21  :: ThreadLocal Value is 10
### org.springframework.boot.loader.LaunchedURLClassLoader@53e25b76
In TenantFilterAspect :: Thread ID is 21  :: ThreadLocal Value is 10
### org.springframework.boot.loader.LaunchedURLClassLoader@53e25b76
In REST API :: Thread ID is 21  :: ThreadLocal Value is 10

When starting the application from the IDE, however, you will see:

### org.springframework.boot.devtools.restart.classloader.RestartClassLoader@1c5e93fb
In Servlet Filter : Thread ID is 36  :: ThreadLocal Value is 10
### sun.misc.Launcher$AppClassLoader@18b4aac2
In TenantFilterAspect :: Thread ID is 36  :: ThreadLocal Value is null
### org.springframework.boot.devtools.restart.classloader.RestartClassLoader@1c5e93fb
In REST API :: Thread ID is 36  :: ThreadLocal Value is 10

See? The TenantContext is loaded in two different classloaders, which means that there are two different thread-locals, which also explains why the one in the aspect is uninitialised.

Update 2: OK, I looked at the javadoc for RestartClassLoader and found this sentence:

Disposable ClassLoader used to support application restarting. Provides parent last loading for the specified URLs.

Parent last loading! This is not what we want, because it means that each child classloader will reload classes the parent already has loaded before, which explains the problem we saw above. In order to get the consistent behaviour you expect, simply deactivate this dependency in your POM:

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-devtools</artifactId>
  <scope>runtime</scope>
  <optional>true</optional>
</dependency>

This way you lose the ability to restart the application and dynamically refresh resources, but your tenant thingy works as expected. Please decide for yourself, which way you prefer. Maybe there is a way to configure the class-loading behaviour in a more fine-grained way, e.g. excluding TenantContext from parent-last loading. Not being a Spring user, I do not know.

By the way, you can also deactivate AspectJ Maven plugin, because the load-time weaver can finish the aspect while loading it, the compiler is not necessary for LTW, if you are not using native AspectJ syntax. The old plugin version you are using limits you to JDK 8. If you just remove it, you can also build your application with JDK 9+, e.g. JDK 16. I tested it, it works flawlessly.