Closed Bug 967613 Opened 10 years ago Closed 10 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: 10 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: