Closed Bug 1665550 Opened 4 years ago Closed 3 years ago

Intermittent editor/libeditor/tests/test_dragdrop.html | Test timed out.

Categories

(Core :: DOM: Editor, defect, P5)

Product:
Core
Component:
DOM: Editor
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
92 Branch
Tracking Flags:
Tracking Status
firefox-esr78 --- unaffected
firefox-esr91 --- wontfix
firefox81 --- unaffected
firefox82 --- wontfix
firefox83 --- wontfix
firefox90 --- wontfix
firefox91 --- wontfix
firefox92 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])

Attachments

(4 files)

Bug 1665550 - part 1: Make `test_dragdrop.html` handle exception from synthesizePlainDragAndDrop r=m_kato!
48 bytes, text/x-phabricator-request
Details | Review
Bug 1665550 - part 2: Rewrite `test_dragdrop.html` with IIEF r=m_kato!
48 bytes, text/x-phabricator-request
Details | Review
Bug 1665550 - part 3: Make `nsTextControlFrame` set the source node and selection of drag session to new ones when it's reframed r=smaug!
48 bytes, text/x-phabricator-request
Details | Review
Bug 1665550 - part 4: Make `EventStateManager` update `mGestureDownFrameOwner` when anonymous nodes in `<input>` or `<textarea>` are replaced r=smaug!
48 bytes, text/x-phabricator-request
Details | Review

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

...
[task 2020-09-17T03:53:10.629Z] 03:53:10 INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to contenteditable: data of "input" event should be null on the <div> element
[task 2020-09-17T03:53:10.629Z] 03:53:10 INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to contenteditable: on the <div> element: dataTransfer of "input" event should have "e1
[task 2020-09-17T03:53:10.629Z] 03:53:10 INFO - Li" whose type is "text/plain"
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to contenteditable: getTargetRange() of "input" event should return empty array
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to contenteditable: only one "drop" event should be fired on other contenteditable
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | copy-dragging text in <textarea> to contenteditable: dataTransfer should have selected text as "text/plain"
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | copy-dragging text in <textarea> to contenteditable: dataTransfer should have not have selected nodes as "text/html"
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - Buffered messages finished
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_dragdrop.html | Test timed out.
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - reportError@SimpleTest/TestRunner.js:143:22
[task 2020-09-17T03:53:10.630Z] 03:53:10 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-09-17T03:53:11.036Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.036Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.036Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.583Z] 03:53:11 INFO - GECKO(2664) | MEMORY STAT | vsize 2104163MB | vsizeMaxContiguous 71724986MB | residentFast 171MB | heapAllocated 12MB
[task 2020-09-17T03:53:11.602Z] 03:53:11 INFO - TEST-OK | editor/libeditor/tests/test_dragdrop.html | took 309904ms
[task 2020-09-17T03:53:11.621Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.621Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.621Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.621Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 2506
[task 2020-09-17T03:53:11.622Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8516
[task 2020-09-17T03:53:11.622Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8378
[task 2020-09-17T03:53:11.622Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8288
[task 2020-09-17T03:53:11.622Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: '!outputStream', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 2506
[task 2020-09-17T03:53:11.622Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8516
[task 2020-09-17T03:53:11.622Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8378
[task 2020-09-17T03:53:11.623Z] 03:53:11 INFO - GECKO(2664) | [Parent 9776, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp, line 8288
[task 2020-09-17T03:53:11.628Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.628Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.628Z] 03:53:11 INFO - GECKO(2664) | [GPU 7568, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-17T03:53:11.638Z] 03:53:11 INFO - TEST-START | editor/libeditor/tests/test_execCommandPaste_noTarget.html

Has Regression Range: --- → yes

I don't think so. It touches only deleting content path (i.e., only "moving" drag and drop may run the path), but it times out during "coping" drag and drop.

And oddly, it fails here:
https://searchfox.org/mozilla-central/rev/45d0b4e8da44fe5e629317c597d7af684f355440/editor/libeditor/tests/test_dragdrop.html#1827-1841

  onDrop = aEvent => {
    dragEvents.push(aEvent);
    comparePlainText(aEvent.dataTransfer.getData("text/plain"), textarea.value.substring(3, 8),
       `${description}: dataTransfer should have selected text as "text/plain"`);
    is(aEvent.dataTransfer.getData("text/html"), "",
       `${description}: dataTransfer should have not have selected nodes as "text/html"`);
  };
  document.addEventListener("drop", onDrop);
  await synthesizePlainDragAndDrop({
    srcSelection: SpecialPowers.wrap(textarea).editor.selection,
    destElement: contenteditable,
    dragEvent: kModifiersToCopy,
  });
  is(textarea.value, "Line1\nLine2",
     `${description}: dragged range should be removed from <textarea>`);

The checks in onDrop were done, but textarea.value wasn't checked so that it's timed out in synthesizePlainDragAndDrop. However, the drop event is fired here:
https://searchfox.org/mozilla-central/rev/45d0b4e8da44fe5e629317c597d7af684f355440/testing/mochitest/tests/SimpleTest/EventUtils.js#3225-3232
and remaining async code is only:

await new Promise(r => setTimeout(r, 0));

https://searchfox.org/mozilla-central/rev/45d0b4e8da44fe5e629317c597d7af684f355440/testing/mochitest/tests/SimpleTest/EventUtils.js#3257

Therefore, I have no idea what happened at the timeout because of no JS errors which are thrown from synthesizePlainDragAndDrop.

Flags: needinfo?(masayuki)

Set release status flags based on info from the regressing bug 1664741

status-firefox81: --- → unaffected
status-firefox82: --- → affected
status-firefox83: --- → affected
status-firefox-esr78: --- → unaffected

I'm still not sure what's going on when it fails. But now, it's caused by unhandled JS error which is thrown by synthesizePlainDragAndDrop. I take a look.

Assignee: nobody → masayuki
Status: NEW → ASSIGNED

Trying to catch where cancels to start to drag in ESM. However, oddly, it's not recorded into a pref...
https://treeherder.mozilla.org/jobs?repo=try&selectedTaskRun=Bd7_m-eKQNCZsgYNaalDyA.0&revision=39732024a895c044f8d15bfcda4089d73372cc9f

Keep trying to think how to debug this.

Finally! I got found the root cause. DnD fails to dispatch dragend event if <input>/<textarea> element whose selection is dragged is reframed before dropping it. And perhaps, I guess, dragstart is not fired (and drag session failed to start) if <input>/<textarea> element is reframed during mousemove for starting DnD.

When they are reframed, its anonymous contents are also recreated. So, I think that we should stop recreating the anonymous content, or at least, reuse the original nodes at biding the frame.

When the test is timed out, there is a JS error which is thrown by
synthesizePlainDragAndDrop. So, first, make the test handle exception
with try-catch and assert the error.

With IIEF, we can guarantee each test block isolated. So, without declaring
semi-global variables a lot for all tests, developers can comment out every
tests to debug only one thing.

Depends on D119485

When nsTextControlFrame is reframed, TextEditor, anonymous <div> and
its Text are deleted temporarily and recreated them.

If users are dragging text in <input> or <textarea>, the drag session's
source node is set to the anonymous text node in the element. So, if the
element is reframed during a drag, the source node is disconnected from the
document and EndDragSession failed to dispatch eDragEnd event.

Therefore, this patch makes nsTextControlFrame replaces the source node
when it's recreated and only when the drag session's original source node
was in the text control element. For checking which text control had the
anonymous text node, this patch makes nsTextControlFrame replaces source
node with the <input> or <textarea> element when the frame is destroyed.

Depends on D119486

EventStateManager gives up to track gesture to start a drag if mouse down
content which is stored in mGestureDownFrameOwner gets lost its primary frame.

When user tries to start to drag selected text in <input> or <textarea>
element, mouse down content is an anonymous node in TextControlElement. So,
if a reflow occurs after mousedown event, the anonymous <div> element
is replaced with new one and EventStateManager gives up to track it.

Therefore, this patch makes EventStateManager do similar things as
nsBaseDragService. When nsTextControlFrame notifies of remove/add
the anonymous nodes, EventStateManager tries to keep tracking gesture with
a new anonymous node.

Depends on D119487

Attachment #9230424 - Attachment description: Bug 1665550 - part 3: Make `nsTextControlFrame` set the source node of drag session to new one when it's reframed r=smaug! → Bug 1665550 - part 3: Make `nsTextControlFrame` set the source node and selection of drag session to new ones when it's reframed r=smaug!
Pushed by masayuki@d-toybox.com:
https://hg.mozilla.org/integration/autoland/rev/4f1d7ce7792b
part 1: Make `test_dragdrop.html` handle exception from synthesizePlainDragAndDrop r=m_kato
https://hg.mozilla.org/integration/autoland/rev/d898c1a182cd
part 2: Rewrite `test_dragdrop.html` with IIEF r=m_kato
https://hg.mozilla.org/integration/autoland/rev/5b350f2aeb47
part 3: Make `nsTextControlFrame` set the source node and selection of drag session to new ones when it's reframed r=smaug
https://hg.mozilla.org/integration/autoland/rev/89aa5231ddb8
part 4: Make `EventStateManager` update `mGestureDownFrameOwner` when anonymous nodes in `<input>` or `<textarea>` are replaced r=smaug

Failure log from mozilla-beta: https://treeherder.mozilla.org/logviewer?job_id=345858631&repo=mozilla-beta&lineNumber=7582

[task 2021-07-21T08:55:38.996Z] 08:55:38     INFO - TEST-START | editor/libeditor/tests/test_dragdrop.html
[task 2021-07-21T08:55:41.754Z] 08:55:41     INFO - GECKO(3936) | JavaScript error: http://mochi.test:8888/tests/SimpleTest/EventUtils.js, line 3311: Error: "dragend" event is not fired by nsIDragService.endDragSession()
[task 2021-07-21T09:00:45.091Z] 09:00:45     INFO - TEST-INFO | started process screenshot
[task 2021-07-21T09:00:45.149Z] 09:00:45     INFO - TEST-INFO | screenshot: exit 0
[task 2021-07-21T09:00:45.150Z] 09:00:45     INFO - <snipped 1633 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
[task 2021-07-21T09:00:45.151Z] 09:00:45     INFO - Buffered messages logged at 08:55:41
[task 2021-07-21T09:00:45.152Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <input> to other <textarea> (canceling "insertFromDrop"): inputType of "input" event should be "deleteByDrag" on the <input> element 
[task 2021-07-21T09:00:45.153Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <input> to other <textarea> (canceling "insertFromDrop"): data of "input" event should be null on the <input> element 
[task 2021-07-21T09:00:45.153Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <input> to other <textarea> (canceling "insertFromDrop"): dataTransfer should be null on the <input> element 
[task 2021-07-21T09:00:45.154Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <input> to other <textarea> (canceling "insertFromDrop"): getTargetRange() of "input" event should return empty array 
[task 2021-07-21T09:00:45.155Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <input> to other <textarea> (canceling "insertFromDrop"): only one "drop" event should be fired on <textarea> 
[task 2021-07-21T09:00:45.156Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | copy-dragging text in <input> to <textarea>: dataTransfer should have selected text as "text/plain"
<...>
[task 2021-07-21T09:00:45.217Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to <input> (canceling "deleteByDrag"): data of "input" event should be e1
[task 2021-07-21T09:00:45.217Z] 09:00:45     INFO - Li on the <input> element 
[task 2021-07-21T09:00:45.217Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to <input> (canceling "deleteByDrag"): dataTransfer should be null on the <input> element 
[task 2021-07-21T09:00:45.217Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to <input> (canceling "deleteByDrag"): getTargetRange() of "input" event should return empty array 
[task 2021-07-21T09:00:45.219Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to <input> (canceling "deleteByDrag"): only one "drop" event should be fired on <textarea> 
[task 2021-07-21T09:00:45.219Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to <input> (canceling "insertFromDrop"): dataTransfer should have selected text as "text/plain" 
[task 2021-07-21T09:00:45.220Z] 09:00:45     INFO - TEST-PASS | editor/libeditor/tests/test_dragdrop.html | dragging text in <textarea> to <input> (canceling "insertFromDrop"): dataTransfer should have not have selected nodes as "text/html" 
[task 2021-07-21T09:00:45.220Z] 09:00:45     INFO - Buffered messages finished
[task 2021-07-21T09:00:45.220Z] 09:00:45     INFO - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_dragdrop.html | Test timed out. - 
[task 2021-07-21T09:00:46.117Z] 09:00:46     INFO - GECKO(3936) | MEMORY STAT | vsize 2103859MB | vsizeMaxContiguous 67310901MB | residentFast 98MB | heapAllocated 10MB
[task 2021-07-21T09:00:46.123Z] 09:00:46     INFO - TEST-OK | editor/libeditor/tests/test_dragdrop.html | took 307126ms
[task 2021-07-21T09:00:46.135Z] 09:00:46     INFO - TEST-START | editor/libeditor/tests/test_execCommandPaste_noTarget.html
status-firefox91: --- → affected

The patch landed in nightly and beta is affected.
:masayuki, is this bug important enough to require an uplift?
If not please set status_beta to wontfix.

For more information, please visit auto_nag documentation.

Flags: needinfo?(masayuki)
Regressions: 1745730
No longer regressions: 1745730
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: