Random issue when trying to expose a search resource [DATAREST-474]

Hugo Lassiège opened DATAREST-474 and commented

Hi,

I've got a weird issue with spring-data-rest.

The problem is that the problem occurs randomly, so it could be hard to see.
I've build a demo project to show it.

In this project, when you launch it, sometimes, the two following endpoints don't work. It returns a 404 error and that's all.

http://localhost:8287/api/recommandations/search
http://localhost:8287/api/recommandations/search/profile

When it happens, I have the following logs (in debug mode only)

20:06:02.460 [http-nio-8287-exec-1] DEBUG o.s.b.a.e.mvc.EndpointHandlerMapping - Looking up handler method for path /api/recommandations/search/profile
20:06:02.461 [http-nio-8287-exec-1] DEBUG o.s.b.a.e.mvc.EndpointHandlerMapping - Did not find handler method for [/api/recommandations/search/profile]
20:06:02.462 [http-nio-8287-exec-1] DEBUG o.s.w.s.m.m.a.RequestMappingHandlerMapping - Looking up handler method for path /api/recommandations/search/profile
20:06:02.464 [http-nio-8287-exec-1] DEBUG o.s.w.s.m.m.a.RequestMappingHandlerMapping - Did not find handler method for [/api/recommandations/search/profile]
20:06:02.465 [http-nio-8287-exec-1] DEBUG o.s.d.r.w.BaseUriAwareHandlerMapping - Looking up handler method for path /api/recommandations/search/profile
20:06:02.466 [http-nio-8287-exec-1] DEBUG o.s.d.r.w.BaseUriAwareHandlerMapping - Did not find handler method for [/api/recommandations/search/profile]
20:06:02.466 [http-nio-8287-exec-1] DEBUG o.s.d.r.w.RepositoryRestHandlerMapping - Looking up handler method for path /api/recommandations/search/profile
20:06:02.475 [http-nio-8287-exec-1] DEBUG o.s.d.r.w.RepositoryRestHandlerMapping - Returning handler method [public org.springframework.http.ResponseEntity<java.lang.Object> org.springframework.data.rest.webmvc.RepositorySearchController.executeSearch(org.springframework.data.rest.webmvc.RootResourceInformation,org.springframework.web.context.request.WebRequest,java.lang.String,org.springframework.data.rest.webmvc.support.DefaultedPageable,org.springframework.data.domain.Sort,org.springframework.data.rest.webmvc.PersistentEntityResourceAssembler)]
20:06:02.475 [http-nio-8287-exec-1] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'repositorySearchController'
20:06:02.476 [http-nio-8287-exec-1] DEBUG o.s.web.servlet.DispatcherServlet - Last-Modified value for [/api/recommandations/search/profile] is: -1
20:06:02.498 [http-nio-8287-exec-1] DEBUG o.s.b.f.s.DefaultListableBeanFactory - Returning cached instance of singleton bean 'readOnlyRecommandationRepository'
20:06:02.509 [http-nio-8287-exec-1] DEBUG o.s.w.s.m.m.a.ExceptionHandlerExceptionResolver - Resolving exception from handler [public org.springframework.http.ResponseEntity<java.lang.Object> org.springframework.data.rest.webmvc.RepositorySearchController.executeSearch(org.springframework.data.rest.webmvc.RootResourceInformation,org.springframework.web.context.request.WebRequest,java.lang.String,org.springframework.data.rest.webmvc.support.DefaultedPageable,org.springframework.data.domain.Sort,org.springframework.data.rest.webmvc.PersistentEntityResourceAssembler)]: org.springframework.data.rest.webmvc.ResourceNotFoundException: Resource not found!
20:06:02.512 [http-nio-8287-exec-1] DEBUG o.s.w.s.m.m.a.ExceptionHandlerExceptionResolver - Invoking @ExceptionHandler method: public org.springframework.http.ResponseEntity<?> org.springframework.data.rest.webmvc.AbstractRepositoryRestController.handleNotFound()
20:06:02.531 [http-nio-8287-exec-1] DEBUG o.s.w.s.m.m.a.ResponseBodyAdviceChain - Invoking ResponseBodyAdvice chain for body=null
20:06:02.531 [http-nio-8287-exec-1] DEBUG o.s.w.s.m.m.a.ResponseBodyAdviceChain - After ResponseBodyAdvice chain body=null
20:06:02.531 [http-nio-8287-exec-1] DEBUG o.s.web.servlet.DispatcherServlet - Null ModelAndView returned to DispatcherServlet with name 'dispatcherServlet': assuming HandlerAdapter completed request handling
20:06:02.531 [http-nio-8287-exec-1] DEBUG o.s.web.servlet.DispatcherServlet - Successfully completed request

But most of the time, it works ^^

In debug mode I just saw that the problem is visible in RepositoryResourceMappings.getSearchResourceMappings
The searchcache contains a resourceMapping that is empty.

But again, it's hard to understand because if you try to debug the first time, it always works (or maybe I was just unlucky). I was just able to see this problem of resourceMapping when the searchCache is not empty.

I don't know how to go further but it's really blocking

Affects: 2.2.1 (Evans SR1)

Reference URL: https://github.com/Hopwork/spring-data-rest-bugreport

5 votes, 7 watchers