Closed Bug 1558642 Opened 5 years ago Closed 3 years ago

OSX Mojave (10.14) - dom/tests/mochitest/chrome/test_bug1224790-1.xul/dom/tests/mochitest/chrome/test_bug1224790-2.xul | Test timed out.

Tracking

()

Status:

RESOLVED FIXED

Milestone:

83 Branch

People

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

References

Details

Attachments

(4 files, 1 obsolete file)

Accesibility Access dialog 5 years ago Tooru Fujisawa [:arai] 482.29 KB, image/png		Details
Bug 1558642 - Remove synthesizeNativeOSXClick and consumer tests. r?mstange 5 years ago Tooru Fujisawa [:arai] 47 bytes, text/x-phabricator-request		Details \| Review
Bug 1558642 - disable test_bug1224790 on macosx1014 due to persistent failures 5 years ago Edwin Takahashi (:egao \| infrequent contributor) 47 bytes, text/x-phabricator-request		Details \| Review
Bug 1558642 - Part 1: Use synthesizeNativeMouseClick in test_bug1224790-1/2.xhtml (with a new AtCenter helper), re-enable the tests, and remove synthesizeNativeOSXClick. r?mstange 5 years ago Tooru Fujisawa [:arai] 47 bytes, text/x-phabricator-request		Details \| Review
Bug 1558642 - Part 2: Use EventUtils.synthesizeNative* where possible. r?mstange 5 years ago Tooru Fujisawa [:arai] 47 bytes, text/x-phabricator-request		Details \| Review

Treeherder Bug Filer

Reporter

Description

•

5 years ago

treeherder

Filed by: egao [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=251034558&repo=try
Full log: https://queue.taskcluster.net/v1/task/Yu5WSam5Q-6rjPZHYKtE7A/runs/0/artifacts/public/logs/live_backing.log

Platform: macosx1014-mojave
Test: mochtiest-chrome

Context:
23:00:34 INFO - TEST-START | dom/tests/mochitest/chrome/test_bug1224790-1.xul
23:01:00 INFO - GECKO(2155) | 2019-06-10 23:01:00.698 firefox[2155:22364] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2)
23:06:03 INFO - TEST-INFO | started process screencapture
23:06:03 INFO - TEST-INFO | screencapture: exit 0
23:06:03 INFO - Buffered messages logged at 23:00:34
23:06:03 INFO - must wait for load
23:06:03 INFO - must wait for load
23:06:03 INFO - must wait for focus
23:06:03 INFO - Buffered messages logged at 23:00:35
23:06:03 INFO - must wait for load
23:06:03 INFO - must wait for focus
23:06:03 INFO - must wait for focus
23:06:03 INFO - Buffered messages finished
23:06:03 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/chrome/test_bug1224790-1.xul | Test timed out.
23:06:03 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:275:18
23:06:03 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
23:06:03 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:06:03 INFO - TestRunner.runTests/<@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:381:20
23:06:03 INFO - promise callbackTestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:368:50
23:06:03 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:201:14
23:06:03 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:180:12
23:06:03 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:273:12
23:06:03 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
23:06:03 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
23:06:03 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
23:06:03 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:253:5
23:06:03 INFO - linkAndHookup@chrome://mochikit/content/harness.xul:45:3
23:06:03 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
23:06:03 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
23:06:03 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
23:06:03 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:251:3
23:06:03 INFO - loadTests@chrome://mochikit/content/harness.xul:24:3
23:06:03 INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xul:48:12
23:06:04 INFO - GECKO(2155) | MEMORY STAT | vsize 7581MB | residentFast 333MB | heapAllocated 79MB
23:06:04 INFO - TEST-OK | dom/tests/mochitest/chrome/test_bug1224790-1.xul | took 329997ms
23:06:04 INFO - TEST-START | dom/tests/mochitest/chrome/test_bug1224790-2.xul
23:11:34 INFO - Not taking screenshot here: see the one that was previously logged
23:11:34 INFO - Buffered messages logged at 23:06:04
23:11:34 INFO - must wait for load
23:11:34 INFO - must wait for load
23:11:34 INFO - must wait for focus
23:11:34 INFO - Buffered messages logged at 23:06:05
23:11:34 INFO - must wait for load
23:11:34 INFO - must wait for focus
23:11:34 INFO - Buffered messages finished
23:11:34 INFO - TEST-UNEXPECTED-FAIL | dom/tests/mochitest/chrome/test_bug1224790-2.xul | Test timed out.
23:11:34 INFO - SimpleTest.ok@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:275:18
23:11:34 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:22
23:11:34 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - setTimeout handlerTestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
23:11:34 INFO - TestRunner.runTests/<@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:381:20
23:11:34 INFO - promise callbackTestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:368:50
23:11:34 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:201:14
23:11:34 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:180:12
23:11:34 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:273:12
23:11:34 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
23:11:34 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
23:11:34 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
23:11:34 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:253:5
23:11:34 INFO - linkAndHookup@chrome://mochikit/content/harness.xul:45:3
23:11:34 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
23:11:34 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
23:11:34 INFO - EventHandlerNonNullgetTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
23:11:34 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:251:3
23:11:34 INFO - loadTests@chrome://mochikit/content/harness.xul:24:3
23:11:34 INFO - EventListener.handleEvent@chrome://mochikit/content/harness.xul:48:12
23:11:35 INFO - GECKO(2155) | MEMORY STAT | vsize 7597MB | residentFast 332MB | heapAllocated 80MB
23:11:35 INFO - TEST-OK | dom/tests/mochitest/chrome/test_bug1224790-2.xul | took 330450ms

Edwin Takahashi (:egao | infrequent contributor)

Updated

•

5 years ago

Keywords: regression

Edwin Takahashi (:egao | infrequent contributor)

Comment 1

•

5 years ago

:hsinyi - this appears to be a new failure observed on macosx1014 platform, which is in the works as the successor of macosx1010. Could you take a look, or pass on the ni to someone that maybe able to do so? Thanks!

Flags: needinfo?(htsai)

Hsin-Yi Tsai (she/her) [:hsinyi]

Comment 2

•

5 years ago

I'm not really sure who should ask for.
Masayuki or :arai, do you know if there's some limitation, such as synthesizeNativeOSXClick, on mac 10.14 version that causes this new failure?

Flags: needinfo?(masayuki)

Flags: needinfo?(htsai)

Flags: needinfo?(arai.unmht)

Tooru Fujisawa [:arai]

Assignee

Comment 3

•

5 years ago

it might require extra privilege about accessibility, to simulate mouse event.
I'll look into it this weekend

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

Comment 4

•

5 years ago

Well, I really don't know about it. Arai-san, thank you for taking it.

Flags: needinfo?(masayuki)

Tooru Fujisawa [:arai]

Assignee

Comment 5

•

5 years ago

Attached image Accesibility Access dialog — Details

I get "Accessibility Access (Events)" dialog when I call CGEventPost API,
and I have to open Preferences, Security & Privacy pane, Privacy tab, and check "Terminal" (or the application that invokes ./mach test).
That's the reason why the test fails on macOS 10.14, that added sandboxing around that.

https://developer.apple.com/library/archive/documentation/Security/Conceptual/AppSandboxDesignGuide/DesigningYourSandbox/DesigningYourSandbox.html

Posting keyboard or mouse events to another app

You cannot sandbox an app that controls another app. Posting keyboard or
mouse events using functions like CGEventPost offers a way to circumvent
this restriction, and is therefore not allowed from a sandboxed app.

and I think, configuring all environment to allow that isn't reasonable solution.
so, we'll need to disable the test.

Tooru Fujisawa [:arai]

Assignee

Comment 6

•

5 years ago

what's the plan about automation and macos versions?
will all instances be replaced/updated to macOS 10.14 or later?
or will there be any 10.13 or older instances?

if former, the test just needs to be disabled or removed, given that cannot be tested "automatically".
if latter, the test needs to detect the environment somehow and run only if possible.

Flags: needinfo?(htsai)

Comment hidden (Intermittent Failures Robot)

Hsin-Yi Tsai (she/her) [:hsinyi]

Comment 8

•

5 years ago

Thank you, :arai for the good questions.
:egao, could you please answer :arai's questions in comment 6?

Flags: needinfo?(htsai) → needinfo?(egao)

Edwin Takahashi (:egao | infrequent contributor)

Comment 9

•

5 years ago

:arai - as far as I am aware, we are converting all macosx1010 machines to macosx1014, and macosx1010 will be deprecated at that point. The timeline is unclear, but my aim is to have most if not all of the tests running on macosx1014 by end of this month.

So it sounds like we need to disable the test or removed.

Flags: needinfo?(egao)

Tooru Fujisawa [:arai]

Assignee

Comment 10

•

5 years ago

Attached file Bug 1558642 - Remove synthesizeNativeOSXClick and consumer tests. r?mstange (obsolete) — Details

synthesizeNativeOSXClick uses CGEventPost, that needs "Accessibility Access
(Events)" on macOS 10.14 or later, and cannot be tested in automation without
human interaction to add the access.

Markus Stange [:mstange]

Comment 11

•

5 years ago

Kats is fixing this in bug 1549052.

Flags: needinfo?(arai.unmht)

Edwin Takahashi (:egao | infrequent contributor)

Comment 12

•

5 years ago

:mstange - thanks for heads up, will test this suite as well when bug 1549052 lands in central.

Tooru Fujisawa [:arai]

Assignee

Comment 13

•

5 years ago

bug 1549052 touches different part.
this bug is about synthesizeNativeOSXClick function in EventUtils.js, that uses js-ctypes to call CGEventPost.
I think we might be able to do similar thing as the patch there to perform native click in the function.

but, given it's Objective-C call, calling it from ctypes is somewhat complicated.
I know it's possible, and I have some wrapper code written before, but I'm not sure introducing whole those things into EventUtils.js makes sense.

Tooru Fujisawa [:arai]

Assignee

Comment 14

•

5 years ago

or maybe we should move the code to native part?

Markus Stange [:mstange]

Comment 15

•

5 years ago

Oohh, I see, I didn't realize that. Let me look at this in more detail.

Edwin Takahashi (:egao | infrequent contributor)

Comment 16

•

5 years ago

Pushed a try with the changes in bug 1549052, but these tests continue to fail.

I will post a patch to disable these tests against this bug, but investigations (if any) can continue if desired.

Edwin Takahashi (:egao | infrequent contributor)

•

5 years ago

Pushed by egao@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/15a08d101dd7
disable test_bug1224790 on macosx1014 due to persistent failures r=arai,jmaher

Daniel Varga [:dvarga]

Comment 20

•

5 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/15a08d101dd7

Tooru Fujisawa [:arai]

Assignee

Comment 21

•

5 years ago

looks like we can use synthesizeNativeMouseEvent in EventUtils.js.
some files are using it to emulate click.
I think adding synthesizeNativeMouseClick would make them simpler.

Tooru Fujisawa [:arai]

Assignee

•

•

4 years ago

Assignee: nobody → arai.unmht

Attachment #9081094 - Attachment description: Bug 1558642 - Part 1: Add synthesizeNativeClick{,AtCenter} and remove synthesizeNativeOSXClick. r?mstange → Bug 1558642 - Part 1: Use synthesizeNativeMouseClick in test_bug1224790-1/2.xhtml (with a new AtCenter helper), re-enable the tests, and remove synthesizeNativeOSXClick. r?mstange

Status: NEW → ASSIGNED

Markus Stange [:mstange]

Comment 33

•

4 years ago

Looks greenish now: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b12946f722b1d592a8c66d3365d975ed4432389f

Pulsebot

Comment 34

•

4 years ago

Pushed by mstange@themasta.com:
https://hg.mozilla.org/integration/autoland/rev/21e13390db4f
Part 1: Use synthesizeNativeMouseClick in test_bug1224790-1/2.xhtml (with a new AtCenter helper), re-enable the tests, and remove synthesizeNativeOSXClick. r=mstange
https://hg.mozilla.org/integration/autoland/rev/b86d52383964
Part 2: Use EventUtils.synthesizeNative* where possible. r=mstange

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 35

•

4 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/21e13390db4f
https://hg.mozilla.org/mozilla-central/rev/b86d52383964

BugBot [:suhaib / :marco/ :calixte]

Comment 36

•

3 years ago

The leave-open keyword is there and there is no activity for 6 months.
:arai, maybe it's time to close this bug?

Flags: needinfo?(arai.unmht)

Tooru Fujisawa [:arai]

Assignee

Comment 37

•

3 years ago

Thanks.
the above patch fixed the issue, for firefox 83

Status: ASSIGNED → RESOLVED

Closed: 3 years ago

Flags: needinfo?(arai.unmht)

Keywords: leave-open

Resolution: --- → FIXED

Target Milestone: --- → 83 Branch

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