Closed Bug 967613 Opened 11 years ago Closed 11 years ago

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

Categories

(Firefox for Metro Graveyard :: Tests, defect, P2)

Product:
Firefox for Metro Graveyard
Component:
Tests
Platform:
x86
Windows 8
Type:
defect

Tracking

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

Status:
RESOLVED FIXED
Milestone:
Firefox 30
Tracking Flags:
Tracking Status
firefox28 --- wontfix
firefox29 --- fixed
firefox30 --- fixed
firefox-esr24 --- unaffected

People

(Reporter: RyanVM, Assigned: jimm)

References

Details

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

Attachments

(1 file)

potential fix
2.25 KB, patch
mbrubeck
: review+
Details | Diff | Splinter Review
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
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.
Blocks: 880298
Blocks: metrobacklog
Whiteboard: [defect] p=0
Priority: -- → P2
Whiteboard: [defect] p=0 → p=0
Assignee: nobody → jmathies
Whiteboard: p=0 → p=2
Attached patch potential fix — — Splinter Review
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.
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+
Status: NEW → ASSIGNED
QA Contact: kamiljoz
Whiteboard: p=2 → p=2 s=it-30c-29a-28b.3 r=ff30
remote: https://hg.mozilla.org/integration/fx-team/rev/0d6826801df6 Thanks for the quick review!
https://hg.mozilla.org/mozilla-central/rev/0d6826801df6
Status: ASSIGNED → RESOLVED
Closed: 11 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)
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
(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
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.

Attachment

General

Creator:
Created:
Updated:
Size: