1586002 - [Interkitten] LifecycleOwner of this LifecycleRegistry is already garbage collected. It is too late to change lifecycle state.

Status: RESOLVED FIXED

(Data Platform and Tools :: Glean: SDK, defect, P3)

Description

[Alessio Placitelli [:Dexter]]

Looks like LifecycleRegistry is biting us, again. This time in tests, causing intermittent test rules.

[task 2019-10-03T14:39:29.935Z] TEST: test sending of background pings
[task 2019-10-03T14:39:29.935Z] [Robolectric] mozilla.components.service.glean.GleanTest.test sending of background pings: sdk=28; resources=legacy
[task 2019-10-03T14:39:29.935Z] [Robolectric] NOTICE: legacy resources mode is deprecated; see http://robolectric.org/migrating/#migrating-to-40
[task 2019-10-03T14:39:29.935Z] I/AssetManager: no overlays.list file found
[task 2019-10-03T14:39:29.935Z] I/MonitoringInstr: Instrumentation started!
[task 2019-10-03T14:39:29.935Z] I/MonitoringInstr: Setting context classloader to 'org.robolectric.internal.bytecode.SandboxClassLoader@26cae7d0', Original: 'org.robolectric.internal.bytecode.SandboxClassLoader@26cae7d0'
[task 2019-10-03T14:39:30.034Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.034Z] D/SQLiteCursor: received count() from native_fill_window: 1
[task 2019-10-03T14:39:30.034Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.034Z] D/SQLiteCursor: received count() from native_fill_window: 1
[task 2019-10-03T14:39:30.034Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.034Z] D/SQLiteCursor: received count() from native_fill_window: 0
[task 2019-10-03T14:39:30.034Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.034Z] D/SQLiteCursor: received count() from native_fill_window: 0
[task 2019-10-03T14:39:30.034Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.035Z] D/SQLiteCursor: received count() from native_fill_window: 0
[task 2019-10-03T14:39:30.035Z] I [glean/Glean] Metrics enabled: true
[task 2019-10-03T14:39:30.035Z] I [glean/Glean] Registering pings for mozilla.components.service.glean.GleanMetrics.Pings
[task 2019-10-03T14:39:30.035Z] Oct 03, 2019 2:39:29 PM okhttp3.mockwebserver.MockWebServer$2 execute
[task 2019-10-03T14:39:30.035Z] INFO: MockWebServer[60677] starting to accept connections
[task 2019-10-03T14:39:30.035Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.035Z] D/SQLiteCursor: received count() from native_fill_window: 1
[task 2019-10-03T14:39:30.035Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.035Z] D/SQLiteCursor: received count() from native_fill_window: 1
[task 2019-10-03T14:39:30.035Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.035Z] D/SQLiteCursor: received count() from native_fill_window: 0
[task 2019-10-03T14:39:30.035Z] I/CursorWindowStats: Created a new Cursor. # Open Cursors=1 (# cursors opened by this proc=1)
[task 2019-10-03T14:39:30.035Z] D/SQLiteCursor: received count(*) from native_fill_window: 0
[task 2019-10-03T14:39:30.035Z] I [glean/Glean] Metrics enabled: true
[task 2019-10-03T14:39:30.035Z] I [glean/Glean] Registering pings for mozilla.components.service.glean.GleanMetrics.Pings
[task 2019-10-03T14:39:30.134Z] W/SQLiteConnectionPool: A SQLiteConnection object for database ':memory:' was leaked! Please fix your application to end transactions in progress properly and to close the database when it is no longer needed.
[task 2019-10-03T14:39:30.134Z] Oct 03, 2019 2:39:30 PM okhttp3.mockwebserver.MockWebServer$2 acceptConnections
[task 2019-10-03T14:39:30.134Z] INFO: MockWebServer[60677] done accepting connections: Socket closed
[task 2019-10-03T14:39:30.134Z] FAILURE
[task 2019-10-03T14:39:30.134Z]
[task 2019-10-03T14:39:30.135Z] java.lang.IllegalStateException: LifecycleOwner of this LifecycleRegistry is alreadygarbage collected. It is too late to change lifecycle state.
[task 2019-10-03T14:39:30.135Z] at androidx.lifecycle.LifecycleRegistry.sync(LifecycleRegistry.java:327)
[task 2019-10-03T14:39:30.135Z] at androidx.lifecycle.LifecycleRegistry.moveToState(LifecycleRegistry.java:145)
[task 2019-10-03T14:39:30.135Z] at androidx.lifecycle.LifecycleRegistry.handleLifecycleEvent(LifecycleRegistry.java:131)
[task 2019-10-03T14:39:30.135Z] at mozilla.components.service.glean.GleanTest.test sending of background pings(GleanTest.kt:149)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2019-10-03T14:39:30.135Z] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2019-10-03T14:39:30.135Z] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2019-10-03T14:39:30.135Z] at org.robolectric.RobolectricTestRunner$HelperTestRunner$1.evaluate(RobolectricTestRunner.java:601)
[task 2019-10-03T14:39:30.135Z] at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
[task 2019-10-03T14:39:30.135Z] at org.junit.rules.RunRules.evaluate(RunRules.java:20)
[task 2019-10-03T14:39:30.135Z] at org.robolectric.internal.SandboxTestRunner$2.evaluate(SandboxTestRunner.java:260)
[task 2019-10-03T14:39:30.135Z] at org.robolectric.internal.SandboxTestRunner.runChild(SandboxTestRunner.java:130)
[task 2019-10-03T14:39:30.135Z] at org.robolectric.internal.SandboxTestRunner.runChild(SandboxTestRunner.java:42)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
[task 2019-10-03T14:39:30.135Z] at org.robolectric.internal.SandboxTestRunner$1.evaluate(SandboxTestRunner.java:84)
[task 2019-10-03T14:39:30.135Z] at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
[task 2019-10-03T14:39:30.135Z] at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:110)
[task 2019-10-03T14:39:30.135Z] at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58)
[task 2019-10-03T14:39:30.135Z] at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38)
[task 2019-10-03T14:39:30.135Z] at org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:62)
[task 2019-10-03T14:39:30.135Z] at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
[task 2019-10-03T14:39:30.135Z] at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
[task 2019-10-03T14:39:30.135Z] at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:118)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:175)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:157)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
[task 2019-10-03T14:39:30.135Z] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[task 2019-10-03T14:39:30.135Z] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[task 2019-10-03T14:39:30.135Z] at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
[task 2019-10-03T14:39:30.135Z] at java.lang.Thread.run(Thread.java:748)

Comment 1

[Michael Droettboom [:mdroettboom]]

Attachment: GitHub Pull Request

Comment 2

[Michael Droettboom [:mdroettboom]]

Attachment: GitHub Pull Request

Comment 3

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/adfbc439f1b1
[components] 1586002: Fix intermittent test failure in Glean