Intermittent browser_apzc.js | uncaught exception - NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIDOMWindowUtils.sendNativeTouchPoint] | Test timed out

RESOLVED FIXED in Firefox 29

Status

Firefox for Metro
Tests
P2
normal
RESOLVED FIXED
5 years ago
4 years ago

People

(Reporter: RyanVM, Assigned: jimm)

Tracking

({intermittent-failure})

unspecified
Firefox 30
x86
Windows 8
intermittent-failure
Dependency tree / graph

Firefox Tracking Flags

(firefox28 wontfix, firefox29 fixed, firefox30 fixed, firefox-esr24 unaffected)

Details

(Whiteboard: p=2 s=it-30c-29a-28b.3 r=ff30 [qa-])

Attachments

(1 attachment)

(Reporter)

Description

5 years ago
https://tbpl.mozilla.org/php/getParsedLog.php?id=34068632&tree=Fx-Team

WINNT 6.2 fx-team pgo test mochitest-metro-chrome on 2014-02-04 08:30:58 PST for push f989ab51fa44
slave: t-w864-ix-076

08:34:20     INFO -  TEST-PASS | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/res/scroll_test_tall.html is loaded
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] start: 1005ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] main: 1051ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] selectProfile: 1179ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] startupCrashDetectionBegin: 1291ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] firstPaint: 3086ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] sessionRestored: 2451ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] createTopLevelWindow: 1802ms
08:34:20     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [timing] firstLoadURI: 3843ms
08:34:20     INFO -  MetroWidget::ApzContentIgnoringTouch
08:34:21     INFO -  InjectTouchInput failure. GetLastError=1460
08:34:21  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | uncaught exception - NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIDOMWindowUtils.sendNativeTouchPoint] at chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js:884
08:34:21     INFO -  Stack trace:
08:34:21     INFO -      JS frame :: chrome://mochikit/content/tests/SimpleTest/SimpleTest.js :: simpletestOnerror :: line 1218
08:34:21     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
08:34:21     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Console message: [JavaScript Error: "NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIDOMWindowUtils.sendNativeTouchPoint]" {file: "chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js" line: 884}]
08:34:48     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Longer timeout required, waiting longer...  Remaining timeouts: 1
08:35:19     INFO -  ['C:\\slave\\test\\build\\tests\\bin\\screenshot.exe'] exited with code 1
08:35:19  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | Test timed out
08:35:19     INFO -  TEST-INFO | MEMORY STAT vsize after test: 517210112
08:35:19     INFO -  TEST-INFO | MEMORY STAT vsizeMaxContiguous after test: 1893662720
08:35:19     INFO -  TEST-INFO | MEMORY STAT residentFast after test: 108040192
08:35:19     INFO -  TEST-INFO | MEMORY STAT heapAllocated after test: 29479720
08:35:19     INFO -  INFO TEST-END | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | finished in 60033ms
08:35:19     INFO -  TEST-INFO | checking window state
08:35:19     INFO -  TEST-START | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js
08:35:19     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | RUN deck offset
08:35:19     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Opening about:mozilla in a new tab
08:35:19     INFO -  ### Content.js loaded
08:35:19     INFO -  ### FormHelper.js loaded
08:35:19     INFO -  ### SelectionPrototype.js loaded
08:35:19     INFO -  ### SelectionHandler.js loaded
08:35:19     INFO -  ### ContextMenuHandler.js loaded
08:35:19     INFO -  ### ConsoleAPIObserver.js loaded
08:35:19     INFO -  TEST-PASS | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | about:mozilla is loaded
08:35:19     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 3000ms
08:35:22     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 3001ms
08:35:22     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:23     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 501ms
08:35:23     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:24     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 501ms
08:35:24     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:25     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 502ms
08:35:26     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:26     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 502ms
08:35:27     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:27     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 502ms
08:35:28     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:28     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 502ms
08:35:29     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:29     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 501ms
08:35:30     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:31     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 501ms
08:35:31     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:32     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 501ms
08:35:32     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Wating for 500ms
08:35:33     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | PERF-TEST | DECLARE {"id":"ecb5fbec-0b3d-490f-8d4a-13fa8963e54a","version":"1","name":"shift browser deck","category":"browser","subcategory":"ux","description":"Triggers multiple SKB deck shifting operations using an offset value of 300px. Measures total time in milliseconds for a up/down shift operation plus the total number of frames. Strips outliers.","buildid":"20140204060002"}
08:35:33     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | PERF-TEST | RESULTS {"id":"ecb5fbec-0b3d-490f-8d4a-13fa8963e54a","version":"1","results":{"r0":{"value":637.6310965668947,"desc":"msec"},"r1":{"value":36.888888888888886,"desc":"frame count"}}}
08:35:33     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | END deck offset
08:35:33     INFO -  DownloadNotificationsView handleEvent, got TabClose event for browser: [object XULElement]
08:35:33  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Left over tab after test: 'chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/res/scroll_test.html'
08:35:33     INFO -  Stack trace:
08:35:33     INFO -      JS frame :: chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js :: runTests/</< :: line 1016
08:35:33     INFO -      JS frame :: chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js :: runTests/< :: line 1011
08:35:33     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 233
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 118
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 43
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 185
08:35:33     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 242
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 118
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 43
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 185
08:35:33     INFO -      JS frame :: chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js :: done :: line 397
08:35:33     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
08:35:33  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | Left over tab after test: 'chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/res/scroll_test_tall.html'
08:35:33     INFO -  Stack trace:
08:35:33     INFO -      JS frame :: chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js :: runTests/</< :: line 1016
08:35:33     INFO -      JS frame :: chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js :: runTests/< :: line 1011
08:35:33     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 233
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 118
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 43
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 185
08:35:33     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 242
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 118
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 43
08:35:33     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 185
08:35:33     INFO -      JS frame :: chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js :: done :: line 397
08:35:33     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
08:35:33     INFO -  DownloadNotificationsView handleEvent, got TabClose event for browser: [object XULElement]
08:35:33     INFO -  DownloadNotificationsView handleEvent, got TabClose event for browser: [object XULElement]
08:35:33     INFO -  TEST-INFO | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | waitForMs finished waiting, waited for 510ms
08:35:33     INFO -  TEST-INFO | MEMORY STAT vsize after test: 474783744
08:35:33     INFO -  TEST-INFO | MEMORY STAT vsizeMaxContiguous after test: 1893662720
08:35:33     INFO -  TEST-INFO | MEMORY STAT residentFast after test: 116183040
08:35:33     INFO -  TEST-INFO | MEMORY STAT heapAllocated after test: 29260792
08:35:33     INFO -  INFO TEST-END | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_deck_01.js | finished in 14657ms
(Assignee)

Comment 1

5 years ago
08:34:21  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/metro/browser/metro/base/tests/mochiperf/browser_apzc.js | uncaught exception - NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIDOMWindowUtils.sendNativeTouchPoint] at chrome://mochitests/content/metro/browser/metro/base/tests/mochitest/head.js:884

Looks like our native touch injection apis barfed for some reason. We can trap these if need be. First time I've seen this though.
(Assignee)

Updated

5 years ago
Blocks: 880298

Updated

5 years ago
Blocks: 861680
Whiteboard: [defect] p=0
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Updated

4 years ago
Priority: -- → P2
Comment hidden (Treeherder Robot)

Updated

4 years ago
Whiteboard: [defect] p=0 → p=0
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(Assignee)

Updated

4 years ago
Assignee: nobody → jmathies
Whiteboard: p=0 → p=2
Comment hidden (Treeherder Robot)
(Assignee)

Comment 23

4 years ago
Created attachment 8386381 [details] [diff] [review]
potential fix

Turns out there's a 100msec max delay between injections that Windows sets, which is the error we're getting. Tightening up the interval should help, although I imagine there's probably no way to avoid a rare failure due to hangs, gc, and what not during test runs.

Need to push this to try for a bunch of test runs.
(Assignee)

Comment 25

4 years ago
Comment on attachment 8386381 [details] [diff] [review]
potential fix

Lets land this and see if it helps. Looks like it might.
Attachment #8386381 - Flags: review?(mbrubeck)
Attachment #8386381 - Flags: review?(mbrubeck) → review+

Updated

4 years ago
Status: NEW → ASSIGNED
QA Contact: kamiljoz
Whiteboard: p=2 → p=2 s=it-30c-29a-28b.3 r=ff30
(Assignee)

Comment 26

4 years ago
remote:   https://hg.mozilla.org/integration/fx-team/rev/0d6826801df6

Thanks for the quick review!
Comment hidden (Treeherder Robot)
https://hg.mozilla.org/mozilla-central/rev/0d6826801df6
Status: ASSIGNED → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 30
Hey Kamil and Jim, should this bug be [qa+] or [qa-] for verification?
Flags: needinfo?(kamiljoz)
Flags: needinfo?(jmathies)
(Reporter)

Comment 30

4 years ago
https://hg.mozilla.org/releases/mozilla-aurora/rev/2c13252f2d7f

I have this in my queue to push to beta as a ride-along as well.
status-firefox28: --- → affected
status-firefox29: --- → fixed
status-firefox30: --- → fixed
status-firefox-esr24: --- → unaffected
(Assignee)

Comment 31

4 years ago
(In reply to Marco Mucci [:MarcoM] from comment #29)
> Hey Kamil and Jim, should this bug be [qa+] or [qa-] for verification?

nothing to test here, marking qa-.

(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #30)
> https://hg.mozilla.org/releases/mozilla-aurora/rev/2c13252f2d7f
> 
> I have this in my queue to push to beta as a ride-along as well.

Per comment 23 I can't promise this will fix the problem 100% since jank in the browser can trigger this. But hopefully I've minimized occurrences. We'll see after a few days.
Flags: needinfo?(jmathies)
Whiteboard: p=2 s=it-30c-29a-28b.3 r=ff30 → [qa-] p=2 s=it-30c-29a-28b.3 r=ff30
Comment hidden (Treeherder Robot)
(Reporter)

Updated

4 years ago
status-firefox28: affected → wontfix
Flags: needinfo?(kamiljoz)
Whiteboard: [qa-] p=2 s=it-30c-29a-28b.3 r=ff30 → [qa-] p=2 s=it-30c-29a-28b.3 r=ff30 [qa-]
Whiteboard: [qa-] p=2 s=it-30c-29a-28b.3 r=ff30 [qa-] → p=2 s=it-30c-29a-28b.3 r=ff30 [qa-]
You need to log in before you can comment on or make changes to this bug.