Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MethodIntrospector.selectMethods() fails to detect bridge methods across ApplicationContexts #32586

Closed
RHarryH opened this issue Apr 7, 2024 · 6 comments
Assignees
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: backported An issue that has been backported to maintenance branches type: bug A general bug
Milestone

Comments

@RHarryH
Copy link

RHarryH commented Apr 7, 2024

Spring Boot version: 3.2.3, 3.2.4 (Spring Core 6.1.4)
Java version: Temurin 17 (17.0.10)

Reproduced on Windows and Github Actions with Ubuntu 22.04.

Minimal example: https://github.com/RHarryH/spring-webmvc-github-issue

Description:

I have observed weird issue of WebMvcTest failure with code 405 instead of expected 200 because Spring does not resolve controller method based on the request url. 405 error happens when there are two endpoints with the same request url but different HTTP method. When request urls are different 404 error is thrown.

This happens only when specific hierarchy of controllers is used and when WebMvcTest is run after SpringBootTest (achieved by changing test class execution order in junit-platform.properties.

The hierarchy of the controllers is as follows:

  • Controller interface defining endpoints and annotating them with @XMapping annotations
  • AbstractController implementing delete method. Please not it is a package-private abstract class
  • ActualController implementing remaining methods

The presence of AbstractController is the main cause of the issue. Working workaround is making it public.

When debugging tests SpringBootTest logs contains:

2024-04-07T12:01:20.781+02:00 DEBUG 33568 --- [           main] _.s.web.servlet.HandlerMapping.Mappings  : 
	c.a.i.ActualController:
	{POST [/v1/a]}: add(Body,BindingResult)
	{POST [/v1/a/{id}]}: update(UUID,Body,BindingResult)
	{DELETE [/v1/a/{id}]}: delete(UUID)

while WebMvcTest logs miss DELETE method:

2024-04-07T12:01:22.203+02:00 DEBUG 33568 --- [           main] _.s.web.servlet.HandlerMapping.Mappings  : 
	c.a.i.ActualController:
	{POST [/v1/a]}: add(Body,BindingResult)
	{POST [/v1/a/{id}]}: update(UUID,Body,BindingResult)

I have tracked down the rootcause to the org.springframework.core.MethodIntrocpector class and selectMethods(Class<?> targetType, final MetadataLookup<T> metadataLookup) method (

).

Line 74 correctly inspects the method. The problem is in line 77. When SpringBootTest tests are run the fields looks like below:

method = {Method@7492} "public void com.avispa.issue.AbstractController.delete(java.util.UUID)"
specificMethod = {Method@7493} "public void com.avispa.issue.ActualController.delete(java.util.UUID)"
result = {RequestMappingInfo@7494} "{DELETE [/v1/a/{id}]}"
bridgedMethod = {Method@7492} "public void com.avispa.issue.AbstractController.delete(java.util.UUID)"

But then whenWebMvcTest tests are run it looks like below:

method = {Method@9155} "public void com.avispa.issue.AbstractController.delete(java.util.UUID)"
specificMethod = {Method@9156} "public void com.avispa.issue.ActualController.delete(java.util.UUID)"
result = {RequestMappingInfo@9157} "{DELETE [/v1/a/{id}]}"
bridgedMethod = {Method@7492} "public void com.avispa.issue.AbstractController.delete(java.util.UUID)"

As you can see in second case method and bridgedMethod represents the same method but are in fact different instances of Method class. And because the comparison in line 77 is done by reference, it failes and does not add found DELETE method to the mappings registry.

When SpringBootTest tests are disabled, the problem does not exist.

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Apr 7, 2024
@wilkinsona wilkinsona self-assigned this Apr 8, 2024
@wilkinsona
Copy link
Member

Thanks very much for the detailed report, analysis, and minimal example.

It turns out that this isn't a Spring Boot problem and that it can be reproduced with pure Spring Framework. For the problem to occur, two contexts must be involved. Using @WebMvcTest and @SpringBootTest achieves this, but the same can be achieved with any configuration where the tests' context configurations are different.

I've forked the example and pushed an update that removes Spring Boot. Its tests still fail in the same way and log similar output for the mappings:

11:15:06.563 [main] DEBUG _org.springframework.web.servlet.HandlerMapping.Mappings -- 
	c.a.i.ActualController:
	{POST [/v1/a]}: add(Body,BindingResult)
	{POST [/v1/a/{id}]}: update(UUID,Body,BindingResult)
	{DELETE [/v1/a/{id}]}: delete(UUID)
11:15:06.848 [main] DEBUG _org.springframework.web.servlet.HandlerMapping.Mappings -- 
	c.a.i.ActualController:
	{POST [/v1/a]}: add(Body,BindingResult)
	{POST [/v1/a/{id}]}: update(UUID,Body,BindingResult)

My suspicion at the moment is that the problem's due to some static-scoped caching during the method introspection. We'll transfer this issue to the Framework team so that they can continue the investigation.

@wilkinsona wilkinsona removed their assignment Apr 8, 2024
@bclozel bclozel transferred this issue from spring-projects/spring-boot Apr 8, 2024
@bclozel bclozel added the in: test Issues in the test module label Apr 8, 2024
@wilkinsona
Copy link
Member

I should also have noted that I don't think this is even test-specific. I was also able to reproduce the problem (judging by the logging of the mappings) by adding a main method to the app in which I called SpringApplication.run(…).close() twice.

@sbrannen sbrannen added in: web Issues in web modules (web, webmvc, webflux, websocket) and removed in: test Issues in the test module labels Apr 8, 2024
@sbrannen sbrannen self-assigned this Apr 8, 2024
@sbrannen sbrannen added type: bug A general bug in: core Issues in core modules (aop, beans, core, context, expression) and removed status: waiting-for-triage An issue we've not yet triaged or decided on in: web Issues in web modules (web, webmvc, webflux, websocket) labels Apr 8, 2024
@sbrannen sbrannen added this to the 6.1.6 milestone Apr 8, 2024
@sbrannen sbrannen changed the title WebMvcTest tests fails with 405 when SpringBootTest invoked first because of package-private abstract class implementing endpoint in RestController hierarchy MethodIntrospector.selectMethods() fails to detect bridge method on subsequent run for the same criteria Apr 8, 2024
@sbrannen sbrannen changed the title MethodIntrospector.selectMethods() fails to detect bridge method on subsequent run for the same criteria MethodIntrospector.selectMethods() fails to detect bridged method on subsequent run for the same criteria Apr 8, 2024
@sbrannen
Copy link
Member

sbrannen commented Apr 8, 2024

Thanks to the examples from @RHarryH and @wilkinsona, I've been able to reproduce this in a simplified, stand-alone test class.

@SpringJUnitWebConfig
class ReproTests {

	@Nested
	// Configure a test property source to ensure we get a different ApplicationContext
	// than the one created for the enclosing ReproTests class.
	@TestPropertySource(properties = "enigma = 42")
	class ActualControllerTests {

		private final MockMvc mockMvc;
		private final UUID id = UUID.randomUUID();

		ActualControllerTests(WebApplicationContext wac) {
			this.mockMvc = MockMvcBuilders.webAppContextSetup(wac).build();
		}

		@Test
		void givenDto_whenUpdate_thenServiceCalled() throws Exception {
			mockMvc.perform(post("/v1/a/" + id)
					.contentType(APPLICATION_JSON)
					.content("""
							{"test" : "Value"}
							"""))
				.andExpect(status().isOk());
		}

		@Test
		void whenDelete_thenServiceCalled() throws Exception {
			mockMvc.perform(delete("/v1/a/" + id))
				.andExpect(status().isOk());
		}
	}

	@Configuration
	@EnableWebMvc
	@Import(ActualController.class)
	static class Config {
	}

	static class Body {

		private String test;

		Body() {
		}

		Body(String test) {
			this.test = test;
		}

		void setTest(String test) {
			this.test = test;
		}

		String getTest() {
			return test;
		}
	}

	@RestController
	interface Controller {

		@PostMapping("/{id}")
		void update(@PathVariable UUID id, @RequestBody Body body);

		@DeleteMapping("/{id}")
		void delete(@PathVariable UUID id);
	}

	// public
	static abstract class AbstractController implements Controller {

		@Override
		public void delete(UUID id) {
		}
	}

	@RequestMapping("/v1/a")
	public static class ActualController extends AbstractController {

		@Override
		public void update(UUID id, Body body) {
		}
	}

}

@RHarryH
Copy link
Author

RHarryH commented Apr 8, 2024

Thanks guys for such quick reaction and further simplification of the reproduction code. Actually this can be simplified even more because Body is not necessary to achieve the result. We don't even need update method with it's test. It fails with 404 now but the root cause is still the same.

@SpringJUnitWebConfig
class ReproTests {

	@Nested
	// Configure a test property source to ensure we get a different ApplicationContext
	// than the one created for the enclosing ReproTests class.
	@TestPropertySource(properties = "enigma = 42")
	class ActualControllerTests {

		private final MockMvc mockMvc;
		private final UUID id = UUID.randomUUID();

		ActualControllerTests(WebApplicationContext wac) {
			this.mockMvc = MockMvcBuilders.webAppContextSetup(wac).build();
		}

		@Test
		void whenDelete_thenServiceCalled() throws Exception {
			mockMvc.perform(delete("/v1/a/" + id))
				.andExpect(status().isOk());
		}
	}

	@Configuration
	@EnableWebMvc
	@Import(ActualController.class)
	static class Config {
	}

	@RestController
	interface Controller {
		@DeleteMapping("/{id}")
		void delete(@PathVariable UUID id);
	}

	// public
	static abstract class AbstractController implements Controller {
		@Override
		public void delete(UUID id) {
		}
	}

	@RequestMapping("/v1/a")
	public static class ActualController extends AbstractController {
	}
}

sbrannen added a commit that referenced this issue Apr 9, 2024
Prior to this commit, MethodIntrospector failed to properly detect
bridge methods for subsequent invocations of selectMethods() with the
same targetType and MetadataLookup, if such subsequent invocations
occurred after the ApplicationContext had been refreshed.

The reason this occurs is due to the following.

- Class#getDeclaredMethods() always returns "child copies" of the
  underlying Method instances -- which means that `equals()` should be
  used instead of `==` whenever the compared Method instances can come
  from different sources (such as the static caches mentioned below).

- BridgeMethodResolver caches resolved bridge methods in a static cache
  -- which is never cleared.

- ReflectionUtils caches declared methods in a static cache
  -- which gets cleared when an ApplicationContext is refreshed.

Consequently, if you attempt to load an ApplicationContext twice in the
same ClassLoader, the second attempt uses the existing, populated cache
for bridged methods but a cleared, empty cache for declared methods.
This results in new invocations of Class#getDeclaredMethods(), and
identity checks with `==` then fail to detect equivalent bridge methods.

This commit addresses this by additionally comparing bridge methods
using `equals()` in MethodIntrospector.selectMethods().

Note that the `==` checks remain in place as an optimization for when
`equals()` is unnecessary.

Closes gh-32586

(cherry picked from commit e702733)
@sbrannen sbrannen changed the title MethodIntrospector.selectMethods() fails to detect bridged method on subsequent run for the same criteria MethodIntrospector.selectMethods() fails to detect bridge methods across ApplicationContexts Apr 9, 2024
sbrannen added a commit that referenced this issue Apr 9, 2024
Prior to this commit, MethodIntrospector failed to properly detect
bridge methods for subsequent invocations of selectMethods() with the
same targetType and MetadataLookup, if such subsequent invocations
occurred after the ApplicationContext had been refreshed.

The reason this occurs is due to the following.

- Class#getDeclaredMethods() always returns "child copies" of the
  underlying Method instances -- which means that `equals()` should be
  used instead of `==` whenever the compared Method instances can come
  from different sources (such as the static caches mentioned below).

- BridgeMethodResolver caches resolved bridge methods in a static cache
  -- which is never cleared.

- ReflectionUtils caches declared methods in a static cache
  -- which gets cleared when an ApplicationContext is refreshed.

Consequently, if you attempt to load an ApplicationContext twice in the
same ClassLoader, the second attempt uses the existing, populated cache
for bridged methods but a cleared, empty cache for declared methods.
This results in new invocations of Class#getDeclaredMethods(), and
identity checks with `==` then fail to detect equivalent bridge methods.

This commit addresses this by additionally comparing bridge methods
using `equals()` in MethodIntrospector.selectMethods().

Note that the `==` checks remain in place as an optimization for when
`equals()` is unnecessary.

Closes gh-32586

(cherry picked from commit e702733)
@sbrannen
Copy link
Member

Hi @RHarryH,

Thanks again for reporting the issue. This has been addressed and included in today's releases for 6.1.6, 6.0.19, and 5.3.34.

Thanks guys for such quick reaction and further simplification of the reproduction code.

You're welcome.

Actually this can be simplified even more because Body is not necessary to achieve the result.

Indeed. Though, my original goal was to only simplify it enough for inclusion in a stand-alone test case, and I didn't bother simplifying that integration test further beyond that.

Rather, I later reduced it to the minimum in a unit test which you can see in the associated commit.

My suspicion at the moment is that the problem's due to some static-scoped caching during the method introspection.

Your hunch was right, @wilkinsona.

It turned out to be an issue involing two competing static caches that only reared its head after a context refresh, and the devil was in the details.

See e702733 for the full story.

sbrannen added a commit to sbrannen/spring-framework that referenced this issue Dec 1, 2024
Prior to this commit, the equals() implementation in AdvisedSupport's
MethodCacheKey only considered methods to be equal based on an identity
comparison (`==`). However, an identity comparison is not always
sufficient due to the following.

- Class#getDeclaredMethods() always returns "child copies" of the
  underlying Method instances -- which means that `equals()` should be
  used instead of (or in addition to) `==` whenever the compared Method
  instances can come from different sources.

With this commit, the equals() implementation in MethodCacheKey now
considers methods equal based on identity or logical equality, giving
preference to the quicker identity check.

See spring-projectsgh-32586
Closes spring-projectsgh-33915
sbrannen added a commit to sbrannen/spring-framework that referenced this issue Dec 2, 2024
Prior to this commit, the equals() implementation in AdvisedSupport's
MethodCacheKey only considered methods to be equal based on an identity
comparison (`==`). However, an identity comparison is not always
sufficient due to the following.

- Class#getDeclaredMethods() always returns "child copies" of the
  underlying Method instances -- which means that `equals()` should be
  used instead of (or in addition to) `==` whenever the compared Method
  instances can come from different sources.

With this commit, the equals() implementation in MethodCacheKey now
considers methods equal based on identity or logical equality, giving
preference to the quicker identity check.

See spring-projectsgh-32586
Closes spring-projectsgh-33915
sbrannen added a commit that referenced this issue Dec 4, 2024
Prior to this commit, the equals() implementation in AdvisedSupport's
MethodCacheKey only considered methods to be equal based on an identity
comparison (`==`), which led to duplicate entries in the method cache
for the same logical method.

This is caused by the fact that AdvisedSupport's
getInterceptorsAndDynamicInterceptionAdvice() method is invoked at
various stages with different Method instances for the same method:

1) when creating the proxy
2) when invoking the method via the proxy

The reason the Method instances are different is due to the following.

- Methods such as Class#getDeclaredMethods() and
  Class#getDeclaredMethod() always returns "child copies" of the
  underlying Method instances -- which means that `equals()` should be
  used instead of (or in addition to) `==` whenever the compared Method
  instances can come from different sources.

With this commit, the equals() implementation in MethodCacheKey now
considers methods equal based on identity or logical equality, giving
preference to the quicker identity check.

See gh-32586
Closes gh-33915
sbrannen added a commit that referenced this issue Dec 4, 2024
Prior to this commit, the equals() implementation in AdvisedSupport's
MethodCacheKey only considered methods to be equal based on an identity
comparison (`==`), which led to duplicate entries in the method cache
for the same logical method.

This is caused by the fact that AdvisedSupport's
getInterceptorsAndDynamicInterceptionAdvice() method is invoked at
various stages with different Method instances for the same method:

1) when creating the proxy
2) when invoking the method via the proxy

The reason the Method instances are different is due to the following.

- Methods such as Class#getDeclaredMethods() and
  Class#getDeclaredMethod() always returns "child copies" of the
  underlying Method instances -- which means that `equals()` should be
  used instead of (or in addition to) `==` whenever the compared Method
  instances can come from different sources.

With this commit, the equals() implementation in MethodCacheKey now
considers methods equal based on identity or logical equality, giving
preference to the quicker identity check.

See gh-32586
Closes gh-33915
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: core Issues in core modules (aop, beans, core, context, expression) status: backported An issue that has been backported to maintenance branches type: bug A general bug
Projects
None yet
Development

No branches or pull requests

5 participants