We have a MongoDB class that extends an abstract class and implements an interface which looks like this (concrete class names have been changed to be a generic "foo" to avoid unnecessary internal detail and instead show the code structure):


public abstract class AbstractMongoDAO<T> {
    ...
}

public interface IFooDAO {
    ...
    public void delete(Foo foo);
    ...
}

public class FooDAO extends AbstractMongoDAO<Foo> implements IFooDAO {
    @Override
    @Caching(evict = {
            @CacheEvict(cacheNames = SOME_CACHE_NAME, key = "#foo.bar"),
    })
    public void delete(Foo foo) { }
}

Although in this case I think the @Override is actually unnecessary since delete() does not exist in AbstractMongoDAO. We inherited this legacy code from another team previously so the code is not as perfect as it ought to be.

Sometimes on our integration and staging environments we are getting a SpelEvaluationException saying Property or field 'bar' cannot be found on null after calling the delete() method in FooDAO. The stack trace occurs in the cache eviction and SPeL evaluation code. We have confirmed that the parameter is not actually null by logging its value.

The confusing part is the following:

  • This sort of issue should have been fixed by #32087 / 6.1.4. We are on 6.1.13 so it seems like this shouldn't even be happening.
  • I can't reproduce locally, but it definitely occurs on our integration and staging servers, so I can't provide a minimal repro case that will reliably fail. I tried running the app in -server and everything else I could to trigger this and was unable to, but we saw repeated errors remotely when running this code. I ran the app locally via a Gradle bootRun task, and we also have integration tests that build the app and run it in a Docker container which is how it runs in production. Those tests cover this method. All those tests pass without any failures (they are not glitchy).

Is there a better way for me to try to reproduce this? Could there be a lingering issue with spring-aop that occurs when you both extend an abstract class and inherit an interface? Could an unnecessary @Override throw things off? As a workaround, we replaced "#foo.bar" with "#p0.bar" in the cache eviction annotation.

Comment From: simonbasle

Could it be that the jar deployed in production hasn't been compiled with parameter name retention? See https://github.com/spring-projects/spring-framework/wiki/Spring-Framework-6.1-Release-Notes#parameter-name-retention

Comment From: sbrannen

As a workaround, we replaced "#foo.bar" with "#p0.bar" in the cache eviction annotation.

Before I read through the entire description of the issue, that is exactly what I was going to ask you to try.

Since "#p0.bar" works but "#foo.bar" does not, that means that org.springframework.context.expression.MethodBasedEvaluationContext.lazyLoadArguments() could not discover the foo parameter name.

In light of that and the previous comment from @simonbasle (https://github.com/spring-projects/spring-framework/issues/33852#issuecomment-2461766548), I am closing this issue.

In any case, please do let us know if compiling with the -parameters flag resolves your issue.

Thanks

Comment From: warrenhenning-p44

Sorry for not mentioning that earlier. Yeah, we did add -parameters to our Gradle script like so:

allprojects {
    compileJava {
        options.compilerArgs << '-parameters'
    }
}

I ran a gradle build in debug mode and confirmed that -parameters was being passed to javac.

Comment From: warrenhenning-p44

Despite the fact that I did add -parameters and did see it being passed into the build, would improper application of -parameters explain why we can't reproduce locally? Would running the app in a development profile locally have debug symbols that get stripped away when it's running on our servers? I tried running the app as a JAR in -server mode on my laptop to try to explore this possibility and still couldn't reproduce.

What I don't get is this code worked locally and in CI before I added -parameters.

Comment From: bclozel

@warrenhenning-p44 it seems this is more of an infrastructure problem than a Spring problem at this point. Debug symbols are built in the bytecode at compilation time. If the project runs properly locally with the same JAR being run in production, then the problem is elsewhere. If your application is applying the Spring Boot Gradle plugin, that parameters compiler option was already enforced.

Comment From: warrenhenning-p44

@bclozel Thank you for the feedback. Do you have any suggestions on how to debug the infrastructure issue behind this? E.g., are there any metrics I should check, anything in our staging environment to check, etc?

Comment From: bclozel

I guess the first step is to ensure that the JAR being run in production contains debug information. Running javap on compiled classes should show you whether the bytecode contains the parameters information. I can't think of anything else, especially if you can't reproduce it in another environment.

Comment From: warrenhenning-p44

@bclozel I would like to follow up on this a bit. I pulled down a Docker image that we run in Kubernetes in our production environments from Artifactory and made an ad-hoc custom Dockerfile so that I could actually run javap in the Docker container (our normal containers don't have much in them besides what is needed to run the service). Artifactory is our source of artifacts that we deploy to production, so this should be the exact same images with the exact same JARs running on our services. I had some trouble getting javap to work with the JAR as a classpath so I just extracted out the JAR, like so:

FROM <company>.jfrog.io/<company>-docker-local/<company>/foo-service:v3.3.2
USER root
RUN apt-get update && apt-get install -y openjdk-17-jdk openjdk-17-jre
RUN jar -xf app.jar
USER <regular username>

... <some irrelevant details about keeping the same entrypoint command, exposed ports, etc. are here but are omitted for clarity> ...

Then I docker exec -it'd into the container and ran javap -v against the class file in question. Changing internal model and parameter names to "foo" as I did above, the output looks like:

  public void deleteFoo(com.foocorp.foo.model.Foo);
    descriptor: (Lcom/foocorp/foo/model/Foo;)V
    flags: (0x0001) ACC_PUBLIC
    Code:
      stack=2, locals=2, args_size=2
         ... <irrelevant bytecode dump omitted> ...
      LineNumberTable:
        line 184: 0
        line 185: 7
        line 186: 15
      LocalVariableTable:
        Start  Length  Slot  Name   Signature
            0      16     0  this   Lcom/foocorp/foo/dao/mongo/FooDAO;
            0      16     1 foo   Lcom/foocorp/foo/model/Foo;
    MethodParameters:
      Name                           Flags
      foo
    RuntimeVisibleAnnotations:
      0: #393(#394=[@#395(#350=[s#380],#396=Z#389),@#395(#350=[s#351],#398=s#405),@#395(#350=[s#357],#398=s#406),@#395(#350=[s#400],#398=s#406),@#395(#350=[s#402],#398=s#407)])
        org.springframework.cache.annotation.Caching(
          evict=[@org.springframework.cache.annotation.CacheEvict(
            cacheNames=["AllFoos"]
            allEntries=true
          ),@org.springframework.cache.annotation.CacheEvict(
            cacheNames=["FooById"]
            key="#p0.foo"
          ),
          ... <additional cache eviction entries omitted since they are similar in format to to the above, just with different caches> ...
        )

I think the important part is that MethodParameters does indeed contain the parameter name of foo. Since this is based on the exact docker image we run on all our servers, this should be the exact JAR that is running. This version does have the p0 workaround mentioned above that we settled on but the MethodParameters table is the same even if you change the key string value to directly reference foo by name.

I believe this suffices to conclude that the JAR run in production does contain the debug information you mentioned above.

Is this sufficient to re-open this issue? Thanks.

Comment From: bclozel

We have indeed eliminated one possibility. It seems parameter information is present.

We can reopen this issue if you can provide a way for us to replicate the problem. I understand that this does not happen all the time and not locally, so this is going to be hard to replicate. Unfortunately we cannot reopen this issue until we can investigate ourselves.