Closed Bug 945675 Opened 11 years ago Closed 9 years ago

Intermittent TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status

Categories

(Firefox for Android Graveyard :: General, defect)

Product:
Firefox for Android Graveyard
Component:
General
Platform:
ARM
Android
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 1252570

People

(Reporter: cbook, Unassigned)

References

(
URL
)

Details

(Keywords: intermittent-failure, Whiteboard: [test disabled][leave open])

Android 2.2 Armv6 Tegra fx-team opt test robocop-2 on 2013-12-03 00:54:12 PST for push 1659537d5ed3 slave: tegra-225 https://tbpl.mozilla.org/php/getParsedLog.php?id=31369349&tree=Fx-Team 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status junit.framework.AssertionFailedError: 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 13 INFO TEST-UNEXPECTED-FAIL | testMozPay | Exception caught - junit.framework.AssertionFailedError: 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 12-03 01:20:30.094 I/Robocop ( 6667): 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 12-03 01:20:30.124 I/Robocop ( 6667): junit.framework.AssertionFailedError: 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 12-03 01:20:30.124 I/Robocop ( 6667): 13 INFO TEST-UNEXPECTED-FAIL | testMozPay | Exception caught - junit.framework.AssertionFailedError: 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status 12-03 01:20:31.264 I/TestRunner( 6667): junit.framework.AssertionFailedError: 13 INFO TEST-UNEXPECTED-FAIL | testMozPay | Exception caught - junit.framework.AssertionFailedError: 12 INFO TEST-UNEXPECTED-FAIL | testMozPay | GeckoEventExpecter - blockForEvent timeout: Robocop:Status Mochi-Remote ERROR | Automation Error: Missing end of test marker (process crashed?)
This seems to only happen on Armv6. I see an exception in the logcats: 12-05 05:29:50.256 D/GeckoTabs( 6628): handleMessage: Content:LocationChange 12-05 05:29:50.256 D/GeckoTab( 6628): Ignoring location change event: URIs are the same. 12-05 05:29:50.256 D/GeckoTabs( 6628): handleMessage: Content:SecurityChange 12-05 05:29:50.286 D/GeckoToolbar( 6628): onTabChanged: FAVICON 12-05 05:29:50.286 D/GeckoBrowserApp( 6628): BrowserApp.onTabChanged: 0: FAVICON 12-05 05:29:50.286 D/GeckoToolbar( 6628): onTabChanged: SECURITY_CHANGE 12-05 05:29:50.286 D/GeckoBrowserApp( 6628): BrowserApp.onTabChanged: 1: SECURITY_CHANGE 12-05 05:29:50.296 D/GeckoTabs( 6628): handleMessage: DOMTitleChanged 12-05 05:29:50.306 D/GeckoTabs( 6628): handleMessage: DOMContentLoaded 12-05 05:29:50.306 E/GeckoConsole( 6628): [JavaScript Error: "uncaught exception: Can't find method getMCC"] 12-05 05:29:50.316 W/dalvikvm( 6628): JNI WARNING: JNI method called with exception raised 12-05 05:29:50.316 W/dalvikvm( 6628): in Lorg/mozilla/gecko/mozglue/GeckoLoader;.nativeRun (Ljava/lang/String;)V (CallBooleanMethodV) 12-05 05:29:50.316 W/dalvikvm( 6628): Pending exception is: 12-05 05:29:50.316 I/dalvikvm( 6628): Ljava/lang/NoSuchMethodError;: getMCC 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:372) 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:177) 12-05 05:29:50.316 I/dalvikvm( 6628): "Gecko" prio=5 tid=12 NATIVE 12-05 05:29:50.316 I/dalvikvm( 6628): | group="main" sCount=0 dsCount=0 s=N obj=0x48583600 self=0x26ee40 12-05 05:29:50.316 I/dalvikvm( 6628): | sysTid=6645 nice=0 sched=0/0 cgrp=unknown handle=2551680 12-05 05:29:50.316 I/dalvikvm( 6628): | schedstat=( 3928030000 663654000 1847 ) 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.GeckoAppShell.runGecko(GeckoAppShell.java:372) 12-05 05:29:50.316 I/dalvikvm( 6628): at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:177) 12-05 05:29:50.316 I/dalvikvm( 6628): 12-05 05:29:50.316 E/dalvikvm( 6628): VM aborting 12-05 05:29:50.356 D/GeckoToolbar( 6628): onTabChanged: TITLE 12-05 05:29:50.356 D/GeckoBrowserApp( 6628): BrowserApp.onTabChanged: 1: TITLE 12-05 05:29:50.356 D/GeckoToolbar( 6628): onTabChanged: LOADED 12-05 05:29:50.356 D/GeckoBrowserApp( 6628): BrowserApp.onTabChanged: 1: LOADED 12-05 05:29:50.556 D/GeckoThumbnailHelper( 6628): Using new thumbnail size: 242544 (width 326) 12-05 05:29:50.556 D/GeckoThumbnailHelper( 6628): Sending thumbnail event: 326, 186
wesj had a look at this today, but no fix was obvious. Disabled on Android 2.2 only: https://hg.mozilla.org/integration/mozilla-inbound/rev/36bd64203d5d
Whiteboard: [test disabled][leave open]
I see now that this test is failing even more often on Panda, it just isn't causing the test to be reported as a failure on tbpl (darn mozharness!): https://tbpl.mozilla.org/php/getParsedLog.php?id=31592786&tree=Mozilla-Inbound&full=1#error0 https://tbpl.mozilla.org/php/getParsedLog.php?id=31592311&tree=Mozilla-Inbound&full=1#error0 Disabled entirely now: https://hg.mozilla.org/integration/mozilla-inbound/rev/26fb7e60d288
This was probably fixed by bug 956417.
Maybe we should try re-enabling the test to check if it was really fixed by 956417.
It fails differently now: http://ftp.mozilla.org/pub/mozilla.org/mobile/try-builds/gbrown@mozilla.com-1d91d69cdb2f/try-android-api-11/try_panda_android_test-robocop-5-bm101-tests1-panda-build3049.txt.gz 09:46:34 INFO - TEST-START | testMozPay 09:46:34 INFO - TEST-PASS | testMozPay | Robocop tests need the test device screen to be powered on. - 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready 09:46:34 INFO - EventExpecter: no longer listening for Gecko:Ready 09:46:34 INFO - Registered listener for Robocop:JS 09:46:34 INFO - Loading JavaScript test from http://mochi.test:8888/tests/robocop/robocop_javascript.html?slug=1420019189100&path=testMozPay.js 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 1 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - (xpcshell/head.js) | test 1 pending 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | test 2 pending\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - (xpcshell/head.js) | test 2 pending 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"\nTEST-INFO | testMozPay.js | Starting test_get_set","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | Starting test_get_set 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"\nTEST-UNEXPECTED-FAIL | testMozPay.js | undefined == Fake Provider - See following stack:\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 WARNING - TEST-UNEXPECTED-FAIL | testMozPay | testMozPay.js - undefined == Fake Provider - See following stack: 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: robocop_head.js :: do_throw :: line 472\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: robocop_head.js :: do_throw :: line 472 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: robocop_head.js :: do_report_result :: line 574\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: robocop_head.js :: do_report_result :: line 574 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: robocop_head.js :: _do_check_eq :: line 584\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: robocop_head.js :: _do_check_eq :: line 584 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: robocop_head.js :: do_check_eq :: line 591\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: robocop_head.js :: do_check_eq :: line 591 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: testMozPay.js :: test_get_set\/< :: line 54\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: testMozPay.js :: test_get_set/< :: line 54 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: jar:jar:file:\/\/\/data\/app\/org.mozilla.fennec-1.apk!\/assets\/omni.ja!\/components\/PaymentsUI.js :: confirmPaymentRequest :: line 80\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: jar:jar:file:///data/app/org.mozilla.fennec-1.apk!/assets/omni.ja!/components/PaymentsUI.js :: confirmPaymentRequest :: line 80 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: testMozPay.js :: test_get_set :: line 51\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: testMozPay.js :: test_get_set :: line 51 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: self-hosted :: next :: line 945\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: self-hosted :: next :: line 945 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: resource:\/\/gre\/modules\/Task.jsm :: TaskImpl_run :: line 330\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 330 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: resource:\/\/gre\/modules\/Task.jsm :: TaskImpl :: line 275\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: resource://gre/modules/Task.jsm :: TaskImpl :: line 275 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: resource:\/\/gre\/modules\/Task.jsm :: createAsyncFunction\/asyncFunction :: line 249\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: resource://gre/modules/Task.jsm :: createAsyncFunction/asyncFunction :: line 249 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: resource:\/\/gre\/modules\/Task.jsm :: Task_spawn :: line 164\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: resource://gre/modules/Task.jsm :: Task_spawn :: line 164 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: robocop_head.js :: _run_next_test :: line 1118\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: robocop_head.js :: _run_next_test :: line 1118 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"JS frame :: robocop_head.js :: do_execute_soon\/<.run :: line 439\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | JS frame :: robocop_head.js :: do_execute_soon/<.run :: line 439 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - testMozPay.js | native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0 09:46:34 INFO - TEST-PASS | testMozPay | Given message occurred for registered event: {"message":"\nTEST-INFO | (xpcshell\/head.js) | exiting test\n","innerType":"progress","type":"Robocop:JS"} - Robocop:JS should equal Robocop:JS 09:46:34 INFO - (xpcshell/head.js) | exiting test 09:46:34 INFO - EventExpecter: no longer listening for Robocop:JS 09:46:34 INFO - Unregistered listener for Robocop:JS 09:46:34 INFO - TEST-OK | testMozPay | took 6695ms 09:46:34 INFO - TEST-START | Shutdown 09:46:34 INFO - Passed: 22 09:46:34 INFO - Failed: 1 09:46:34 INFO - Todo: 0 09:46:34 INFO - SimpleTest FINISHED
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → DUPLICATE
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.