Intermittent accessible/tests/browser/e10s/browser_caching_name.js | Test timed out -

REOPENED
Unassigned
(NeedInfo from)

Status

()

defect
P2
normal
REOPENED
2 years ago
4 days ago

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

Tracking

({intermittent-failure})

unspecified
mozilla58
Points:
---

Firefox Tracking Flags

(firefox58 fixed)

Details

(Whiteboard: [stockwell unknown])

Attachments

(1 attachment)

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)
Yura probably has more insight here.
Flags: needinfo?(eitan) → needinfo?(yzenevich)
Comment hidden (Intermittent Failures Robot)
High ratio, bumping to p2, since the test is a candidate for throwing out.

Yura, do we have any logging in browsers tests to track down the problem?
Priority: P5 → P2
Posted patch 1388256 v1Splinter Review
trying aria owns test approach.
Flags: needinfo?(yzenevich)
Attachment #8915730 - Flags: review?(eitan)
Assignee: nobody → yzenevich
Status: NEW → ASSIGNED
Comment hidden (Intermittent Failures Robot)
Comment on attachment 8915730 [details] [diff] [review]
1388256 v1

Review of attachment 8915730 [details] [diff] [review]:
-----------------------------------------------------------------

I'm not 100% this will remedy the intermittent failures, but it's worth trying.

Depending on if this fixes the issue or not, I would add a diagnostic:
Have waitForEvent timeout before the test times out. That way we will have a stack with exactly what event we missed.

::: accessible/tests/browser/.eslintrc.js
@@ +4,5 @@
>    "extends": [
>      "plugin:mozilla/browser-test"
>    ],
> +  "globals": {
> +    "gBrowser": false

why is this needed here?

::: accessible/tests/browser/events.js
@@ +185,5 @@
>  }
> +
> +/*
> + * This function spawns a content task and awaits expected mutation events from
> + * aria-owns changes. It's good at catching events we did *not* expect. We do

We are using it now for more than just aria-owns so this comment should be updated.
Attachment #8915730 - Flags: review?(eitan) → review+

Comment 15

2 years ago
Pushed by yura.zenevich@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3c5cbd09b604
improving stability of name caching test. r=eeejay
https://hg.mozilla.org/mozilla-central/rev/3c5cbd09b604
Status: ASSIGNED → RESOLVED
Last Resolved: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla58
Fail reappeared on Windows 10 x64.
Log: https://treeherder.mozilla.org/logviewer.html#?job_id=155088585&repo=autoland&lineNumber=1971
Status: RESOLVED → REOPENED
Flags: needinfo?(yzenevich)
Resolution: FIXED → ---
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)
Clearing ni? for now low intermittent rate.
Flags: needinfo?(yzenevich)
Assignee: yzenevich → nobody
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 hidden (Intermittent Failures Robot)
There is a total of 48 total failures in the last 7 days.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=194730472&repo=autoland&lineNumber=1125

00:55:38     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_name.js
00:56:23     INFO - TEST-INFO | started process screenshot
00:56:23     INFO - TEST-INFO | screenshot: exit 0
00:56:23     INFO - Buffered messages logged at 00:55:38
00:56:23     INFO - Entering test bound 
00:56:23     INFO - Buffered messages finished
00:56:23     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/e10s/browser_caching_name.js | Test timed out - 
00:56:23     INFO - GECKO(6080) | MEMORY STAT | vsize 1727MB | vsizeMaxContiguous 132673633MB | residentFast 238MB | heapAllocated 93MB
00:56:23     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_name.js | took 45075ms
00:56:23     INFO - checking window state

Yura can you take a look?
Flags: needinfo?(yzenevich)
Whiteboard: [stockwell needswork]
Comment hidden (Intermittent Failures Robot)
There is a total of 36 total failures in the last 7 days.

Any updates on this?
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Over the last 7 days there are 31 failures present on this bug. These happen on windows10-64, osx-10-10, linux64, linux32

Here is the most recent log example: https://treeherder.mozilla.org/logviewer.html#?job_id=197354351&repo=autoland&lineNumber=1127

11:23:59     INFO - *** Start BrowserChrome Test Results ***
11:23:59     INFO - checking window state
11:23:59     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_attributes.js
11:23:59     INFO - GECKO(2040) | MEMORY STAT | vsize 1706MB | vsizeMaxContiguous 131445450MB | residentFast 258MB | heapAllocated 112MB
11:23:59     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_attributes.js | took 451ms
11:23:59     INFO - checking window state
11:23:59     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_description.js
11:24:00     INFO - GECKO(2040) | MEMORY STAT | vsize 1717MB | vsizeMaxContiguous 131445440MB | residentFast 268MB | heapAllocated 115MB
11:24:00     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_description.js | took 543ms
11:24:00     INFO - checking window state
11:24:00     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_name.js
11:24:45     INFO - TEST-INFO | started process screenshot
11:24:45     INFO - TEST-INFO | screenshot: exit 0
11:24:45     INFO - Buffered messages logged at 11:24:00
11:24:45     INFO - Entering test bound 
11:24:45     INFO - Buffered messages finished
11:24:45     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/e10s/browser_caching_name.js | Test timed out - 
11:24:45     INFO - GECKO(2040) | MEMORY STAT | vsize 1720MB | vsizeMaxContiguous 131445427MB | residentFast 237MB | heapAllocated 79MB
11:24:45     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_name.js | took 45076ms
11:24:45     INFO - checking window state
Flags: needinfo?(surkov.alexander)
Comment hidden (Intermittent Failures Robot)
asurkov: Hi, Have you had a chance to take a look at this bug yet?
Comment hidden (Intermittent Failures Robot)
This bug fails 31 times in the last 7 days. Occurs on linux32, osx10-10 and windows10-64 on opt, asan and debug build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#?job_id=200111999&repo=mozilla-inbound&lineNumber=1607

INFO - TEST-PASS | accessible/tests/browser/e10s/browser_caching_name.js | Wrong name of the accessible for [DOM node id: a-img, role: link, name: 'test5', address: [xpconnect wrapped nsIAccessible]] - 
[task 2018-09-19T05:34:30.597Z] 05:34:30     INFO - Buffered messages finished
[task 2018-09-19T05:34:30.598Z] 05:34:30     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/e10s/browser_caching_name.js | Test timed out - 
[task 2018-09-19T05:34:30.599Z] 05:34:30     INFO - GECKO(1069) | MEMORY STAT | vsize 611MB | residentFast 245MB | heapAllocated 71MB
[task 2018-09-19T05:34:30.599Z] 05:34:30     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_name.js | took 45114ms
[task 2018-09-19T05:34:30.600Z] 05:34:30     INFO - checking window state
[task 2018-09-19T05:34:30.602Z] 05:34:30     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_relations.js
[task 2018-09-19T05:34:30.806Z] 05:34:30     INFO - GECKO(1069) | MEMORY STAT | vsize 606MB | residentFast 247MB | heapAllocated 72MB
[task 2018-09-19T05:34:30.808Z] 05:34:30     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_relations.js | took 590ms
[task 2018-09-19T05:34:30.840Z] 05:34:30     INFO - checking window state
[task 2018-09-19T05:34:30.857Z] 05:34:30     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_states.js
[task 2018-09-19T05:34:31.339Z] 05:34:31     INFO - GECKO(1069) | MEMORY STAT | vsize 601MB | residentFast 249MB | heapAllocated 74MB
[task 2018-09-19T05:34:31.339Z] 05:34:31     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_states.js | took 476ms
[task 2018-09-19T05:34:31.359Z] 05:34:31     INFO - checking window state

asurkov:Can you please take a look at this bug?
here's relevant log:

INFO - TEST-PASS | accessible/tests/browser/e10s/browser_caching_name.js | Wrong name of the accessible for [DOM node id: a-img, role: link, name: 'test2 test3', address: [xpconnect wrapped nsIAccessible]] - 
[task 2018-09-19T05:34:30.595Z] 05:34:30     INFO - TEST-PASS | accessible/tests/browser/e10s/browser_caching_name.js | Wrong name of the accessible for [DOM node id: a-img, role: link, name: 'test1', address: [xpconnect wrapped nsIAccessible]] - 
[task 2018-09-19T05:34:30.596Z] 05:34:30     INFO - TEST-PASS | accessible/tests/browser/e10s/browser_caching_name.js | Wrong name of the accessible for [DOM node id: a-img, role: link, name: 'test5', address: [xpconnect wrapped nsIAccessible]] - 
[task 2018-09-19T05:34:30.597Z] 05:34:30     INFO - Buffered messages finished

It hangs on 'a-img' "test4", after "test5" is done, presumably we don't receive a reorder event when child img element is removed [1].

[1] https://dxr.mozilla.org/mozilla-central/source/accessible/tests/browser/e10s/browser_caching_name.js?q=browser_caching_name.js&redirect_type=direct#363

Yura, does it sound about right? and if so, then are there any thoughts on why reorder event may be not delivered?
Flags: needinfo?(surkov.alexander)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
This bug failed 36 times in the last 7 days. This fails on all platforms except Android. build types are debug, asan and opt.

Log:
https://treeherder.mozilla.org/logviewer.html#?job_id=202565061&repo=autoland&lineNumber=1531

 INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_name.js
10:31:06     INFO - TEST-INFO | started process screenshot
10:31:06     INFO - TEST-INFO | screenshot: exit 0
10:31:06     INFO - Buffered messages logged at 10:30:21
10:31:06     INFO - Entering test bound 
10:31:06     INFO - Buffered messages finished
10:31:06     INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/e10s/browser_caching_name.js | Test timed out - 
10:31:06     INFO - GECKO(6508) | MEMORY STAT | vsize 1719MB | vsizeMaxContiguous 132282804MB | residentFast 236MB | heapAllocated 80MB
10:31:06     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_name.js | took 45082ms
10:31:06     INFO - checking window state
10:31:06     INFO - TEST-START | accessible/tests/browser/e10s/browser_caching_relations.js
10:31:07     INFO - GECKO(6508) | MEMORY STAT | vsize 1725MB | vsizeMaxContiguous 132282816MB | residentFast 244MB | heapAllocated 82MB
10:31:07     INFO - TEST-OK | accessible/tests/browser/e10s/browser_caching_relations.js | took 468ms

asurkov: Can you please take a look at this bug?
Flags: needinfo?(surkov.alexander)
QA Contact: surkov.alexander
QA Contact: surkov.alexander
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
This has failed 32 times in the last 7 days. Recent logs:https://treeherder.mozilla.org/logviewer.html#?job_id=207288888&repo=mozilla-central

:asurkov, :yzen
Do you guys have any update? Or should we disable this?
(In reply to Arthur Iakab [arthur_iakab] from comment #59)
> This has failed 32 times in the last 7 days. Recent
> logs:https://treeherder.mozilla.org/logviewer.
> html#?job_id=207288888&repo=mozilla-central
> 
> :asurkov, :yzen
> Do you guys have any update? Or should we disable this?

Leaving the bug at Yura's discretion. If the logging can be improved that will help to investigate the bug further, then it's worth to try, otherwise the test should be disabled I'd say.
Flags: needinfo?(surkov.alexander)
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 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)
You need to log in before you can comment on or make changes to this bug.