Closed Bug 1678120 Opened 4 years ago Closed 3 years ago

Intermittent org.mozilla.geckoview.test.PanZoomControllerTest#touchEventForResultWithPreventDefault | java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html

Categories

(Core :: Panning and Zooming, defect)

Unspecified
All
defect

Tracking

()

RESOLVED DUPLICATE of bug 1678895

People

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

Details

(Keywords: assertion, intermittent-failure, Whiteboard: [stockwell disable-recommended])

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


[task 2020-11-18T20:07:46.770Z] 20:07:46     INFO -  TEST-START | org.mozilla.geckoview.test.PanZoomControllerTest.touchEventForResultWithPreventDefault
[task 2020-11-18T20:07:48.014Z] 20:07:48     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html
[task 2020-11-18T20:07:48.014Z] 20:07:48     INFO -  org.mozilla.geckoview.test | Expected: <2>
[task 2020-11-18T20:07:48.014Z] 20:07:48     INFO -  org.mozilla.geckoview.test |      but: was <1>
[task 2020-11-18T20:07:48.014Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.Assert.assertThat(Assert.java:956)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:104)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.touchEventForResultWithPreventDefault(PanZoomControllerTest.kt:431)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at java.lang.reflect.Method.invoke(Native Method)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2020-11-18T20:07:48.015Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1313)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$sIbRNaZJgAu-QrUVWSGD8JbPSWM.run(lambda)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at android.os.Looper.loop(Looper.java:154)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at java.lang.reflect.Method.invoke(Native Method)
[task 2020-11-18T20:07:48.016Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2020-11-18T20:07:48.018Z] 20:07:48     INFO -  org.mozilla.geckoview.test | 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2020-11-18T20:07:48.018Z] 20:07:48     INFO -  org.mozilla.geckoview.test |
[task 2020-11-18T20:07:48.018Z] 20:07:48     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=400
[task 2020-11-18T20:07:48.018Z] 20:07:48     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
[task 2020-11-18T20:07:48.018Z] 20:07:48  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PanZoomControllerTest.touchEventForResultWithPreventDefault | java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html
[task 2020-11-18T20:07:48.018Z] 20:07:48     INFO -  TEST-INFO took 1245ms```

resetting priority so we can evaluate at triage

Priority: P5 → --

Has anyone made any changes recently that could be causing these spikes in failures?

Component: General → Panning and Zooming
Product: GeckoView → Core

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

Summary: Intermittent org.mozilla.geckoview.test.PanZoomControllerTest.touchEventForResultWithPreventDefault | java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html → Intermittent org.mozilla.geckoview.test.PanZoomControllerTest#touchEventForResultWithPreventDefault | java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html

I pushed to try based on an m-c revision each day from July 10 to July 30 and retriggered these tests, I haven't been able to determine any pattern at when these became more frequent.

Update:
There have been 76 failures within the last 7 days:
• 1 failures on android-em-7-0-x86_64-lite-qr opt
• 26 failures on android-em-7-0-x86_64-lite-qr debug
• 1 failures on Android 7.0 x86-64 WebRender opt
• 24 failures on Android 7.0 x86-64 WebRender debug-isolated-process
• 24 failures on Android 7.0 x86-64 WebRender debug
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=347594383&repo=autoland&lineNumber=9599

[task 2021-08-06T00:51:43.012Z] 00:51:43     INFO -  TEST-START | org.mozilla.geckoview.test.PanZoomControllerTest#touchEventForResultWithPreventDefault
[task 2021-08-06T00:51:44.478Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=796
[task 2021-08-06T00:51:44.479Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-08-06T00:51:44.479Z] 00:51:44     INFO -  org.mozilla.geckoview.test | Error in touchEventForResultWithPreventDefault(org.mozilla.geckoview.test.PanZoomControllerTest):
[task 2021-08-06T00:51:44.479Z] 00:51:44     INFO -  org.mozilla.geckoview.test | java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html
[task 2021-08-06T00:51:44.479Z] 00:51:44     INFO -  org.mozilla.geckoview.test | Expected: <2>
[task 2021-08-06T00:51:44.479Z] 00:51:44     INFO -  org.mozilla.geckoview.test |      but: was <1>
[task 2021-08-06T00:51:44.480Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-08-06T00:51:44.480Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-08-06T00:51:44.480Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-08-06T00:51:44.480Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-08-06T00:51:44.481Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-08-06T00:51:44.481Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:824)
[task 2021-08-06T00:51:44.481Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:115)
[task 2021-08-06T00:51:44.481Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.PanZoomControllerTest.touchEventForResultWithPreventDefault(PanZoomControllerTest.kt:432)
[task 2021-08-06T00:51:44.482Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at java.lang.reflect.Method.invoke(Native Method)
[task 2021-08-06T00:51:44.482Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-08-06T00:51:44.482Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-08-06T00:51:44.482Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-08-06T00:51:44.482Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-08-06T00:51:44.483Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1315)
[task 2021-08-06T00:51:44.483Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$cmP_QJg-X16GIlt8KIQd32egmfU.run(lambda)
[task 2021-08-06T00:51:44.483Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-08-06T00:51:44.483Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-08-06T00:51:44.484Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-08-06T00:51:44.484Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at android.os.Looper.loop(Looper.java:154)
[task 2021-08-06T00:51:44.484Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-08-06T00:51:44.484Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at java.lang.reflect.Method.invoke(Native Method)
[task 2021-08-06T00:51:44.485Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-08-06T00:51:44.485Z] 00:51:44     INFO -  org.mozilla.geckoview.test | 	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-08-06T00:51:44.485Z] 00:51:44     INFO -  org.mozilla.geckoview.test |
[task 2021-08-06T00:51:44.485Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
<...>
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.134 D/GeckoViewProgress( 3392): receiveMessage: MozAfterPaint
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.150 D/GeckoViewConsole( 3392): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"b7c7f945-a9a6-4953-9e8b-e27da8a261dd","args":{},"type":"FlushApzRepaints"}}
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.156 D/GeckoViewTestSupport[C](16224): receiveMessage: FlushApzRepaints
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.157 D/GeckoViewTestSupport[C](16224): Flushed APZ repaints, waiting for callback...
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.158 D/GeckoViewTestSupport[C](16224): APZ flush done
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.165 E/GeckoSessionTestRule( 3392): after evaluate
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.165 E/GeckoSessionTestRule( 3392): after performTestEndCheck
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.166 D/EGL_emulation( 3392): eglMakeCurrent: 0x72d01118f160: ver 3 0 (tinfo 0x72d0110db720)
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.167 D/GeckoViewContent( 3392): handleEvent: DOMWindowClose
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.168 D/GeckoViewProgressDelegate[C](16224): handleEvent: MozAfterPaint
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.168 D/GeckoViewConsole( 3392): onEvent GeckoView:WebExtension:List null
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.172 I/Gecko   ( 3392): nsWindow[0x72cfd6d33000]::Show 0
[task 2021-08-06T00:51:44.648Z] 00:51:44     INFO -  08-06 00:51:44.173 E/GeckoSessionTestRule( 3392): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 touchEventForResultWithPreventDefault(org.mozilla.geckoview.test.PanZoomControllerTest)
[task 2021-08-06T00:51:44.649Z] 00:51:44  WARNING -  TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.PanZoomControllerTest#touchEventForResultWithPreventDefault | java.lang.AssertionError: The input result should be HANDLED_CONTENT in /assets/www/iframe_98vh_scrollable.html
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  TEST-INFO took 1578ms
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=796
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=scrollToHorizontalAuto
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.PanZoomControllerTest
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=400
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: 1
[task 2021-08-06T00:51:44.649Z] 00:51:44     INFO -  TEST-START | org.mozilla.geckoview.test.PanZoomControllerTest#scrollToHorizontalAuto
Whiteboard: [stockwell needswork:owner]

Botond, as the owner of this component, could you help us assign it to someone?
Thank you.

Flags: needinfo?(botond)

Redirecting, similar to bug 1678895

Flags: needinfo?(botond) → needinfo?(hikezoe.birchill)

I haven't been able to reproduce both failures locally (rather I often get timeout), my wild guess is that something has been changed related to page load timing (more specific to this test case, it's first-contentful-paint timing), as a result the test in question starts running before we set a callback to prevent events.

Assignee: nobody → hikezoe.birchill
Status: NEW → ASSIGNED

This will be fixed by bug 1678895.

Flags: needinfo?(hikezoe.birchill)
See Also: → 1678895
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → DUPLICATE
See Also: 1678895
You need to log in before you can comment on or make changes to this bug.