Closed Bug 1654682 Opened 4 years ago Closed 3 years ago

Intermittent org.mozilla.geckoview.test.SessionLifecycleTest#asyncScriptsSuspendedWhileInactive | java.lang.AssertionError: requestAnimationFrame has not run yet

Categories

(GeckoView :: General, defect, P1)

Unspecified
All
defect

Tracking

(firefox87 fixed)

RESOLVED FIXED
87 Branch
Tracking Status
firefox87 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: agi)

Details

(Keywords: assertion, intermittent-failure, Whiteboard: [geckoview:m84][geckoview:m85][geckoview:m87][stockwell unknown])

Attachments

(1 file)

Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=310777739&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/d2gWMqdFRsWNqhHupHUh_A/runs/0/artifacts/public/logs/live_backing.log


[task 2020-07-22T22:33:40.626Z] 22:33:40 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2020-07-22T22:33:40.626Z] 22:33:40 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=asyncScriptsSuspendedWhileInactive
[task 2020-07-22T22:33:40.626Z] 22:33:40 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SessionLifecycleTest
[task 2020-07-22T22:33:40.627Z] 22:33:40 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2020-07-22T22:33:40.627Z] 22:33:40 INFO - org.mozilla.geckoview.test | Expected: <true>
[task 2020-07-22T22:33:40.627Z] 22:33:40 INFO - org.mozilla.geckoview.test | but: was <false>
[task 2020-07-22T22:33:40.627Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2020-07-22T22:33:40.627Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2020-07-22T22:33:40.628Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2020-07-22T22:33:40.628Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2020-07-22T22:33:40.628Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2020-07-22T22:33:40.629Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:801)
[task 2020-07-22T22:33:40.629Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:85)
[task 2020-07-22T22:33:40.629Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive(SessionLifecycleTest.kt:497)
[task 2020-07-22T22:33:40.629Z] 22:33:40 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2020-07-22T22:33:40.629Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2020-07-22T22:33:40.630Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2020-07-22T22:33:40.630Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2020-07-22T22:33:40.630Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2020-07-22T22:33:40.630Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1293)
[task 2020-07-22T22:33:40.630Z] 22:33:40 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$sIbRNaZJgAu-QrUVWSGD8JbPSWM.run(lambda)
[task 2020-07-22T22:33:40.631Z] 22:33:40 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2020-07-22T22:33:40.631Z] 22:33:40 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2020-07-22T22:33:40.631Z] 22:33:40 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2020-07-22T22:33:40.631Z] 22:33:40 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2020-07-22T22:33:40.631Z] 22:33:40 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2020-07-22T22:33:40.631Z] 22:33:40 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2020-07-22T22:33:40.632Z] 22:33:40 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2020-07-22T22:33:40.632Z] 22:33:40 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2020-07-22T22:33:40.632Z] 22:33:40 INFO - org.mozilla.geckoview.test |
[task 2020-07-22T22:33:40.632Z] 22:33:40 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=546
[task 2020-07-22T22:33:40.632Z] 22:33:40 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2020-07-22T22:33:40.633Z] 22:33:40 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive | java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2020-07-22T22:33:40.633Z] 22:33:40 INFO - TEST-INFO took 3013ms

Assignee: nobody → agi
Priority: P5 → P1
Whiteboard: [geckoview:m84]
Whiteboard: [geckoview:m84] → [geckoview:m84][geckoview:m85]

Looks like this is back being a low-volume intermittent, I'll keep monitoring for a bit.

Update:

There have been 35 failures within the last 7 days:

  • 10 failures on Android 7.0 x86-64 opt/debug
  • 13 failures on Android 7.0 x86-64 WebRender opt/debug
  • 6 failures on Android 7.0 x86-64 Shippable opt
  • 6 failures on Android 7.0 x86-64 Shippable WebRender opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=327543745&repo=autoland&lineNumber=11885

[task 2021-01-23T00:22:51.659Z] 00:22:51 INFO - TEST-START | org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive
[task 2021-01-23T00:22:54.022Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=778
[task 2021-01-23T00:22:54.023Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | Error in asyncScriptsSuspendedWhileInactive(org.mozilla.geckoview.test.SessionLifecycleTest):
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | Expected: <true>
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | but: was <false>
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-01-23T00:22:54.024Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:104)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive(SessionLifecycleTest.kt:143)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-01-23T00:22:54.025Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-01-23T00:22:54.026Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-01-23T00:22:54.026Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-01-23T00:22:54.026Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-01-23T00:22:54.026Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1313)
[task 2021-01-23T00:22:54.026Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$sIbRNaZJgAu-QrUVWSGD8JbPSWM.run(lambda)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-01-23T00:22:54.027Z] 00:22:54 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test |
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=asyncScriptsSuspendedWhileInactive
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SessionLifecycleTest
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | Expected: <true>
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | but: was <false>
[task 2021-01-23T00:22:54.028Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-01-23T00:22:54.029Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-01-23T00:22:54.029Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-01-23T00:22:54.029Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-01-23T00:22:54.029Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-01-23T00:22:54.029Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-01-23T00:22:54.029Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:104)
[task 2021-01-23T00:22:54.030Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive(SessionLifecycleTest.kt:143)
[task 2021-01-23T00:22:54.030Z] 00:22:54 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-01-23T00:22:54.030Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-01-23T00:22:54.030Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-01-23T00:22:54.030Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-01-23T00:22:54.030Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1313)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$sIbRNaZJgAu-QrUVWSGD8JbPSWM.run(lambda)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-01-23T00:22:54.031Z] 00:22:54 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-01-23T00:22:54.032Z] 00:22:54 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-01-23T00:22:54.032Z] 00:22:54 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-01-23T00:22:54.032Z] 00:22:54 INFO - org.mozilla.geckoview.test |
[task 2021-01-23T00:22:54.032Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=581
[task 2021-01-23T00:22:54.032Z] 00:22:54 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2021-01-23T00:22:54.033Z] 00:22:54 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive | java.lang.AssertionError: requestAnimationFrame has not run yet

Whiteboard: [geckoview:m84][geckoview:m85] → [geckoview:m84][geckoview:m85][stockwell needswork]

In the last 7 days there have been 36 occurrences, all on android-em-7-0-x86 opt and debug.

Recent failure: https://treeherder.mozilla.org/logviewer?job_id=328396892&repo=autoland&lineNumber=11891

Emily, could you, please, take a look and assign this to the appropriate person if needed?

Whiteboard: [geckoview:m84][geckoview:m85][stockwell needswork] → [geckoview:m84][geckoview:m85][stockwell needswork][geckoview:m87]

There are 36 total failures in the last 7 days on

  • android-em-7-0-x86_64 debug and opt
  • android-em-7-0-x86_64-qr debug and opt
  • android-em-7-0-x86_64-shippable-qr opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=329940565&repo=autoland&lineNumber=12584

[task 2021-02-14T14:51:21.444Z] 14:51:21 INFO - TEST-START | org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive
[task 2021-02-14T14:51:27.129Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=780
[task 2021-02-14T14:51:27.129Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-02-14T14:51:27.129Z] 14:51:27 INFO - org.mozilla.geckoview.test | Error in asyncScriptsSuspendedWhileInactive(org.mozilla.geckoview.test.SessionLifecycleTest):
[task 2021-02-14T14:51:27.129Z] 14:51:27 INFO - org.mozilla.geckoview.test | java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2021-02-14T14:51:27.129Z] 14:51:27 INFO - org.mozilla.geckoview.test | Expected: <true>
[task 2021-02-14T14:51:27.130Z] 14:51:27 INFO - org.mozilla.geckoview.test | but: was <false>
[task 2021-02-14T14:51:27.130Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-02-14T14:51:27.130Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-02-14T14:51:27.130Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-02-14T14:51:27.130Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-02-14T14:51:27.130Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-02-14T14:51:27.131Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-02-14T14:51:27.131Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:105)
[task 2021-02-14T14:51:27.131Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive(SessionLifecycleTest.kt:143)
[task 2021-02-14T14:51:27.131Z] 14:51:27 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-02-14T14:51:27.131Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-02-14T14:51:27.131Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-02-14T14:51:27.132Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-02-14T14:51:27.132Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-02-14T14:51:27.132Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1313)
[task 2021-02-14T14:51:27.132Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$sIbRNaZJgAu-QrUVWSGD8JbPSWM.run(lambda)
[task 2021-02-14T14:51:27.132Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-02-14T14:51:27.132Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test |
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2021-02-14T14:51:27.133Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=asyncScriptsSuspendedWhileInactive
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SessionLifecycleTest
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | Expected: <true>
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | but: was <false>
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-02-14T14:51:27.134Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:105)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive(SessionLifecycleTest.kt:143)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-02-14T14:51:27.135Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1313)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$sIbRNaZJgAu-QrUVWSGD8JbPSWM.run(lambda)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-02-14T14:51:27.136Z] 14:51:27 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test |
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=583
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2021-02-14T14:51:27.137Z] 14:51:27 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive | java.lang.AssertionError: requestAnimationFrame has not run yet
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - TEST-INFO took 5687ms
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=780
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=restoreRuntimeSettings_noSession
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SessionLifecycleTest
[task 2021-02-14T14:51:27.137Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=584
[task 2021-02-14T14:51:27.138Z] 14:51:27 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
Agi are there updates here?

Flags: needinfo?(agi)
Whiteboard: [geckoview:m84][geckoview:m85][stockwell needswork][geckoview:m87] → [geckoview:m84][geckoview:m85][stockwell needswork:owner][geckoview:m87]

I think this test works by accident right now (it's trying to assert that we don't call requestAnimationFrame when suspended, but that's wrong, we do call rAF, albeit at a reduced rate). Patch incoming

Flags: needinfo?(agi)

asyncScriptsSuspendedWhileInactive expects requestAnimationFrame to not trigger
at all when the tab is suspended. This is not the case however, rAF triggers
about once a second when the tab is suspended.

This patch accounts for that by computing the rAF rate, when suspended it
asserts that it's 500ms < rAF rate < 10s, while when not suspended it asserts
it's 5ms < rAF rate < 50ms (expected 16.6ms).

Pushed by asferro@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/37bb1eef5ade
Account for throttled rAF rate in asyncScriptsSuspendedWhileInactive. r=esawin
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 87 Branch

No failures since it landed \o/

6c6f5da9-bf33-4082-a19d-7d99e8083d97 Mass rename intermittents due to Bug 1723034.

Summary: Intermittent org.mozilla.geckoview.test.SessionLifecycleTest.asyncScriptsSuspendedWhileInactive | java.lang.AssertionError: requestAnimationFrame has not run yet → Intermittent org.mozilla.geckoview.test.SessionLifecycleTest#asyncScriptsSuspendedWhileInactive | java.lang.AssertionError: requestAnimationFrame has not run yet
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: