1729480 - Intermittent TEST-UNEXPECTED-PASS | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=(input|textarea)&hide-target=(editor|parent) | (<input>|<textarea>) is hidden by "keydown" event listener - expected FAIL (in Opt builds)

Status: RESOLVED FIXED

(Core :: DOM: UI Events & Focus Handling, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-09-07T16:07:39.293Z] 16:07:39     INFO - TEST-START | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent
[task 2021-09-07T16:07:39.294Z] 16:07:39     INFO - Closing window 69aaabe4-1f09-41bd-85a6-70b3182df5bf
[task 2021-09-07T16:07:39.387Z] 16:07:39     INFO - {'actions': [{'type': 'none', 'actions': [{'type': 'pause', 'duration': 16}, {'type': 'pause', 'duration': 16}], 'id': '0'}, {'type': 'key', 'actions': [{'type': 'keyDown', 'value': 'a'}, {'type': 'keyUp', 'value': 'a'}], 'id': '1'}]}
[task 2021-09-07T16:07:39.471Z] 16:07:39     INFO - {'actions': [{'type': 'none', 'actions': [{'type': 'pause', 'duration': 16}, {'type': 'pause', 'duration': 16}], 'id': '2'}, {'type': 'key', 'actions': [{'type': 'keyDown', 'value': 'a'}, {'type': 'keyUp', 'value': 'a'}], 'id': '3'}]}
[task 2021-09-07T16:07:39.540Z] 16:07:39     INFO - {'actions': [{'type': 'none', 'actions': [{'type': 'pause', 'duration': 16}, {'type': 'pause', 'duration': 16}], 'id': '4'}, {'type': 'key', 'actions': [{'type': 'keyDown', 'value': 'a'}, {'type': 'keyUp', 'value': 'a'}], 'id': '5'}]}
[task 2021-09-07T16:07:39.625Z] 16:07:39     INFO - 
[task 2021-09-07T16:07:39.625Z] 16:07:39     INFO - TEST-PASS | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent | Wait for load event 
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - TEST-FAIL | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent | execCommand("insertText", false, "typed value") in <textarea> - assert_equals: The value shouldn't be modified by "insertText" command expected "default value" but got "typed value"
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - @http://web-platform.test:8000/editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent:51:18
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - promise_test/tests.promise_tests</<@http://web-platform.test:8000/resources/testharness.js:638:36
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - promise_test/tests.promise_tests<@http://web-platform.test:8000/resources/testharness.js:637:20
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - TEST-FAIL | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent | execCommand("delete") in <textarea> - assert_equals: The value shouldn't be modified by "delete" command expected "default value" but got ""
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - @http://web-platform.test:8000/editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent:63:18
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - promise_test/tests.promise_tests</<@http://web-platform.test:8000/resources/testharness.js:638:36
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - promise_test/tests.promise_tests<@http://web-platform.test:8000/resources/testharness.js:637:20
[task 2021-09-07T16:07:39.628Z] 16:07:39     INFO - TEST-UNEXPECTED-PASS | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent | <textarea> is hidden by "keydown" event listener - expected FAIL
[task 2021-09-07T16:07:39.629Z] 16:07:39     INFO - TEST-INFO | expected FAIL
[task 2021-09-07T16:07:39.631Z] 16:07:39     INFO - ..
[task 2021-09-07T16:07:39.632Z] 16:07:39     INFO - TEST-OK | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=parent | took 338ms
[task 2021-09-07T16:07:39.634Z] 16:07:39     INFO - PID 6308 | 1631030859626	Marionette	INFO	Stopped listening on port 51660
[task 2021-09-07T16:07:39.678Z] 16:07:39     INFO - PID 6308 | JavaScript error: resource:///modules/Interactions.jsm, line 201: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIUserIdleService.removeIdleObserver]
[task 2021-09-07T16:07:40.103Z] 16:07:40     INFO - PID 6308 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-09-07T16:07:40.319Z] 16:07:40     INFO - Browser exited with return code 0
[task 2021-09-07T16:07:40.324Z] 16:07:40     INFO - Closing logging queue
[task 2021-09-07T16:07:40.324Z] 16:07:40     INFO - queue closed
[task 2021-09-07T16:07:40.457Z] 16:07:40     INFO - Application command: Z:\task_163102894813357\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_163102894813357\AppData\Local\Temp\tmpkb2mindt
[task 2021-09-07T16:07:40.470Z] 16:07:40     INFO - PID 5784 | 1631030857475	Marionette	INFO	Marionette enabled
[task 2021-09-07T16:07:40.473Z] 16:07:40     INFO - PID 5784 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_163102894813357\\AppData\\Local\\Temp\\tmpkt530e4a\\search.json.mozlz4", (void 0)))
[task 2021-09-07T16:07:40.474Z] 16:07:40     INFO - PID 5784 | 1631030859474	Marionette	INFO	Listening on port 51692
[task 2021-09-07T16:07:40.475Z] 16:07:40     INFO - Starting runner
[task 2021-09-07T16:07:41.511Z] 16:07:41     INFO - TEST-START | /editing/other/edit-in-textcontrol-immediately-after-hidden.tentative.html?editor=textarea&hide-target=editor

Comment 1

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Hmm, it probably means that something randomly runs while dispatching a keydown element and it flushes pending notifications which includes destroying the target editor. So editor won't handle it and unexpectedly passes the test.

Comment 4

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Ah, perhaps, I got it. keypress event is dispatched separately from keydown event, and editor handles the keypress event.
After PresShell::EventHandler dispatches any user input event, it tries to flush pending notifications of IMEContentObserver:
https://searchfox.org/mozilla-central/rev/1761c710b035d7dc8892dfa8e56589b4e095221f/layout/base/PresShell.cpp#8153,8158

Then, IMEContentObserver will put it into the queue to wait next vsync:
https://searchfox.org/mozilla-central/rev/1761c710b035d7dc8892dfa8e56589b4e095221f/dom/events/IMEContentObserver.cpp#1426,1436-1437

Therefore, only when the test runs fast, i.e., in PGO build or Opt build, the vsync message comes before the following keypress event. Then, it flushes pending layout and it causes destroying the TextEditor, finally, the keypress event won't be handled in the editor and gets expected result.

In other words, this could happen in the wild randomly. So I think that we need to make keypress event is dispatched as a default action of the preceding keydown event, but it's really hard to fix it because of requiring a lot of changes under widget/. It was already filed as bug 1181501 and bug 1560766.

Comment 6

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

(It's fine to disable the test only in opt builds.)

Comment 7

[Intermittent Failures Robot]

28 failures in 3266 pushes (0.009 failures/push) were associated with this bug in the last 7 days.

This is the #49 most frequent failure this week.

Repository breakdown:

• autoland: 18
• mozilla-central: 8
• try: 2

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 17
  • opt: 17
• macosx1015-64-qr: 4
  • opt: 4
• windows10-64-2004-qr: 5
  • opt: 5
• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1729480&startday=2021-09-06&endday=2021-09-12&tree=all

Comment 8

[Intermittent Failures Robot]

17 failures in 616 pushes (0.028 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 10
• mozilla-central: 5
• try: 2

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 7
  • opt: 7
• windows10-32-2004-shippable-qr: 2
  • opt: 2
• windows10-64-2004-qr: 5
  • opt: 5
• windows10-64-2004-devedition-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 1
  • opt: 1
• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1729480&startday=2021-09-13&endday=2021-09-13&tree=all

Comment 9

[Intermittent Failures Robot]

16 failures in 604 pushes (0.026 failures/push) were associated with this bug yesterday.

Repository breakdown:

• try: 3
• autoland: 10
• mozilla-central: 3

Platform and build breakdown:

• windows10-32-2004-shippable-qr: 2
  • opt: 2
• windows10-64-2004-devedition-qr: 1
  • opt: 1
• windows10-64-2004-shippable-qr: 6
  • opt: 6
• macosx1015-64-qr: 2
  • opt: 2
• windows10-32-2004-qr: 4
  • opt: 4
• windows10-64-2004-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1729480&startday=2021-09-14&endday=2021-09-14&tree=all

Comment 10

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

I have no idea how to make the test result stable except fixing the failure 😋

Comment 11

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Here is the first try:
https://treeherder.mozilla.org/jobs?repo=try&revision=f7e66637baf1b3bfe00f3b5f0397d195bf56cc9d

There are two permanent failures. One is the case of <input> element in editing/other/insert-paragraph-in-void-element.tentative.html. However, I know this is just a hidden bug, not a regression, although I'm not sure the reason. Collapsing Selection might be going down to the anonymous subtree for <input>. I'll check it more.
https://treeherder.mozilla.org/jobs?repo=try&revision=f7e66637baf1b3bfe00f3b5f0397d195bf56cc9d&selectedTaskRun=PYtSlovQQ8SEHK-Co5IhEA.0

The other is the failures of test_editor_for_input_with_autocomplete.html. I have no idea what's going on for this. Perhaps, autocomplete popup behavior is canceled or something by the new flush?? I keep investigating this.
https://treeherder.mozilla.org/jobs?repo=try&revision=f7e66637baf1b3bfe00f3b5f0397d195bf56cc9d&selectedTaskRun=EyoKZnq5TQyQziH1vlt4hQ.0

Comment 12

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

The former issue is bug 1731005. The latter is looks like known intermittent failure.

Comment 13

[Intermittent Failures Robot]

17 failures in 654 pushes (0.026 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 10
• mozilla-central: 3
• try: 4

Platform and build breakdown:

• windows10-64-2004-qr: 5
  • opt: 5
• windows10-64-2004-shippable-qr: 7
  • opt: 7
• macosx1015-64-shippable-qr: 1
  • opt: 1
• macosx1015-64-devedition-qr: 1
  • opt: 1
• windows10-32-2004-shippable-qr: 1
  • opt: 1
• windows10-32-2004-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1729480&startday=2021-09-15&endday=2021-09-15&tree=all

Comment 14

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Attachment: Bug 1729480 - Make `edit-in-textcontrol-immediately-after-hidden` wait for receiving necessary event before checking the editor value r=emilio!

Depends on D125791

Comment 15

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)]

Attachment: Bug 1729480 - Make `keypress` event listener of editor and `execCommand` related methods access editor instance after flushing pending layout r=emilio!,smaug!

I have no idea how to make the test result stable because the intermittent
failure is caused by a race of IMEContentObserver's content query performend
at vsync and keypress event after the keydown event. Therefore, I try to
fix the root cause of the failure.

There are two paths reaching a public method of editor with pending
notifications. One is keypress event listener of the editor. The other is
execCommand related methods of Document. Therefore, we should make them
flush pending notifications before accessing editor, but the cost may be too
expensive. So we should consider whether we should flush pending notifications
or not as far as later.

Note that we cannot fix the beforeinput cases because flushing pending
notifications after dispatching beforeinput event may cause oranges. It'll
be fixed while I'm working on bug 1710784.

Depends on D125791

Comment 16

[Intermittent Failures Robot]

17 failures in 504 pushes (0.034 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 8
• mozilla-central: 8
• try: 1

Platform and build breakdown:

• windows10-64-2004-qr: 2
  • opt: 2
• windows10-64-2004-shippable-qr: 7
  • opt: 7
• windows10-32-2004-shippable-qr: 3
  • opt: 3
• macosx1015-64-shippable-qr: 2
  • opt: 2
• windows10-32-2004-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1729480&startday=2021-09-16&endday=2021-09-16&tree=all

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/82f0527432d5
Make `keypress` event listener of editor and `execCommand` related methods access editor instance after flushing pending layout r=emilio,smaug

Comment 18

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/82f0527432d5

Comment 19

[Intermittent Failures Robot]

79 failures in 3375 pushes (0.023 failures/push) were associated with this bug in the last 7 days.

This is the #9 most frequent failure this week.

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 41
• mozilla-central: 24
• try: 14

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 30
  • opt: 30
• windows10-64-2004-qr: 14
  • opt: 14
• windows10-32-2004-shippable-qr: 11
  • opt: 11
• windows10-64-2004-devedition-qr: 3
  • opt: 3
• macosx1015-64-shippable-qr: 5
  • opt: 5
• macosx1015-64-qr: 3
  • opt: 3
• windows10-32-2004-qr: 11
  • opt: 11
• macosx1015-64-devedition-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1729480&startday=2021-09-13&endday=2021-09-19&tree=all