Deadlock on "waitForValue"

[gissuebot]

From SmokejumperIT on November 29, 2013 14:58:27

This is using Guice 3.0. When we have multiple injections of the same class happening at the same time, I'm encountering a deadlock here:

   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:503)
        at com.google.inject.internal.util.$MapMaker$StrategyImpl.waitForValue(MapMaker.java:529)
        - locked <0x00000000ea6f4248> (a com.google.inject.internal.util.$MapMaker$LinkedStrongEntry)
        at com.google.inject.internal.util.$MapMaker$StrategyImpl$FutureValueReference.waitForValue(MapMaker.java:619)
        at com.google.inject.internal.util.$MapMaker$StrategyImpl.waitForValue(MapMaker.java:533)
        at com.google.inject.internal.util.$MapMaker$StrategyImpl.waitForValue(MapMaker.java:419)
        at com.google.inject.internal.util.$CustomConcurrentHashMap$ComputingImpl.get(CustomConcurrentHashMap.java:2061)
        at com.google.inject.internal.FailableCache.get(FailableCache.java:50)
        at com.google.inject.internal.MembersInjectorStore.get(MembersInjectorStore.java:65)
        at com.google.inject.internal.InjectorImpl.getMembersInjector(InjectorImpl.java:950)
        at com.google.inject.internal.InjectorImpl.getMembersInjector(InjectorImpl.java:957)
        at com.google.inject.internal.InjectorImpl.injectMembers(InjectorImpl.java:943)

If there's any more information that I can provide to you, let me know.

I'm going to try updating to 4.0-beta to see if that solves the problem.

I did a cursory look of the open issues, and didn't see the bug. If it's a duplicate, please just let me know what the duplicated issue is.

Thanks!

(BTW, love Guice. Makes DI not suck, which is always a nice touch.)

Original issue: http://code.google.com/p/google-guice/issues/detail?id=785

[gissuebot]

From eiden@no-cache.net on December 01, 2013 11:24:07

Here is a test that demonstrates the deadlock

    class DeadlockingModule extends AbstractModule {

        @Override
        protected void configure() {
            bind(new TypeLiteral<Deadlock<String>>() {}).toInstance(new Deadlock<String>());
        }

        static class Deadlock<T> {
            @Inject MembersInjector<Deadlock<String>> deadlock;
        }
    }

[gissuebot]

From SmokejumperIT on December 05, 2013 11:13:52

Still fails in 4.0-beta.

[gissuebot]

From sberlin on December 05, 2013 11:27:56

Before I dig in... in that test-case, what would you expect the behavior to be?
 1) It injects a "memberInjector" that isn't ready until the injector has finished (e.g, using it too early will fail)
or 2) It just fails

[gissuebot]

From SmokejumperIT on December 05, 2013 12:30:50

I'd prefer #1, would accept #2, and would be happy with anything that didn't just hang my server indefinitely. :D

[gissuebot]

From sberlin on December 05, 2013 13:54:38

In the latest HEAD version, I get this failure:

com.google.common.util.concurrent.UncheckedExecutionException: com.google.common.util.concurrent.UncheckedExecutionException: java.lang.IllegalStateException: Recursive load
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2203)
        at com.google.common.cache.LocalCache.get(LocalCache.java:3952)
        at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3956)
        at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4828)
        at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4834)
        at com.google.inject.internal.FailableCache.get(FailableCache.java:48)
        at com.google.inject.internal.MembersInjectorStore.get(MembersInjectorStore.java:66)
        at com.google.inject.internal.Initializer$InjectableReference.validate(Initializer.java:140)
        at com.google.inject.internal.Initializer.validateOustandingInjections(Initializer.java:91)
        at com.google.inject.internal.InternalInjectorCreator.initializeStatically(InternalInjectorCreator.java:140)
        at com.google.inject.internal.InternalInjectorCreator.build(InternalInjectorCreator.java:107)
        at com.google.inject.Guice.createInjector(Guice.java:99)
        at com.google.inject.Guice.createInjector(Guice.java:73)
        at com.google.inject.Guice.createInjector(Guice.java:62)
        at com.google.inject.MembersInjectorTest.testInjectIntoItself(MembersInjectorTest.java:255)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at junit.framework.TestCase.runTest(TestCase.java:168)
        at junit.framework.TestCase.runBare(TestCase.java:134)
        at junit.framework.TestResult$1.protect(TestResult.java:110)
        at junit.framework.TestResult.runProtected(TestResult.java:128)
        at junit.framework.TestResult.run(TestResult.java:113)
        at junit.framework.TestCase.run(TestCase.java:124)
        at junit.framework.TestSuite.runTest(TestSuite.java:244)
        at junit.framework.TestSuite.run(TestSuite.java:239)
        at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:83)
        at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)
        at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
        at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)
        at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)
        at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)
        at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)
Caused by: com.google.common.util.concurrent.UncheckedExecutionException: java.lang.IllegalStateException: Recursive load
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2203)
        at com.google.common.cache.LocalCache.get(LocalCache.java:3952)
        at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3956)
        at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4828)
        at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4834)
        at com.google.inject.internal.FailableCache.get(FailableCache.java:48)
        at com.google.inject.internal.MembersInjectorStore.get(MembersInjectorStore.java:66)
        at com.google.inject.internal.InjectorImpl.createMembersInjectorBinding(InjectorImpl.java:325)
        at com.google.inject.internal.InjectorImpl.createJustInTimeBinding(InjectorImpl.java:835)
        at com.google.inject.internal.InjectorImpl.createJustInTimeBindingRecursive(InjectorImpl.java:793)
        at com.google.inject.internal.InjectorImpl.getJustInTimeBinding(InjectorImpl.java:281)
        at com.google.inject.internal.InjectorImpl.getBindingOrThrow(InjectorImpl.java:213)
        at com.google.inject.internal.SingleFieldInjector.<init>(SingleFieldInjector.java:42)
        at com.google.inject.internal.MembersInjectorStore.getInjectors(MembersInjectorStore.java:127)
        at com.google.inject.internal.MembersInjectorStore.createWithListeners(MembersInjectorStore.java:96)
        at com.google.inject.internal.MembersInjectorStore.access$0(MembersInjectorStore.java:85)
        at com.google.inject.internal.MembersInjectorStore$1.create(MembersInjectorStore.java:43)
       &nb...

[gissuebot]

From sberlin on December 05, 2013 13:54:38

...sp;at com.google.inject.internal.MembersInjectorStore$1.create(MembersInjectorStore.java:1)
        at com.google.inject.internal.FailableCache$1.load(FailableCache.java:37)
        at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3541)
        at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319)
        at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282)
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197)
        ... 33 more
Caused by: java.lang.IllegalStateException: Recursive load
        at com.google.common.base.Preconditions.checkState(Preconditions.java:153)
        at com.google.common.cache.LocalCache$Segment.waitForLoadingValue(LocalCache.java:2299)
        at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2289)
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197)
        at com.google.common.cache.LocalCache.get(LocalCache.java:3952)
        at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3956)
        at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4828)
        at com.google.common.cache.LocalCache$LocalLoadingCache.getUnchecked(LocalCache.java:4834)
        at com.google.inject.internal.FailableCache.get(FailableCache.java:48)
        at com.google.inject.internal.MembersInjectorStore.get(MembersInjectorStore.java:66)
        at com.google.inject.internal.InjectorImpl.createMembersInjectorBinding(InjectorImpl.java:325)
        at com.google.inject.internal.InjectorImpl.createJustInTimeBinding(InjectorImpl.java:835)
        at com.google.inject.internal.InjectorImpl.createJustInTimeBindingRecursive(InjectorImpl.java:793)
        at com.google.inject.internal.InjectorImpl.getJustInTimeBinding(InjectorImpl.java:281)
        at com.google.inject.internal.InjectorImpl.getBindingOrThrow(InjectorImpl.java:213)
        at com.google.inject.internal.SingleFieldInjector.<init>(SingleFieldInjector.java:42)
        at com.google.inject.internal.MembersInjectorStore.getInjectors(MembersInjectorStore.java:127)
        at com.google.inject.internal.MembersInjectorStore.createWithListeners(MembersInjectorStore.java:96)
        at com.google.inject.internal.MembersInjectorStore.access$0(MembersInjectorStore.java:85)
        at com.google.inject.internal.MembersInjectorStore$1.create(MembersInjectorStore.java:43)
        at com.google.inject.internal.MembersInjectorStore$1.create(MembersInjectorStore.java:1)
        at com.google.inject.internal.FailableCache$1.load(FailableCache.java:37)
        at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3541)
        at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319)
        at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282)
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197)
        ... 55 more

Could you try building from HEAD and see if you also get that?  If you do, I'm inclined to close this as WontFix.

[gissuebot]

From SmokejumperIT on December 09, 2013 07:05:52

This change so that we're not hanging is a huge improvement: thank you! And the error message and stack traces are meaningful, which is also very useful. But can we get a slightly better error message, so that we know what the injection is deadlocking on?

If that works, then I think you could close it as fixed.

[gissuebot]

From sberlin on December 09, 2013 07:11:39

The best place for that change would be in Guava, I think... changing the "recursive load" exception to "Recursive load of key: <key>".  I'll bring it up with them and see what we can do.

[gissuebot]

From SmokejumperIT on December 23, 2013 06:42:36

Did you raise this as a ticket over on Guava? If not, I will.

[gissuebot]

From sameb@google.com on December 23, 2013 07:20:49

Yup, I fixed it internally, which looks like it got pushed out as https://code.google.com/p/guava-libraries/source/detail?r=2501cceb9f8059153cacda024843b8969e2851d8 and should be included in Guava v16 release. Oncwe we fix up the Guice deps to depend directly on guava instead embedding it, you should see the change.

[gissuebot]

From SmokejumperIT on January 09, 2014 13:50:45

I guess this wasn't as done as we hoped: our staging environment is still getting lock-ups within Guava intermittently, even though I'm using a HEAD version of this code. (I attached the SNAPSHOT jar that we are using.) I suspect it's the same issue, although it's now occurring at a different location.

(If it's not the same issue, I'll fork this and open a new one.)

In the attached stack dump, we're getting a thread (exec-18) which is parking to wait on com.google.inject.internal.guava.util.concurrent.$AbstractFuture$Sync (memory location 0x00000000ea36bcd0) -- condition 0x00007f6254ef0000 -- but I don't see anywhere that's locked. It is just sitting there forever, however, so it looks like some kind of permit bookkeeping has been messed up. That thread is also holding onto a lock of com.google.inject.internal.InheritingState (memory location 0x00000000ea036818), which is resulting in other threads also locking up.

The use case is a web server, where a single static injector is being used to construct the resources (read: "MVC controllers"), one per request, and so we're getting a lot of thread contention. Would a temporary work-around be to synchronize on the injector, so that it is only used once at a time?

Attachment: gist
   jstack_dump.log
Binary attachments: guice-4.0-SNAPSHOT.jar

[gissuebot]

From sberlin on January 09, 2014 14:11:04

I don't know if Guava released a version with the changes, and Guice definitely hasn't updated the version of Guava it uses yet.  So using head Guice won't have changed anything.

[gissuebot]

From sberlin on January 09, 2014 14:12:56

Ah, wait, sorry I was referring to if the recursive load exception happened, but it looks like you're saying you get deadlock instead of the exception still.

I'm not sure why that'd happen.  Does the testcase you posted earlier still result in this deadlock for you?  If not, can you try to come up with a new test-case that reproduces what you're seeing?

[gissuebot]

From SmokejumperIT on January 10, 2014 04:52:32

I'll see what I can pull together for you.

[gissuebot]

From SmokejumperIT on January 10, 2014 05:36:20

This'll do:

import java.util.concurrent.ExecutorService
import java.util.concurrent.Executors

import com.google.inject.Guice
import com.google.inject.Inject
import com.google.inject.Injector

class GuiceHanging {

        static class Injected {
        }

        static class Parent {
                @Inject Injected injectedToParent
        }

        static class Child1 {
                @Inject Injected injectedToChild1
        }

        static class Child2 {
                @Inject Injected injectedToChild2
                @Inject Child1 child1InChild2
        }

        static void main(String[] args) {
                Injector injector = Guice.createInjector()
                List<Runnable> toRun = []
                1000.times { int i ->
                        toRun << {
                                ->
                                println("Injecting members to Child1 #${i+1} > START")
                                injector.injectMembers(new Child1())
                                println("Injecting members to Child1 #${i+1} > END")
                        } as Runnable
                        toRun << {
                                ->
                                println("Injecting members to Child2 #${i+1} > START")
                                injector.injectMembers(new Child2())
                                println("Injecting members to Child2 #${i+1} > END")
                        } as Runnable
                }
                ExecutorService executor = Executors.newCachedThreadPool()
                try {
                        executor.invokeAll(toRun)*.get()
                        println("Successfully executed all the injections")
                } finally {
                        assert !executor.shutdownNow()
                }
        }
}