Closed Bug 1388256 Opened 7 years ago Closed 4 years ago

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

Categories

(Core :: Disability Access APIs, defect, P2)

Product:
Core
Component:
Disability Access APIs
Type:
defect

Tracking

()

Status:
RESOLVED WORKSFORME
Milestone:
mozilla58
Tracking Flags:
Tracking Status
firefox58 --- fixed

People

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

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown][stockwell disabled])

Attachments

(2 files)

1388256 v1
12.36 KB, patch
eeejay
: review+
Details | Diff | Splinter Review
Bug 1388256 - disabled browser_caching_name.js on debug mac and win, linux64 r=gbrown
47 bytes, text/x-phabricator-request
Details | Review 
Yura probably has more insight here.
Flags: needinfo?(eitan) → needinfo?(yzenevich)
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
Attached patch 1388256 v1 — — Splinter Review 
trying aria owns test approach.
Flags: needinfo?(yzenevich)
Attachment #8915730 - Flags: review?(eitan)
Assignee: nobody → yzenevich
Status: NEW → ASSIGNED
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+
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
Closed: 7 years ago
status-firefox58: --- → fixed
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
status-firefox57: fixed → ---
Flags: needinfo?(yzenevich)
Resolution: FIXED → ---
Clearing ni? for now low intermittent rate.
Flags: needinfo?(yzenevich)
Assignee: yzenevich → nobody
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]
There is a total of 36 total failures in the last 7 days.

Any updates on this?
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)
asurkov: Hi, Have you had a chance to take a look at this bug yet?
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)
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
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)

In the last 7 days there were 32 failures associated with this bug: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-09-13&endday=2019-09-20&tree=trunk&bug=1388256
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=267588955&repo=autoland&lineNumber=1833
Occurs on windows7-32, windows10-64-qr, windows10-64, macosx1014-64, linux64-shippable, linux64 debug and asan build types.

:Jamie, can you please assign this to someone or should we disable this test?

Flags: needinfo?(jteh)

Yura, do you think the re-occurrence of this is related to bug 1503084?

Flags: needinfo?(jteh)

Over the last 7 days there are 34 present on this bug. These happen on linux64, macosx1014-64, windows10-64, windows10-64-qr, windows7-32

Here is the most recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=269265135&repo=autoland&lineNumber=2398

Flags: needinfo?(jteh)
Whiteboard: [stockwell unknown] → [stockwell unknown][stockwell needswork:owner]
Attachment #9099513 - Attachment description: Bug 1388256 - disabled browser_caching_name.js on debug mac and win, linux64 r?#intermittent-reviewers → Bug 1388256 - disabled browser_caching_name.js on debug mac and win, linux64 r=gbrown
Keywords: leave-open
Whiteboard: [stockwell unknown][stockwell needswork:owner] → [stockwell unknown][stockwell disabled]
Pushed by apavel@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/639b85978740
disabled browser_caching_name.js on debug mac and win, linux64 r=gbrown

@jteh, Looks like in most cases we time out because a reorder event is not received and around this assertion:

WARNING: NS_ENSURE_TRUE(!IsDefunct()) failed: file z:/build/build/src/accessible/windows/msaa/AccessibleWrap.cpp, line 1151

Status: REOPENED → RESOLVED
Closed: 7 years ago → 4 years ago
Flags: needinfo?(yzenevich)
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: