markBeanAsCreated does not clear merged bean definition in a thread-safe fashion [SPR-14269]

[spring-projects-issues]

Marcin Piela opened SPR-14269 and commented

When creating a context and then calling getBean on it from multiple threads we sometimes get a BeanInitializationException from RequiredAnnotationBeanPostProcessor.postProcessPropertyValues.
Attached is a simple maven project to reproduce. In a loop it:

1. creates a fresh spring context
2. attempts to fetch some beans from it in parallel.
   The number of threads and max number of loop iterations can be passed as the first and second argument to the Main class.
   Usage:
   mvn clean package && java -jar target/spring-bug-1.0-SNAPSHOT-jar-with-dependencies.jar
   We never get any errors when the getBean method is called from a single thread, so:
   java -jar target/spring-bug-1.0-SNAPSHOT-jar-with-dependencies.jar 1
   always works.
   We don't get any errors for spring version 4.1.9, but as long as we switch to 4.2.0 or later the errors start occuring.
   Example exception:

Exception in thread "main" org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'service-2' defined in class path resource [example-context.xml]: Cannot resolve reference to bean 'bean_0_1' while setting bean property 'bean_0_1'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'bean_0_1' defined in URL [jar:file:/home/mpiela/devel/repo/spring-bug/target/spring-bug-1.0-SNAPSHOT-jar-with-dependencies.jar!/test/Bean_0_1.class]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanInitializationException: Properties 'bean_1_0' and 'bean_1_1' are required for bean 'bean_0_1'
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:359)
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1481)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1226)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:325)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
	at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1054)
	at test.Main.lambda$tryToGetBean$0(Main.java:75)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'bean_0_1' defined in URL [jar:file:/home/mpiela/devel/repo/spring-bug/target/spring-bug-1.0-SNAPSHOT-jar-with-dependencies.jar!/test/Bean_0_1.class]: Initialization of bean failed; nested exception is org.springframework.beans.factory.BeanInitializationException: Properties 'bean_1_0' and 'bean_1_1' are required for bean 'bean_0_1'
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:553)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:325)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
	... 13 more
Caused by: org.springframework.beans.factory.BeanInitializationException: Properties 'bean_1_0' and 'bean_1_1' are required for bean 'bean_0_1'
	at org.springframework.beans.factory.annotation.RequiredAnnotationBeanPostProcessor.postProcessPropertyValues(RequiredAnnotationBeanPostProcessor.java:156)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1214)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:543)
	... 17 more

---

Affects: 4.2.6

Attachments:

• spring-bug.tar.gz (2.25 kB)

Issue Links:

• Reduce BeanDefinition cloning in AbstractBeanFactory.getMergedBeanDefinition [SPR-12236] #16851 Reduce BeanDefinition cloning in AbstractBeanFactory.getMergedBeanDefinition

Referenced from: commits 9064d38, 71463fb, 933bbf2, 6efa058

Backported to: 4.2.7

[spring-projects-issues]

andyjojo commented

the method markBeanAsCreated(String beanName) in AbstractBeanFactory is not thread safe.
thread A and thread B try to call this method, A check !this.alreadyCreated.contains(beanName) return true, then call this.alreadyCreated.add(beanName); at this time B check !this.alreadyCreated.contains(beanName) return false, then B out of this method, but now A does not finish clearMergedBeanDefinition(beanName); then B call getMergedLocalBeanDefinition(String beanName) may return old BeanDefinition

[spring-projects-issues]

andyjojo commented

I have a pull request, #1059, please help to review.

[spring-projects-issues]

Juergen Hoeller commented

Moving the this.alreadyCreated.add(beanName) call right after clearMergedBeanDefinition(beanName) seems to be the most efficient way out here: In case of a race condition, we'll clear the merged bean definition too often but that's acceptable; we'll at least guarantee that subsequent steps will always see an up-to-date bean definition then.

[spring-projects-issues]

andyjojo commented

@Juergen Hoeller I have tried not adding synchronized (this.alreadyCreated), when running the test still throw the same exception with more attempts(one test happened after 239 attempts of 4 threads). You can have a try. I still do not know why it is happen, but it is actually happened.

[spring-projects-issues]

andyjojo commented

the error just occurs just because the too ofter clear the merged bean definition in multi threads for method protected RootBeanDefinition getMergedBeanDefinition(String beanName, BeanDefinition bd, BeanDefinition containingBd) throws BeanDefinitionStoreException If thread A first clear merged bean then call getMergedBeanDefinition and create a new RootBeanDefinition, but thread B first clear the merged bean definition then call getMergedBeanDefinition and create another new RootBeanDefinition, there will be two different BeanDefinitions.

[spring-projects-issues]

Juergen Hoeller commented

Since getMergedBeanDefinition operates within a full lock, there should never be two different bean definitions stored there. Temporary use of two different (but equivalent) merged bean definitions is not an issue; we do that in other scenarios as well.

Have you tried to reproduce this against the latest 4.3.0.BUILD-SNAPSHOT? It would help a lot to isolate failures against that re-ordered but non-synchronized scenario since there might be some related bug lurking in our merged bean definition handling.

[spring-projects-issues]

andyjojo commented

I have download latest code and running ./gradlew install then using 4.3.0.BUILD-SNAPSHOT, the issues can be reproduced.

[spring-projects-issues]

andyjojo commented

if there are two different merged bean definitions for same beanName, the method InjectionMetadata.checkPropertySkipping(PropertyValues pvs) will not work correctly because same InjectionMetadata cached from CommonAnnotationBeanPostProcessor.findResourceMetadata for same beanName but different PropertyValues.

[spring-projects-issues]

Juergen Hoeller commented

Good catch! Thanks for the insight, I'll have another pass today.

[spring-projects-issues]

Juergen Hoeller commented

I've addressed this through synchronizing on this.mergedBeanDefinitions now, checking for this.alreadyCreated.add(beanName) within and clearing the merged bean definition if the add call returned true. We still do an non-synchronized !this.alreadyCreated.contains(beanName) first, so overall this should not cause any inefficiency in a fully initialized system.

The use of the this.mergedBeanDefinitions lock is in sync with getMergedBeanDefinition, in order to prevent interleaving with ongoing merge attempts as well (where an old version might get cached in certain race condition cases otherwise, e.g. with concurrent type matching attempts touching the same bean and the bean definition having been modified inbetween).

[spring-projects-issues]

andyjojo commented

@Juergen Do you test your code? I have test it and still can reproduce the issue. I have test my pull request via 8 thread and 40000 attempts without reproduce the issue.

[spring-projects-issues]

Juergen Hoeller commented

It'd be great if you could run your tests against the latest 4.3.0.BUILD-SNAPSHOT again... Please make sure that it's actually the latest, not a locally cached old snapshot.

[spring-projects-issues]

Juergen Hoeller commented

Ouch, there might indeed be a remaining issue since the add exposes itself for early contains checks again... I was just checking the re-merge behavior but not potential access to an old bean definition. Alright, one more pass coming here, moving the add to the end of the synchronized block.

[spring-projects-issues]

andyjojo commented

not the issue of add method, the issue in your commit is same with no synchronized because the method getMergedLocalBeanDefinition(String beanName) are not synchronized in line 1176.

[spring-projects-issues]

Juergen Hoeller commented

As far as I can see, with the add moved, the code is analogous to your pull request now, just using a different lock to synchronize on.

getMergedLocalBeanDefinition does not have to be synchronized from my perspective. As long as the clearMergedBeanDefinition call happens before we expose a bean as already created, any actual creation attempts will see the fresh bean definition. And for concurrent type matching purposes, an old bean definition is good enough.

[spring-projects-issues]

Juergen Hoeller commented

BTW, I'm currently working on a whole range of 4.2.x backports, so this fix will appear in the upcoming 4.2.7.BUILD-SNAPSHOT as well (actually, there first).

[spring-projects-issues]

andyjojo commented

I do not mean getMergedLocalBeanDefinition need synchronized, I mean non-syncrhonzied getMergedLocalBeanDefinition case your commit not work.

[spring-projects-issues]

Juergen Hoeller commented

That's true but it isn't meant to cover that case: The common lock is just intended to cover mergedBeanDefinitions add/remove attempts, where a remove does not happen while another thread is currently doing a merge (e.g. from a type match attempt) based on potentially outdated metadata... so it rather happens right afterwards then.

In any case, I can't reproduce the reported issue anymore with the add moved to the end of the synchronized (mergedBeanDefinitions) block, not even with 8 threads and 40.000 attempts. So I guess we can consider your case covered now? The current 4.2.7.BUILD-SNAPSHOT and the upcoming 4.3.0.BUILD-SNAPSHOT contain that candidate state.