Closed Bug 1587959 Opened 5 years ago Closed 5 years ago

Intermittent accessible/tests/browser/events/browser_test_focus_urlbar.js | wrong state bits for [DOM node id: urlbar-input, role: entry, name: 'Search with Google or enter address', address: 0x12af996a0]!got '0', expected 'focused' -

Categories

(Firefox :: Address Bar, defect, P2)

Product:
Firefox
Component:
Address Bar
Type:
defect
Points:
2

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 71
Iteration:
71.4 - Oct 14 - 20
Tracking Flags:
Tracking Status
firefox71 --- fixed

People

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

References

Details

(Keywords: access, intermittent-failure, Whiteboard: [access-p2])

Attachments

(1 file)

Bug 1587959 - The userSelectionBehavior property of the urlbar controller may get stale and confuse a11y. r=Standard8
47 bytes, text/x-phabricator-request
Details | Review

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=270779149&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/XY4ZUpwiQbeKh2l3WIFlug/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/XY4ZUpwiQbeKh2l3WIFlug/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2019-10-10T21:05:18.893Z] 21:05:18 INFO - TEST-START | accessible/tests/browser/events/browser_test_focus_urlbar.js
[task 2019-10-10T21:05:18.963Z] 21:05:18 INFO - GECKO(1661) | [1669, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:18.963Z] 21:05:18 INFO - GECKO(1661) | [1669, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:18.964Z] 21:05:18 INFO - GECKO(1661) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/36/klpkks_52sn740vy6z74ktnh000017/T/tmpwZe1wC.mozrunner/runtests_leaks_tab_pid1669.log
[task 2019-10-10T21:05:18.964Z] 21:05:18 INFO - GECKO(1661) | [1669, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:18.964Z] 21:05:18 INFO - GECKO(1661) | [1669, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:19.007Z] 21:05:19 INFO - GECKO(1661) | [Child 1669, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 732
[task 2019-10-10T21:05:19.616Z] 21:05:19 INFO - GECKO(1661) | ++DOCSHELL 0x107239800 == 1 [pid = 1669] [id = {26c760c4-a8b5-0441-b19d-a2eb5ec3a0ab}]
[task 2019-10-10T21:05:19.625Z] 21:05:19 INFO - GECKO(1661) | ++DOMWINDOW == 1 (0x11fb4d020) [pid = 1669] [serial = 1] [outer = 0x0]
[task 2019-10-10T21:05:19.646Z] 21:05:19 INFO - GECKO(1661) | ++DOMWINDOW == 2 (0x119ce4800) [pid = 1669] [serial = 2] [outer = 0x11fb4d020]
[task 2019-10-10T21:05:19.776Z] 21:05:19 INFO - GECKO(1661) | ++DOMWINDOW == 3 (0x11fbafc00) [pid = 1669] [serial = 3] [outer = 0x11fb4d020]
[task 2019-10-10T21:05:19.777Z] 21:05:19 INFO - GECKO(1661) | [Child 1669, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80070057: file /builds/worker/workspace/build/src/dom/base/ThirdPartyUtil.cpp, line 217
[task 2019-10-10T21:05:20.214Z] 21:05:20 INFO - GECKO(1661) | --DOCSHELL 0x1191d9800 == 1 [pid = 1664] [id = {fe3ca3d5-749f-5247-8c69-d82573ab4968}] [url = about:blank]
[task 2019-10-10T21:05:20.517Z] 21:05:20 INFO - GECKO(1661) | [1670, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:20.517Z] 21:05:20 INFO - GECKO(1661) | [1670, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:20.517Z] 21:05:20 INFO - GECKO(1661) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/36/klpkks_52sn740vy6z74ktnh000017/T/tmpwZe1wC.mozrunner/runtests_leaks_tab_pid1670.log
[task 2019-10-10T21:05:20.517Z] 21:05:20 INFO - GECKO(1661) | [1670, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:20.518Z] 21:05:20 INFO - GECKO(1661) | [1670, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-10T21:05:20.569Z] 21:05:20 INFO - GECKO(1661) | [Child 1670, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 732
[task 2019-10-10T21:05:20.715Z] 21:05:20 INFO - TEST-INFO | started process screencapture
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - TEST-INFO | screencapture: exit 0
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - Buffered messages logged at 21:05:18
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - Entering test bound
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - Buffered messages logged at 21:05:19
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - TEST-PASS | accessible/tests/browser/events/browser_test_focus_urlbar.js | Recieved document load complete event -
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - Buffered messages logged at 21:05:20
[task 2019-10-10T21:05:20.896Z] 21:05:20 INFO - TEST-PASS | accessible/tests/browser/events/browser_test_focus_urlbar.js | Recieved focus event -
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - Ensuring no focus change when first text is typed
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - Buffered messages finished
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - TEST-UNEXPECTED-FAIL | accessible/tests/browser/events/browser_test_focus_urlbar.js | wrong state bits for [DOM node id: urlbar-input, role: entry, name: 'Search with Google or enter address', address: 0x12af996a0]!got '0', expected 'focused' -
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - Stack trace:
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - chrome://mochikit/content/browser-test.js:test_ok:1575
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - chrome://mochitests/content/a11y/accessible/tests/mochitest/states.js:isState:359
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - chrome://mochitests/content/a11y/accessible/tests/mochitest/states.js:testStates:90
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - chrome://mochitests/content/browser/accessible/tests/browser/events/browser_test_focus_urlbar.js:runTests:84
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:addAccessibleTask/</<:297
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - resource://testing-common/BrowserTestUtils.jsm:withNewTab:136
[task 2019-10-10T21:05:20.897Z] 21:05:20 INFO - chrome://mochitests/content/browser/accessible/tests/browser/shared-head.js:addAccessibleTask/<:268
[task 2019-10-10T21:05:20.898Z] 21:05:20 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1345
[task 2019-10-10T21:05:20.898Z] 21:05:20 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1380
[task 2019-10-10T21:05:20.898Z] 21:05:20 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1202
[task 2019-10-10T21:05:20.898Z] 21:05:20 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:805
[task 2019-10-10T21:05:20.898Z] 21:05:20 INFO - TEST-PASS | accessible/tests/browser/events/browser_test_focus_urlbar.js | Singleline [DOM node id: urlbar-input, role: entry, name: 'Search with Google or enter address', address: 0x12af996a0] cannot be multiline! -
[task 2019-10-10T21:05:20.898Z] 21:05:20 INFO - TEST-PASS | accessible/tests/browser/events/browser_test_focus_urlbar.js | Collapsed or expanded [DOM node id: urlbar-input, role: entry, name: 'Search with Google or enter address', address: 0x12af996a0] must be expandable! -

So far this is just on TV.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Status: RESOLVED → REOPENED
Resolution: FIXED → ---

If I run this test with --verify locally, it constantly fails, that makes me think TV is a permanent failure, not an intermittent one.

The problem is that I have a small urlbar patch also touching this test, if I land it TV will fail, so I'm blocked.
I don't know much about this accessibility testing, but the failure is reproducible, so it should be understandable to someone more comfortable with a11y code.

Jamie, any idea or suggestion?

Flags: needinfo?(jteh)

This suggests that in some cases, clearing the URL bar then typing some text causes aria-activedescendant to be set to an autocomplete suggestion. That's incorrect behaviour: aria-activedescendant isn't supposed to be set unless the user presses down/up arrow. I think I've actually seen this using the address bar myself, but it definitely doesn't always occur. I'm not entirely sure what triggers it. It's definitely a bug we should fix. My hunch is that it is probably timing related and probably related to multiple uses of the URL bar, which is why it shows up with --verify.

Flags: needinfo?(jteh)

It always shows up at the first testStates() in browser_test_focus_urlbar.js. basically the test runs once without problems, then TV runs it again in the same window and it fails immediately here:
https://searchfox.org/mozilla-central/rev/ebe492edacc75bb122a2b380e4cafcca3470864c/accessible/tests/browser/events/browser_test_focus_urlbar.js#94

I'll have a look at that attribute.
In the worst case, would it be ok to disable this test only on verify, if I can't find the cause of this failure? Even if the behavior is manually intermittent, it's a permanent failure in TV. Any patch touching this test will look like breaking it, because TV only runs the tests modified by a changeset.

Flags: needinfo?(jteh)

I figured out how to reliably repro this manually:

  1. Press control+t to open a new tab, which focuses the address bar.
  2. Type: t
    • Observe: aria-activedescendant on #urlbar-input is not present.
  3. Press down arrow.
    • Observe: aria-activedescendant on #urlbar-input is present.
  4. Press escape twice.
    • Observe: aria-activedescendant on #urlbar-input is not present.
  5. Type: t
    • Expected: aria-activedescendant on #urlbar-input should not be present.
    • Actual: it is present.

I'm really reluctant to disable this even for verify given that it is actually symptomatic of a real problem. If you need to do so to unblock something urgent, that's fair; this bug is definitely not immediately critical from my perspective. However, I think it needs to be fixed properly sooner rather than later.

Flags: needinfo?(jteh)

Moving this to address bar, since (as per comment 8) this is a bug that needs to be fixed there.

Component: Disability Access APIs → Address Bar
Keywords: access
Product: Core → Firefox
Whiteboard: [access-p2]

I think I may have a patch for this.

Assignee: nobody → mak77
Status: REOPENED → ASSIGNED
Iteration: --- → 71.4 - Oct 14 - 20
Points: --- → 2
Priority: P5 → P2

Thanks Jamie for the hint on the "aria-activedescendant" attribute, it was very useful.

Pushed by mak77@bonardo.net:
https://hg.mozilla.org/integration/autoland/rev/15cbe8345e7a
The userSelectionBehavior property of the urlbar controller may get stale and confuse a11y. r=Standard8

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

Status: ASSIGNED → RESOLVED
Closed: 5 years ago → 5 years ago
status-firefox71: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 71
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: