HandlerInterceptorAdapter: unexpected behaviour for different methods on the same endpoint [SPR-17375]

[spring-projects-issues]

Enrico Graziani opened SPR-17375 and commented

Problem

While testing how HandlerInterceptorAdapter works, we found out that by:

• registering the interceptor for /some/**
• having a controller with a registered method GET /some/thing

will cause the interceptor to be executed for:

•  GET /some/thing
• all [VERB] /some/**
  APART [VERB] /some/thing

e.g. so POST /some/thing will not pass through the above interceptor

 

IMO
This sounds confusing.
The +expected behaviour+ would be to either execute the interceptor for:

• all available methods/endpoint for the registered interceptor
  in this example, [VERB] /some/** requests
• or, only the method/endpoint registered in the controllers
  in this example,  GET /some/thing

Background

We have a requirement to log every request and collect metrics in Splunk.
We were thinking on registering a HandlerInterceptorAdapter for holding these behaviours.

Code Snippets

Application is annotated with @SpringBootApplication 
Controller is annotated with @RestController

springBootVersion = "2.0.2.RELEASE"

Application

@SpringBootApplication
public class Application {

    private static final Logger logger = LoggerFactory.getLogger(Application.class);

    public static void main(String[] args) {
        logger.info("Starting Application");
        SpringApplication.run(Application.class, args);
    }
}

WebConfig

@Configuration
public class WebConfig implements WebMvcConfigurer {

    @Autowired
    private LoggerRequestInterceptor loggerRequestInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(loggerRequestInterceptor)
                .addPathPatterns("/some/**");
    }
}

LoggerRequestInterceptor

@Component
public class LoggerRequestInterceptor extends HandlerInterceptorAdapter {
    private static final Logger logger = LoggerFactory.getLogger(LoggerRequestInterceptor.class);

    @Override
    public boolean preHandle(
            HttpServletRequest request,
            HttpServletResponse response,
            Object handler) {
        logger.info(MessageFormat.format(
                "{0} {1}",
                request.getMethod(),
                request.getRequestURI()
        ));
        return true;
    }

}

Controller

@RestController
@RequestMapping("/some/")
public class HoldingController {

    @GetMapping(path = {"/thing"}, produces={"application/json"})
    public String getHoldingsMaterial() {
        return "hi";
    }
}

Behaviours

GET /some/thing

*.LoggerRequestInterceptor   : GET /some/thing

GET /some/notExisting

*.LoggerRequestInterceptor   : GET /some/notExisting

POST /some/thing

o.s.web.servlet.PageNotFound             : Request method 'POST' not supported

---

Affects: 5.0.6

[spring-projects-issues]

Brian Clozel commented

A HandlerInterceptor, as described in its javadoc, is made to intercept requests before/after a Spring MVC handler is called. It goes (roughly) like this:

• A request comes in and is processed by the DispatcherServlet 
• that servlet runs that request through registered HandlerMapping instances
• if a HandlerMapping instance finds a handler that matches the incoming request
  • the registered handler interceptors are executed
• if nothing was mapped to this request, a 404 is issued

In this case, your Controller only maps GET and HEAD requests by default. So the RequestMappingHandlerMapping doesn't find any handler for that request - your interceptor is never called.

In the case of GET /some/notExisting:

• the ResquestMappingHandlerMapping does not map that path, so this request is delegated to the next handlermapping in line
• next in line, static resource handling kicks in; a SimpleUrlHandlerMapping instance (probably mapped to /*) delegates to ResourceHttpRequestHandler
• that resource handler doesn't have a resource matching that path, so it issues a 404. The request is handled still by that handler so interceptors are applied here (as of resourceHandlerMapping should be registered with shared HandlerInterceptor [SPR-16034] #20583).

In the case of POST /some/thing:

• the ResquestMappingHandlerMapping does map that path, so this request is handled by it
• the method is not supported by the selected controller handler, so the error message is returned

I agree that in this case this can be confusing - but HandlerInterceptor are not meant for instrumentation of incoming requests, but rather intercepting requests before they're being processed by a handler. You should see that the Object handler instance passed to your interceptor is not the same in the examples you've outlined.

If you'd like to instrument your application in a more global way, you should use instead a Servlet Filter, which can be applied more broadly. The good news is you don't need the level of information of a handler interceptor (which knows about the selected handler) - you just want to know about the request path.

I'm closing this issue as it's working as designed.

For more questions about this, you can ask on StackOverflow or look into how Spring Boot is instrumenting Spring MVC with WebMvcMetricsFilter.

Thanks!

[spring-projects-issues]

Enrico Graziani commented

Brian Clozel I understand the title of the ticket is misleading and sorry for insisting...

 

Why these requests will pass through the interceptor then?

GET /some/notExisting

*.LoggerRequestInterceptor   : GET /some/notExisting

POST /some/notExisting

*.LoggerRequestInterceptor   : POST/some/notExisting

 

The behaviour you are describing is what is, as you said, reported in the javadoc you mentioned, and is also what it would be naturally expectable.
What I'm suggesting here is that if:

• the controller roots on /some
• a method in this controller register GET /some/thing
• an interceptor is added for /some/**

The interceptor will receive e.g. (GET|POST|PUT|DELETE ) /some/(notExisting|fake|whatever)

Which is totally undocumented and unexpected.

[spring-projects-issues]

Brian Clozel commented

You're right, I've updated my previous comment which was incomplete.

I guess part of the confusion comes from the fact that you think that adding a @RequestMapping("/some") to a Controller class will make it handle all "/some/**" requests, which is not the case. In fact, you can have several controllers with that annotation. This annotation merely prepends all @RequestMapping definitions of that controller with that common path.

I hope that my previous comment explained why you're seeing this behavior in your application. This is still in line with the HandlerInterceptor contract, but indeed requires a bit of knowledge about Spring MVC infrastructure.

To be more in line with your expectations, we'd have to change the implementation of the RequestMappingHandlerMapping and its adapter to not throw an exception when the HTTP method is not the one expected. This would be also be true for other constraints on the handler itself, like expected content-type, required header or parameter, content negotiation for the return value, and more. This is an important part of our REST support and we can't change that without breaking the whole Spring MVC ecosystem.

[spring-projects-issues]

Enrico Graziani commented

Your answer clarifies it all.

Thanks a lot!