Intermittent org.mozilla.geckoview.test.SelectionActionDelegateTest#collapseToEnd[#textarea] | java.lang.AssertionError: Selection offsets should match
Categories
(GeckoView :: General, defect, P5)
Tracking
(firefox93 wontfix, firefox94 wontfix, firefox95 fixed)
People
(Reporter: intermittent-bug-filer, Assigned: hiro)
References
Details
(Keywords: assertion, intermittent-failure)
Attachments
(1 file)
Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=332287490&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UDD_N9PFT9Ck-TGgchrpag/runs/0/artifacts/public/logs/live_backing.log
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.358 D/GeckoViewConsole( 3142): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"988846a2-28f6-4f2e-a1b9-8528ac05df69","eval":"document.querySelector('#textarea').focus()"}}
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.363 D/GeckoViewAutofill[C]( 4254): handleEvent: focusin
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.365 D/GeckoViewConsole( 3142): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"3bbe9137-ad67-4f06-8a6c-a99f2bf7d957","args":{"oldPrefs":{},"newPrefs":{"geckoview.selection_action.show_on_focus":true,"layout.accessiblecaret.script_change_update_mode":2}},"type":"SetPrefs"}}
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.368 D/GeckoViewConsole( 3142): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"3b454797-f00d-4a58-b508-4cab07ef8b49","eval":"document.querySelector('#textarea').select()"}}
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.374 D/GeckoViewContentDelegateChild[C]( 4254): handleEvent: MozFirstContentfulPaint
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.375 D/GeckoViewContentDelegateChild[C]( 4254): handleEvent: MozFirstContentfulPaint
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.375 D/GeckoViewSelectionActionDelegate[C]( 4254): handleEvent: updateposition
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.377 D/GeckoViewContent[C]( 4254): handleEvent: mozcaretstatechanged
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.377 D/GeckoViewSelectionActionDelegate[C]( 4254): handleEvent: updateposition
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.379 D/GeckoViewConsole( 3142): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"17864619-1fdf-41ab-bb49-1aa0b2bb72a0","eval":"[ document.querySelector('#textarea').selectionStart,\ndocument.querySelector('#textarea').selectionEnd ]"}}
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.379 D/GeckoViewContent[C]( 4254): handleEvent: mozcaretstatechanged
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.380 D/GeckoViewSelectionActionDelegate[C]( 4254): handleEvent: updateposition
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.382 D/GeckoViewContent[C]( 4254): handleEvent: mozcaretstatechanged
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.383 W/GeckoViewSelectionActionDelegate[C]( 4254): Stale response org.mozilla.geckoview.COLLAPSE_TO_END
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.385 E/GeckoSessionTestRule( 3142): after evaluate
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.385 D/GeckoViewConsole( 3142): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"4b4d74e0-2391-4bc9-a8aa-0db0593adb52","args":{"oldPrefs":{"geckoview.selection_action.show_on_focus":null,"layout.accessiblecaret.script_change_update_mode":1}},"type":"RestorePrefs"}}
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.386 E/eglCodecCommon( 3142): glUtilsParamSize: unknow param 0x00008caa
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.388 D/GeckoViewScrollDelegate[C]( 4254): handleEvent: mozvisualscroll
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.388 E/GeckoSessionTestRule( 3142): after performTestEndCheck
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.406 D/EGL_emulation( 3142): eglMakeCurrent: 0x7e18a0f619a0: ver 3 0 (tinfo 0x7e18a0f6bc20)
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.407 D/GeckoViewContent( 3142): handleEvent: DOMWindowClose
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.408 D/GeckoViewConsole( 3142): onEvent GeckoView:WebExtension:List null
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.409 D/GeckoViewProgressDelegate[C]( 4254): handleEvent: MozAfterPaint
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - 03-06 22:51:08.409 E/GeckoSessionTestRule( 3142): test_end c5ee677f-bc83-49bd-9e28-2d35f3d0f059 collapseToEnd[#textarea](org.mozilla.geckoview.test.SelectionActionDelegateTest)
[task 2021-03-06T22:51:09.223Z] 22:51:09 WARNING - TEST-UNEXPECTED-FAIL | org.mozilla.geckoview.test.SelectionActionDelegateTest.collapseToEnd[#textarea] | java.lang.AssertionError: Selection offsets should match
[task 2021-03-06T22:51:09.223Z] 22:51:09 INFO - TEST-INFO took 368ms```
Comment 1•4 years ago
|
||
After:
[task 2021-03-06T22:51:08.835Z] 22:51:08 INFO - TEST-START | org.mozilla.geckoview.test.SelectionActionDelegateTest.collapseToEnd[#textarea]
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: numtests=795
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stream=
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | Error in collapseToEnd[#textarea](org.mozilla.geckoview.test.SelectionActionDelegateTest):
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | java.lang.AssertionError: Selection offsets should match
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | Expected: <(5, 5)>
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | but: was <(0, 5)>
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-03-06T22:51:09.043Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:111)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$hasSelectionAt$1.invoke(SelectionActionDelegateTest.kt:486)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$hasSelectionAt$1.invoke(SelectionActionDelegateTest.kt:34)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.testThat(SelectionActionDelegateTest.kt:242)
[task 2021-03-06T22:51:09.044Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$testThat(SelectionActionDelegateTest.kt:34)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$collapseToEnd$1.invoke(SelectionActionDelegateTest.kt:157)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$collapseToEnd$1.invoke(SelectionActionDelegateTest.kt:34)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.assumingEditable(SelectionActionDelegateTest.kt:319)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.collapseToEnd(SelectionActionDelegateTest.kt:156)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-03-06T22:51:09.045Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1317)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$cmP_QJg-X16GIlt8KIQd32egmfU.run(lambda)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-03-06T22:51:09.046Z] 22:51:09 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test |
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: id=AndroidJUnitRunner
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: test=collapseToEnd[#textarea]
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: class=org.mozilla.geckoview.test.SelectionActionDelegateTest
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: stack=java.lang.AssertionError: Selection offsets should match
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | Expected: <(5, 5)>
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | but: was <(0, 5)>
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.Assert.assertThat(Assert.java:956)
[task 2021-03-06T22:51:09.047Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector$1.call(ErrorCollector.java:65)
[task 2021-03-06T22:51:09.049Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkSucceeds(ErrorCollector.java:78)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.rules.ErrorCollector.checkThat(ErrorCollector.java:63)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule.checkThat(GeckoSessionTestRule.java:826)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.BaseSessionTest.assertThat(BaseSessionTest.kt:111)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$hasSelectionAt$1.invoke(SelectionActionDelegateTest.kt:486)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$hasSelectionAt$1.invoke(SelectionActionDelegateTest.kt:34)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.testThat(SelectionActionDelegateTest.kt:242)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.access$testThat(SelectionActionDelegateTest.kt:34)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$collapseToEnd$1.invoke(SelectionActionDelegateTest.kt:157)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest$collapseToEnd$1.invoke(SelectionActionDelegateTest.kt:34)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.assumingEditable(SelectionActionDelegateTest.kt:319)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.SelectionActionDelegateTest.collapseToEnd(SelectionActionDelegateTest.kt:156)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.GeckoSessionTestRule$2.lambda$evaluate$0$GeckoSessionTestRule$2(GeckoSessionTestRule.java:1317)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at org.mozilla.geckoview.test.rule.-$$Lambda$GeckoSessionTestRule$2$cmP_QJg-X16GIlt8KIQd32egmfU.run(lambda)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.app.Instrumentation$SyncRunnable.run(Instrumentation.java:1950)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.os.Handler.handleCallback(Handler.java:751)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.os.Handler.dispatchMessage(Handler.java:95)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.os.Looper.loop(Looper.java:154)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at android.app.ActivityThread.main(ActivityThread.java:6077)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at java.lang.reflect.Method.invoke(Native Method)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:866)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:756)
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test |
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS: current=520
[task 2021-03-06T22:51:09.050Z] 22:51:09 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_STATUS_CODE: -2
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 17•3 years ago
|
||
6c6f5da9-bf33-4082-a19d-7d99e8083d97 Mass rename intermittents due to Bug 1723034.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 29•3 years ago
|
||
Dropping bug 1730998 from the regression field, instead adding bug 1730998 to the blocker instead.
Bug 1730998 makes this failure more frequent. Bug 1730998 raises PAPZ.RequestContentRepaint priority. Anyways there's a race condition in the first place in SelectionActionDelegateChild.jsm.
From a failure log
[task 2021-10-03T10:29:39.215Z] 10:29:39 INFO - 10-03 10:29:38.356 D/GeckoViewSelectionActionDelegateC: handleEvent: updateposition
[task 2021-10-03T10:29:39.215Z] 10:29:39 INFO - 10-03 10:29:38.359 D/GeckoViewContentC: handleEvent: mozcaretstatechanged
[task 2021-10-03T10:29:39.215Z] 10:29:39 INFO - 10-03 10:29:38.359 D/GeckoViewSelectionActionDelegateC: handleEvent: updateposition
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.361 D/GeckoViewConsole( 3456): onEvent GeckoView:WebExtension:PortMessageFromApp {"message":{"id":"4d7f6ef1-27e3-4cb7-b4ce-828619b889a5","eval":"[ document.querySelector('#textarea').selectionStart,\ndocument.querySelector('#textarea').selectionEnd ]"}}
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.361 D/GeckoViewContentC: handleEvent: mozcaretstatechanged
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.361 D/GeckoViewSelectionActionDelegateC: handleEvent: updateposition
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.363 D/GeckoViewContentC: handleEvent: mozcaretstatechanged
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.363 D/GeckoViewProgressDelegateC: handleEvent: MozAfterPaint
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.364 D/GeckoViewProgress( 3456): receiveMessage: MozAfterPaint
[task 2021-10-03T10:29:39.216Z] 10:29:39 INFO - 10-03 10:29:38.365 W/GeckoViewSelectionActionDelegateC: Stale response org.mozilla.geckoview.COLLAPSE_TO_END
There are three "handleEvent: updateposition"s, thus we hit this condition, then the COLLAPSE_TO_END action wasn't properly handled.
Bug 1730998 raises this racy chance. CCing Agi and Ting-Yu.
Assignee | ||
Comment 30•3 years ago
|
||
Now I am mostly 100% sure this is an issue in the test SelectionActionDelegateTest.kt itself. The issue is this delegateDuringNextWait call. As I noted in comment 29, there are multiple "updateposition" events, thus this test needs to call this respondingWith() until the responding action is surely processed.
Honestly I am totally unfamiliar with our GeckoView Junit framework, so I don't have any idea for doing it. (I don't think it can be done without changing SelectionActionDelegateChild.jsm).
A workaround I can think of is, the multiple "updateposition" events are fired in response to scroll operations triggered by this focus() (because it involves a scrollIntoView operation). Avoiding the scroll operations should fix this intermittent.
There are two ways to avoid the scroll operations;
- Setting
<meta name="viewport" content="width=device-width,initial-scale=0.25">
in inputs.html to avoid overflow contents (this is what I tried in 1730998 comment 19) - Setting a bigger displaysize instead of (100, 100) to avoid overflow
Agi, would either one be acceptable fix here?
Comment 31•3 years ago
|
||
So if I understand correctly the issue here is that, because we have to scroll, the test gets confused about which events are fired in response to .focus()
? The thing I'm confused about is, why are we getting a "stale" event here: Stale response org.mozilla.geckoview.COLLAPSE_TO_END
? Does that mean that the event would be ignored if a user was using the browser?
In general either options would be good (slight preference for 2.) if the bug is not really reproducible on people's phones, which I think it's not, but i don't understand why yet.
Assignee | ||
Comment 32•3 years ago
|
||
(In reply to Agi Sferro | :agi | ni? for questions | ⏰ PST | he/him from comment #31)
So if I understand correctly the issue here is that, because we have to scroll, the test gets confused about which events are fired in response to
.focus()
? The thing I'm confused about is, why are we getting a "stale" event here:Stale response org.mozilla.geckoview.COLLAPSE_TO_END
? Does that mean that the event would be ignored if a user was using the browser?
That's a good question. IIUC relevant code, in producation code, this BasicSelectionActionDelegate keeps responding unlike the test does a single shot, isn't it? Of course if a GeckoView embedder does the same manner as what the test does, the same issue will happen there though.
Assignee | ||
Comment 33•3 years ago
|
||
(In reply to Hiroyuki Ikezoe (:hiro) from comment #32)
(In reply to Agi Sferro | :agi | ni? for questions | ⏰ PST | he/him from comment #31)
So if I understand correctly the issue here is that, because we have to scroll, the test gets confused about which events are fired in response to
.focus()
? The thing I'm confused about is, why are we getting a "stale" event here:Stale response org.mozilla.geckoview.COLLAPSE_TO_END
? Does that mean that the event would be ignored if a user was using the browser?That's a good question. IIUC relevant code, in producation code, this BasicSelectionActionDelegate keeps responding unlike the test does a single shot, isn't it?
hmm, there may be a race condition where an action would be ignored (it's slightly different from this intermittent failure cause though). So, say
- SelectionActionDelegateChild.jsm received a "updateposition"
- SelectionActionDelegateChild.jsm received a different event, say "releasecaret"
- SelectionActionDelegateChild.jsm received another "updateposition"
If all these happened before BasicSelectionActionDelegate responds it, the "releasecaret" event will be lost. Though I am not sure these cases will surely happen or not, it depends on our AccesibleCaret implementation. (Probably Ting-Yu can answer it, he's in CC)
Agi, do you want me to open a new bug for the possible race condition? Would it be ok to tweak SelectionActionDelegateTest.kt as what I suggested in comment 30? We'd like to land bug 1730998 since it's one of our top priority items.
Thanks!
Comment 34•3 years ago
•
|
||
(In reply to Hiroyuki Ikezoe (:hiro) from comment #33)
Agi, do you want me to open a new bug for the possible race condition?
Yes please, maybe we can cc :m_kato too he might have ideas.
Would it be ok to tweak SelectionActionDelegateTest.kt as what I suggested in comment 30? We'd like to land bug 1730998 since it's one of our top priority items.
Yes that's fine.
Thank you!
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 36•3 years ago
|
||
(In reply to Agi Sferro | :agi | ni? for questions | ⏰ PST | he/him from comment #34)
(In reply to Hiroyuki Ikezoe (:hiro) from comment #33)
Agi, do you want me to open a new bug for the possible race condition?
Yes please, maybe we can cc :m_kato too he might have ideas.
Filed bug 1735655 with CCing him. Thanks!
Assignee | ||
Comment 37•3 years ago
|
||
SelectionActionDelegateTest does just respond a single event in each test cases,
so if there are multiple events we need to respond, the test stops working since
the response will be discarded in SelectionActionDelegateChild.jsm [1].
We use a lager display size here to avoid the situation, in bug 1735655 the situation
will be eliminated.
Updated•3 years ago
|
Assignee | ||
Comment 38•3 years ago
|
||
A try with (400x400) display size; https://treeherder.mozilla.org/jobs?repo=try&revision=e338788bb5abdd2a6b79842fa872e60467094b86, fwiw.
Updated•3 years ago
|
Comment 39•3 years ago
|
||
Comment 40•3 years ago
|
||
bugherder |
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Description
•