Closed Bug 1671543 Opened 4 years ago Closed 3 years ago

[M-fis-xorig] Intermittent [Fission] dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418

Categories

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

defect

Tracking

()

RESOLVED FIXED
89 Branch
Fission Milestone M7a
Tracking Status
firefox89 --- fixed
firefox90 --- fixed
firefox91 --- fixed

People

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

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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


[task 2020-10-16T03:58:32.796Z] 03:58:32     INFO - TEST-START | http://mochi.test:8888/tests/dom/events/test/test_bug741666.html
[task 2020-10-16T03:58:32.875Z] 03:58:32     INFO - GECKO(1513) | [Child 4197, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-10-16T03:58:32.891Z] 03:58:32     INFO - GECKO(1513) | [Child 4197, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-10-16T03:58:33.027Z] 03:58:33     INFO - GECKO(1513) | [4305, Unnamed thread 7fbb3c05d5e0] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:202
[task 2020-10-16T03:58:33.028Z] 03:58:33     INFO - GECKO(1513) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpId0pBM.mozrunner/runtests_leaks.log
[task 2020-10-16T03:58:33.029Z] 03:58:33     INFO - GECKO(1513) | [4305, Unnamed thread 7fbb3c05d5e0] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/checkouts/gecko/xpcom/base/nsTraceRefcnt.cpp:202
[task 2020-10-16T03:58:33.040Z] 03:58:33     INFO - GECKO(1513) | [4305, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:247
[task 2020-10-16T03:58:33.191Z] 03:58:33     INFO - GECKO(1513) | [Child 4305, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:626
[task 2020-10-16T03:58:33.206Z] 03:58:33     INFO - TEST-INFO | started process screentopng
[task 2020-10-16T03:58:33.715Z] 03:58:33     INFO - TEST-INFO | screentopng: exit 0
[task 2020-10-16T03:58:33.720Z] 03:58:33     INFO - Buffered messages logged at 03:58:33
[task 2020-10-16T03:58:33.720Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct ctrlKey 
[task 2020-10-16T03:58:33.720Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct altKey 
[task 2020-10-16T03:58:33.721Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct shiftKey 
[task 2020-10-16T03:58:33.721Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct metaKey 
[task 2020-10-16T03:58:33.721Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Event is trusted 
[task 2020-10-16T03:58:33.721Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct touches length 
[task 2020-10-16T03:58:33.721Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct identifier 
[task 2020-10-16T03:58:33.722Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct target 
[task 2020-10-16T03:58:33.722Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct pageX 
[task 2020-10-16T03:58:33.722Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct pageY 
[task 2020-10-16T03:58:33.722Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct screenX 
[task 2020-10-16T03:58:33.722Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct screenY 
[task 2020-10-16T03:58:33.723Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct clientX 
[task 2020-10-16T03:58:33.723Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct clientY 
[task 2020-10-16T03:58:33.723Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct radiusX 
[task 2020-10-16T03:58:33.728Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct radiusY 
[task 2020-10-16T03:58:33.728Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct rotationAngle 
[task 2020-10-16T03:58:33.728Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct force 
[task 2020-10-16T03:58:33.729Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct ctrlKey 
[task 2020-10-16T03:58:33.729Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct altKey 
[task 2020-10-16T03:58:33.729Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct shiftKey 
[task 2020-10-16T03:58:33.730Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct metaKey 
[task 2020-10-16T03:58:33.730Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Event is trusted 
[task 2020-10-16T03:58:33.730Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct touches length 
[task 2020-10-16T03:58:33.731Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct identifier 
[task 2020-10-16T03:58:33.731Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct target 
[task 2020-10-16T03:58:33.732Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct pageX 
[task 2020-10-16T03:58:33.732Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct pageY 
[task 2020-10-16T03:58:33.733Z] 03:58:33     INFO - Buffered messages finished
[task 2020-10-16T03:58:33.734Z] 03:58:33     INFO - TEST-UNEXPECTED-FAIL | dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418
[task 2020-10-16T03:58:33.734Z] 03:58:33     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2020-10-16T03:58:33.735Z] 03:58:33     INFO -     checkTouch@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:61:5
[task 2020-10-16T03:58:33.735Z] 03:58:33     INFO -     checkTouches@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:52:15
[task 2020-10-16T03:58:33.736Z] 03:58:33     INFO -     checkEvent/<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:45:17
[task 2020-10-16T03:58:33.736Z] 03:58:33     INFO -     testPreventDefault/</<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:144:24
[task 2020-10-16T03:58:33.737Z] 03:58:33     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-10-16T03:58:33.738Z] 03:58:33     INFO - TEST-UNEXPECTED-FAIL | dom/events/test/test_bug741666.html | Touch has correct screenY - got 504, expected 249
[task 2020-10-16T03:58:33.739Z] 03:58:33     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2020-10-16T03:58:33.739Z] 03:58:33     INFO -     checkTouch@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:62:5
[task 2020-10-16T03:58:33.740Z] 03:58:33     INFO -     checkTouches@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:52:15
[task 2020-10-16T03:58:33.744Z] 03:58:33     INFO -     checkEvent/<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:45:17
[task 2020-10-16T03:58:33.745Z] 03:58:33     INFO -     testPreventDefault/</<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:144:24
[task 2020-10-16T03:58:33.745Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct clientX 
[task 2020-10-16T03:58:33.746Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct clientY 
[task 2020-10-16T03:58:33.748Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct radiusX 
[task 2020-10-16T03:58:33.749Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct radiusY 
[task 2020-10-16T03:58:33.749Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct rotationAngle 
[task 2020-10-16T03:58:33.750Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct force 
[task 2020-10-16T03:58:33.750Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct ctrlKey 
[task 2020-10-16T03:58:33.751Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct altKey 
[task 2020-10-16T03:58:33.752Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct shiftKey 
[task 2020-10-16T03:58:33.752Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct metaKey 
[task 2020-10-16T03:58:33.753Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Event is trusted 
[task 2020-10-16T03:58:33.753Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Correct touches length 
[task 2020-10-16T03:58:33.754Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct identifier 
[task 2020-10-16T03:58:33.756Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct target 
[task 2020-10-16T03:58:33.757Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct pageX 
[task 2020-10-16T03:58:33.757Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct pageY 
[task 2020-10-16T03:58:33.758Z] 03:58:33     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-10-16T03:58:33.758Z] 03:58:33     INFO - TEST-UNEXPECTED-FAIL | dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418
[task 2020-10-16T03:58:33.759Z] 03:58:33     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2020-10-16T03:58:33.759Z] 03:58:33     INFO -     checkTouch@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:61:5
[task 2020-10-16T03:58:33.760Z] 03:58:33     INFO -     checkTouches@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:52:15
[task 2020-10-16T03:58:33.760Z] 03:58:33     INFO -     checkEvent/<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:45:17
[task 2020-10-16T03:58:33.761Z] 03:58:33     INFO -     testPreventDefault/</<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:145:25
[task 2020-10-16T03:58:33.762Z] 03:58:33     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-10-16T03:58:33.765Z] 03:58:33     INFO - TEST-UNEXPECTED-FAIL | dom/events/test/test_bug741666.html | Touch has correct screenY - got 504, expected 249
[task 2020-10-16T03:58:33.766Z] 03:58:33     INFO -     SimpleTest.is@SimpleTest/SimpleTest.js:500:14
[task 2020-10-16T03:58:33.766Z] 03:58:33     INFO -     checkTouch@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:62:5
[task 2020-10-16T03:58:33.767Z] 03:58:33     INFO -     checkTouches@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:52:15
[task 2020-10-16T03:58:33.767Z] 03:58:33     INFO -     checkEvent/<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:45:17
[task 2020-10-16T03:58:33.768Z] 03:58:33     INFO -     testPreventDefault/</<@dom/events/test/test_bug741666.html?currentTestURL=dom%2Fevents%2Ftest%2Ftest_bug741666.html&closeWhenDone=1&showTestReport=false&expected=pass:145:25
[task 2020-10-16T03:58:33.768Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct clientX 
[task 2020-10-16T03:58:33.769Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct clientY 
[task 2020-10-16T03:58:33.769Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct radiusX 
[task 2020-10-16T03:58:33.773Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct radiusY 
[task 2020-10-16T03:58:33.774Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct rotationAngle 
[task 2020-10-16T03:58:33.774Z] 03:58:33     INFO - TEST-PASS | dom/events/test/test_bug741666.html | Touch has correct force 
[task 2020-10-16T03:58:33.775Z] 03:58:33     INFO - GECKO(1513) | MEMORY STAT | vsize 2556MB | residentFast 158MB | heapAllocated 9MB
[task 2020-10-16T03:58:33.775Z] 03:58:33     INFO - TEST-OK | http://mochi.test:8888/tests/dom/events/test/test_bug741666.html | took 507ms```
Summary: Intermittent dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418 → Intermittent [Fission] dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418

ahal hit this test failure when trying to to enable mochitest-plan in fission-xorigin mode on more platforms in bug 1694835.

https://treeherder.mozilla.org/jobs?repo=try&revision=a4813c46eff128482994870bf8a06677022cee24&selectedTaskRun=KxurApDtSoi1MMYFRYC32w.0

Fission Milestone: --- → M7a

Increasing priority to P3 because this intermittent failure rate is high-ish.

Priority: P5 → P3

I used to reproduce a similar failure locally with verify mode on revision 0d51fdccaa96, but after I update to recent revision 3be60f42358a, I could not reproduce anymore. It looks like something in-between these two revisions fix the failure, possible range https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=0d51fdccaa96&tochange=3be60f42358a, I will try if I could narrow down the range a bit.

No longer blocks: 1694835
Summary: Intermittent [Fission] dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418 → [M-fis-xorig] Intermittent [Fission] dom/events/test/test_bug741666.html | Touch has correct screenX - got 431, expected 418

https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=e3307c3c70a5&tochange=9bd3506f2809

So it looks like bug 1689156 somehow fix the intermittent, this also matches with the status in orange Factor: no failure after 2021/03/22 so far.

(In reply to Edgar Chen [:edgar] from comment #27)

https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=e3307c3c70a5&tochange=9bd3506f2809

So it looks like bug 1689156 somehow fix the intermittent, this also matches with the status in orange Factor: no failure after 2021/03/22 so far.

Good find! I will optimistically resolve this bug as fixed by bug 1689156.

Here's the latest orange factor link. We went from 8-11 failures per day to zero.

https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-03-19&endday=2021-03-26&tree=trunk&bug=1671543

Status: NEW → RESOLVED
Closed: 4 years ago
Depends on: 1689156
Resolution: --- → FIXED
Target Milestone: --- → 89 Branch

Note that this test is disabled for fission+xorigin mode on all platforms, so we won't see these failures unless the test is re-enabled:

[test_bug741666.html]
skip-if =
  toolkit == 'android' # fail
  fission && xorigin  # Bug 1716405 - New fission platform triage

https://searchfox.org/mozilla-central/rev/5e955a47c4af398e2a859b34056017764e7a2252/dom/events/test/mochitest.ini#130-133

Status: RESOLVED → REOPENED
Resolution: FIXED → ---

Since Edgar is on PTO, Henri will probably have to look into this.

Flags: needinfo?(hsivonen)

So far, I haven't succeeded at reproducing this locally.

Let's see if I can get it to fail on try in a manner that the Pernosco self-serve API would accept:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=6a0aec7098f1781be66d4c07c782fe99d4ee9353

Flags: needinfo?(hsivonen)
Assignee: nobody → hsivonen
Status: REOPENED → ASSIGNED
Pushed by opettay@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/e532e19d486b Make test_bug741666.html wait for APZ stability. r=smaug
Status: ASSIGNED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → FIXED

Change the status for beta to have the same as nightly and release.
For more information, please visit auto_nag documentation.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: