Spring Data Infinite Loop in HashMap in PreferredConstructor and CustomConversions

Spring Data Infinite Loops in Production

This blog post is related to an issue we have started seeing in production at the company where I work. I am trying to figure out where to take this next. I have posted this report to the Spring Data forum here:

• http://forum.spring.io/forum/spring-projects/data/750072-spring-data-infinite-loop-in-hashmap-in-preferredconstructor-and-customconversions

It started happening a few weeks ago. We would see a box CPU suddenly go to 100% indefinitely until the app was redeployed. Fortunately, we did take thread dumps, and in one case a heap dump. We were able to see that there is a recurring infinite loop in two places in Spring Data.

This has happened a total of 3 times now. Given the number of nodes we run in PROD, INT and QA (some number > 30), and the length of time we have been in production on this stack, we would characterize it as a rare occurrence. But it worries us.

One could ask "what changed in the application to make this start happening?". Ack. We are in our busy season right now, so a lot of commits went into our application for the weeks prior to the first occurrence. And given the rare nature of the problem, it would be difficult to really identify even the time range of commits that we would need to evaluate.

Root Cause

In all 3 cases, the infinite loop is coming from concurrent updates to the thread-unsafe HashMap class. We see it happening within two Spring Data classes:

• org.springframework.data.mapping.PreferredConstructor
• org.springframework.data.mongodb.core.convert.CustomConversions

I could explain why HashMap is getting stuck in infinite loops, but several others have already done a great job doing it, so I refer you there:

• http://mailinator.blogspot.dk/2009/06/beautiful-race-condition.html
• https://code.google.com/p/javasimon/issues/detail?id=115

Why us, not everyone else using Spring Data?

Looking at the PreferredConstructor and CustomConversions source code reveals that indeed they are indeed using raw HashMap instead of ConcurrentHashMap. Does that mean those classes do not expect to be accessed by more than one thread? 

But why are we the first to see this? I see no other complaints about for this issue with respect to Spring Data on the web. Three possibilities:

• We are using Spring Data incorrectly
• This a problem in Spring Data, and
• Other people have hit this, but no one has traced it to Spring Data yet
• We are very unlucky to be the first/only people to have hit it

As for point one, we have reviewed our application and Spring Data docs. We have looked and looked, and cannot see anything amiss in our implementation.

More Often, Occurs Soon After a Deployment

In 2 cases out of 3, this problem happened soon after a redeploy of the application. That suggests that this problem happens during initialization/first run of a code path. But we can't explain the 3rd outage though.

Stack Trace Snippet for PreferredConstructor

This stack trace was taken from a thread dump during one event. A more complete thread dump can be found here: 

• http://pastebin.com/c5erB5XF

"http-bio-8080-exec-235" daemon prio=10 tid=0x00007fb19c0a9800 nid=0x5337 runnable [0x00007fb228953000]

   java.lang.Thread.State: RUNNABLE

at java.util.HashMap.getEntry(HashMap.java:469)

at java.util.HashMap.get(HashMap.java:421)

at org.springframework.data.mapping.PreferredConstructor.isConstructorParameter(PreferredConstructor.java:120)

at org.springframework.data.mapping.model.BasicPersistentEntity.isConstructorArgument(BasicPersistentEntity.java:98)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:252)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:249)

at org.springframework.data.mapping.model.BasicPersistentEntity.doWithProperties(BasicPersistentEntity.java:257)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:249)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:223)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:187)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:183)

at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:77)

at org.springframework.data.mongodb.repository.support.SpringDataMongodbQuery$1.apply(SpringDataMongodbQuery.java:55)

at org.springframework.data.mongodb.repository.support.SpringDataMongodbQuery$1.apply(SpringDataMongodbQuery.java:53)

at com.mysema.query.mongodb.MongodbQuery.list(MongodbQuery.java:270)

at org.springframework.data.mongodb.repository.support.QueryDslMongoRepository.findAll(QueryDslMongoRepository.java:114)

at sun.reflect.GeneratedMethodAccessor356.invoke(Unknown Source)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:606)

at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.executeMethodOn(RepositoryFactorySupport.java:344)

at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:329)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)

at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)

at com.sun.proxy.$Proxy161.findAll(Unknown Source)

at com.silverchalice.scamp.bizniz.v3.media.MediaServiceImpl.findByFilter(MediaServiceImpl.java:293)

Stack Trace Snippet for CustomConversions

This stack trace was taken from a thread dump during one event. A more complete thread dump can be found here:

• http://pastebin.com/gYMGPEkL

"http-bio-8080-exec-75" daemon prio=10 tid=0x00007f3688018000 nid=0x6c2e runnable [0x00007f376e9ef000]
java.lang.Thread.State: RUNNABLE
at java.util.HashMap.getEntry(HashMap.java:469)
at java.util.HashMap.get(HashMap.java:421)
at org.springframework.data.mongodb.core.convert.CustomConversions.getCustomReadTarget(CustomConversions.java:317)
at org.springframework.data.mongodb.core.convert.CustomConversions.hasCustomReadTarget(CustomConversions.java:281)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:200)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.readCollectionOrArray(MappingMongoConverter.java:791)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.readValue(MappingMongoConverter.java:1048)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.access$100(MappingMongoConverter.java:77)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$MongoDbPropertyValueProvider.getPropertyValue(MappingMongoConverter.java:999)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.getValueInternal(MappingMongoConverter.java:755)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:256)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:249)
at org.springframework.data.mapping.model.BasicPersistentEntity.doWithProperties(BasicPersistentEntity.java:257)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:249)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:223)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.readValue(MappingMongoConverter.java:1050)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.access$100(MappingMongoConverter.java:77)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$MongoDbPropertyValueProvider.getPropertyValue(MappingMongoConverter.java:999)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.getValueInternal(MappingMongoConverter.java:755)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:256)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:249)
at org.springframework.data.mapping.model.BasicPersistentEntity.doWithProperties(BasicPersistentEntity.java:257)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:249)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:223)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.readCollectionOrArray(MappingMongoConverter.java:791)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.readValue(MappingMongoConverter.java:1048)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.access$100(MappingMongoConverter.java:77)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$MongoDbPropertyValueProvider.getPropertyValue(MappingMongoConverter.java:999)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.getValueInternal(MappingMongoConverter.java:755)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:256)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter$1.doWithPersistentProperty(MappingMongoConverter.java:249)
at org.springframework.data.mapping.model.BasicPersistentEntity.doWithProperties(BasicPersistentEntity.java:257)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:249)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:223)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:187)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:183)
at org.springframework.data.mongodb.core.convert.MappingMongoConverter.read(MappingMongoConverter.java:77)
at org.springframework.data.mongodb.repository.support.SpringDataMongodbQuery$1.apply(SpringDataMongodbQuery.java:55)
at org.springframework.data.mongodb.repository.support.SpringDataMongodbQuery$1.apply(SpringDataMongodbQuery.java:53)
at com.mysema.query.mongodb.MongodbQuery.list(MongodbQuery.java:270)
at org.springframework.data.mongodb.repository.support.QueryDslMongoRepository.findAll(QueryDslMongoRepository.java:114)
at sun.reflect.GeneratedMethodAccessor470.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.executeMethodOn(RepositoryFactorySupport.java:344)
at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:329)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy124.findAll(Unknown Source)
at com.silverchalice.scamp.bizniz.v3.events.EventServiceImpl.findByLiveStatsAssetId(EventServiceImpl.java:141)

Application Details

Here is a bullet list of details about our application:

• Web application
• We have ~40 Repository definitions (PagingAndSortingRepository)
• We use Spring Java Config
• We use QueryDSL for querying in almost all cases
• Our app is very read heavy, something like 99.9% reads
• Our app ranges from 100 to 10,000 requests per minute on a box. These events took place during times of not-so-high load (say, a few hundred requests per minute)

Stack Details

Here is a bullet list of details about our environment:

• Java webapp hosted as an Amazon EC2 Elasticbeanstalk app
• JVM: java version “1.7.0_51"   Java(TM) SE Runtime Environment (build 1.7.0_51-b13)   Java HotSpot(TM) 64-Bit Server VM (build 24.51-b03, mixed mode)
• OS:  Amazon Linux 3.2.12-3.2.4.amzn1.x86_64
• MongoDB:  2.4.6 (hosted on another box)

POM

Here are some of the managed dependencies from our POM:

0.2.8

2.2.2

14.0.1

1.8

3.2.1

1.1

1.7

2.1

3.2.4

4.2.5

1.7.1

1.5

1.7.2

3.2.3.RELEASE        1.6.2.RELEASE

1.4.2.RELEASE

1.3.2.RELEASE

3.1.4.RELEASE

2.11.3

1.0.13