Description:
When creating custom web filter and extending it from org.springframework.web.filter.OncePerRequestFilter (which is extended from org.springframework.web.filter.GenericFilterBean) and declaring it as bean, then NullPointerException is thrown from GenericFilterBean#init method during embedded server startup because inside init method there is a call to logger's field method, and logger is null somehow.
Versions affected:
Affects at least spring-web 6.0.2.
Investigation results:
After some investigation I found out that this behavior occurs only when custom web filter bean is proxied by CGLIB mechanism. It seems that when custom filter bean is proxied by CGLIb then 'logger' field of proxy instance not initialized.
Possible solutions/workarounds:
Simple workaround here is not to declare filter as bean but I guess in general it's not an intended behavior. I also checked that replacement in source code all direct calls to 'logger' field with getter calls (protected Log getLogger() ) would work but I'm not sure it's the best option for fixing it.
Comment From: mdeinum
It is due to a proxy being created and the init method being final. Meaning the method cannot be proxied and it will be invoked on the proxy instead of passing along to the underlying proxied instance. As a proxy doesn't have any of the fields initialized it will lead to a NullPointerException.
The real question is why is there even a proxy being generated for this filter? This would generally occur with a very broad pointcut. This is more or less the same as in https://github.com/spring-projects/spring-framework/issues/29592.
Comment From: reaper-1617
Yes, it's a great explanation about why it really happens, thanks! I spent some time investigating similar issues, but was not so successful in it. You're right, it looks very similar to #29592
Could you please clarify for me what do you mean by 'why is there even a proxy being generated for this filter'?
I thought if I declare my custom filter as @Bean, it would be proxied by Spring anyway (by JDK dynamic proxy or CGLIB proxy, depending on configuration, but anyway).
Am I missing something general? If yes, could you please provide some points for me to learn/investigate more?
Thanks )
Comment From: mdeinum
There will only be a proxy if there is AOP in your project which applies to the classes in the packages. As you have created your own filter, it is probably in one of your own packages and there is some AOP configuration for that package as well. Depending on the type of pointcut it can be determined at startup if a proxy needs to be created (and can be skipped) or at runtime (cannot be skipped).
If you have your own dedicated pointcuts (or some 3rd party ones) you might want to extend them to, for instance, exclude servlet filters.
Comment From: reaper-1617
Thanks for this detailed explanation!
I checked out my project where this issue appeared first time, and found an AOP config for almost all packages including custom filter package. So it clarifies why CGLIB proxy has appeared. Without this AOP config my custom filter isn't proxied by CGLIB and successfully bootstrapped as @Bean (as intended).
The last question that remains bit unclarified for me: is this an intended behavior to have a NullPointerException if filter bean is proxied via CGLIB? My first expectation was so that filter bean should be bootstrapped correctly whether it is proxied by CGLIB or not.
Comment From: mdeinum
It is a result of not being able to proxy final methods. Which will be invoked on the proxy instead of the underlying object.
Comment From: reaper-1617
Yes, but is it a desired behavior?
If I understood it correctly, it can be fixed if:
1. Change logger field visibility to private
2. Provide getter for logger field in GenericFilterBean (e.g. protected Log getLogger() )
3. Use this getter instead of direct logger field invocation.
What do you think about this fix? Are there any non-obvious pitfalls?
Comment From: mdeinum
That isn't a fix but rather a workaround. Nor would it eventually fix it as the getLogger() for the final method would be invoked on the proxy as well and leading to the same NullPointerException. This is a general issue with class based proxies for final methods and isn't new.
Maybe the documentation could be a bit increased/clarified on this matter.
Comment From: reaper-1617
I meant that getLogger method should not be final so that it might be proxied.
And when some final method invokes getLogger it will invoke proxy's method which will delegate call to original object's method so an appropriate logger instance would be obtained .. at least in my investigation where I did that, the final init method have successfully called getLogger on proxy and got non-null logger instance .. is there something I have missed in this case?
Why it is a workaround, not fix?
Comment From: mdeinum
Because it might not be called on the proxy especially from inside the proxied object, which could lead to other issues. It would also needed to be done for all the methods that are called/variables used. And not only here but for all classes in the framework.
It is also a workaround because the issue is that it is caused by a too broad pointcut (the class shouldn't be proxied) and thus it is a workaround for an issue that shouldn't be there in the first place.
But I'm not maintaining the code, you are always free to submit a PR with your proposed fix ofcourse.
Comment From: bclozel
Thanks @reaper-1617 for bringing this up and thank you @mdeinum for helping diagnose the issue.
As Marten pointed out, the core problem here is a pointcut definition that is too broad. Not all classes are meant to be proxied and we don't think there is a case for this one. Applying such a pattern on all Spring Framework classes would put a massive maintenance burden and unrealistic constraints to our codebase, for no real value for end users. As far as I understand, in your case, fixing the pointcut not only fixed this issue but also massively decreased the numbers of proxies in your application (which should be a performance win).
In light of that, I'm declining this issue. Thanks!
Comment From: reaper-1617
@mdeinum thanks for this great discussion! It seems that I need to go deeper into AOP proxies)
@bclozel you're absolutely right, fixing the pointcut lead to performance win, undoubtedly, and excluding some packages from pointcut was the best solution in my case. First I thought that it's a bit confusing behavior, but if the general idea is that not all classes are supposed to be proxied, then it's ok) Thanks!
Comment From: fhackenberger
Just wanted to add here, that I was running into the same symptom, but because I was (setter) injecting the filter using @Lazy, which creates either JDK or CGLIB proxies. The solution was to add an interface to my class and inject that interface, so Spring could choose JDK proxies instead of CGLIB and the issue was solved. See DefaultAopProxyFactory#createAopProxy().