986164 - android 2.3 testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Testing, defect)

Description

[Geoff Brown [:gbrown] (pto Apr 11-18)]

After resolving Bug 979612, I'm finding some new intermittent failures of testPictureLinkContextMenu on Android 2.3.

https://tbpl.mozilla.org/php/getParsedLog.php?id=36456826&tree=Ash&full=1

11:36:55     INFO -  0 INFO SimpleTest START
11:36:55     INFO -  1 INFO TEST-START | testPictureLinkContextMenu
11:36:55     INFO -  2 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
11:36:55     INFO -  EventExpecter: no longer listening for Gecko:Ready
11:36:55     INFO -  3 INFO TEST-PASS | testPictureLinkContextMenu | waiting for urlbar text to gain focus - urlbar text gained focus
11:36:55     INFO -  4 INFO TEST-PASS | testPictureLinkContextMenu | URL typed properly - http://mochi.test:8888/tests/robocop/robocop_picture_link.html should equal http://mochi.test:8888/tests/robocop/robocop_picture_link.html
11:36:55     INFO -  5 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"errorType":"","bgColor":"transparent","type":"DOMContentLoaded","tabID":0} - DOMContentLoaded should equal DOMContentLoaded
11:36:55     INFO -  EventExpecter: no longer listening for DOMContentLoaded
11:36:55     INFO -  PaintExpecter: no longer listening for events
11:36:55     INFO -  6 INFO TEST-PASS | testPictureLinkContextMenu | Page title is correct - Picture Link should equal Picture Link
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  7 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Copy Image Location is available - The option is available
11:36:55     INFO -  8 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Share Image is available - The option is available
11:36:55     INFO -  9 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Set Image As is available - The option is available
11:36:55     INFO -  10 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Save Image is available - The option is available
11:36:55     INFO -  11 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Open Link in New Tab is available - The option is available
11:36:55     INFO -  12 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Open Link in Private Tab is available - The option is available
11:36:55     INFO -  13 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Copy Link is available - The option is available
11:36:55     INFO -  14 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Share Link is available - The option is available
11:36:55     INFO -  15 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Bookmark Link is available - The option is available
11:36:55     INFO -  Clipboard text =  , expected text = Firefox.jpg
11:36:55     INFO -  Clipboard text =  , expected text = Firefox.jpg
11:36:55     INFO -  Clipboard text =  , expected text = Firefox.jpg
11:36:55     INFO -  Clipboard text =  , expected text = Firefox.jpg
11:36:55     INFO -  Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = Firefox.jpg
11:36:55     INFO -  16 INFO TEST-PASS | testPictureLinkContextMenu | Checking if the text is correctly copied - The text was correctly copied
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  17 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the share pop-up is displayed - The pop-up has been displayed
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  18 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"parentId":0,"delayLoad":false,"title":"http:\/\/mochi.test:8888\/tests\/robocop\/robocop_blank_02.html","selected":false,"isPrivate":false,"stub":false,"external":false,"desktopMode":false,"tabID":1,"type":"Tab:Added","uri":"http:\/\/mochi.test:8888\/tests\/robocop\/robocop_blank_02.html"} - Tab:Added should equal Tab:Added
11:36:55     INFO -  EventExpecter: no longer listening for Tab:Added
11:36:55     INFO -  19 INFO TEST-PASS | testPictureLinkContextMenu | The correct number of tabs are opened - 2 should equal 2
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  20 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"parentId":0,"delayLoad":false,"title":"http:\/\/mochi.test:8888\/tests\/robocop\/robocop_blank_02.html","selected":false,"isPrivate":true,"stub":false,"external":false,"desktopMode":false,"tabID":2,"type":"Tab:Added","uri":"http:\/\/mochi.test:8888\/tests\/robocop\/robocop_blank_02.html"} - Tab:Added should equal Tab:Added
11:36:55     INFO -  EventExpecter: no longer listening for Tab:Added
11:36:55     INFO -  21 INFO TEST-PASS | testPictureLinkContextMenu | The correct number of tabs are opened - 2 should equal 2
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  Clipboard text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  22 INFO TEST-PASS | testPictureLinkContextMenu | Checking if the text is correctly copied - The text was correctly copied
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  23 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the share pop-up is displayed - The pop-up has been displayed
11:36:55     INFO -  long-clicking at 512.0, 103.0
11:36:55     INFO -  24 INFO TEST-PASS | testPictureLinkContextMenu | Waiting for the Bookmark added toaster notification - The notification has been displayed
11:36:55     INFO -  25 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked
11:36:55     INFO -  Exception caught during test!
11:36:55     INFO -  junit.framework.AssertionFailedError: 25 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked
11:36:55     INFO -  	at junit.framework.Assert.fail(Assert.java:47)
11:36:55     INFO -  	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:110)
11:36:55     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:139)
11:36:55     INFO -  	at org.mozilla.gecko.tests.ContentContextMenuTest.verifyBookmarkLinkOption(ContentContextMenuTest.java:82)
11:36:55     INFO -  	at org.mozilla.gecko.tests.testPictureLinkContextMenu.testPictureLinkContextMenu(testPictureLinkContextMenu.java:33)
11:36:55     INFO -  	at java.lang.reflect.Method.invokeNative(Native Method)
11:36:55     INFO -  	at java.lang.reflect.Method.invoke(Method.java:507)
11:36:55     INFO -  	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204)
11:36:55     INFO -  	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194)
11:36:55     INFO -  	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186)
11:36:55     INFO -  	at org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:152)
11:36:55     INFO -  	at junit.framework.TestCase.runBare(TestCase.java:127)
11:36:55     INFO -  	at junit.framework.TestResult$1.protect(TestResult.java:106)
11:36:55     INFO -  	at junit.framework.TestResult.runProtected(TestResult.java:124)
11:36:55     INFO -  	at junit.framework.TestResult.run(TestResult.java:109)
11:36:55     INFO -  	at junit.framework.TestCase.run(TestCase.java:118)
11:36:55     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)
11:36:55     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)
11:36:55     INFO -  	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:529)
11:36:55     INFO -  	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1448)
11:36:55     INFO -  26 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Exception caught - junit.framework.AssertionFailedError: 25 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked
11:36:55     INFO -  27 INFO TEST-END | testPictureLinkContextMenu | finished in 159361ms
11:36:55     INFO -  28 INFO TEST-START | Shutdown
11:36:55     INFO -  29 INFO Passed: 23
11:36:55  WARNING -  30 INFO Failed: 2
11:36:55  WARNING -  One or more unittests failed.
11:36:55     INFO -  31 INFO Todo: 0
11:36:55     INFO -  32 INFO SimpleTest FINISHED
11:36:55     INFO -  INFO | automation.py | Application ran for: 0:02:47.051175


11:36:55     INFO -  03-20 11:20:16.269 I/Robocop (  786): 20 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"parentId":0,"delayLoad":false,"title":"http:\/\/mochi.test:8888\/tests\/robocop\/robocop_blank_02.html","selected":false,"isPrivate":true,"stub":false,"external":false,"desktopMode":false,"tabID":2,"type":"Tab:Added","uri":"http:\/\/mochi.test:8888\/tests\/robocop\/robocop_blank_02.html"} - Tab:Added should equal Tab:Added
11:36:55     INFO -  03-20 11:20:16.269 D/Robocop (  786): received event Tab:Added
11:36:55     INFO -  03-20 11:20:16.280 D/Robocop (  786): unblocked on expecter for Tab:Added
11:36:55     INFO -  03-20 11:20:16.280 I/Robocop (  786): EventExpecter: no longer listening for Tab:Added
11:36:55     INFO -  03-20 11:20:16.289 I/Robocop (  786): 21 INFO TEST-PASS | testPictureLinkContextMenu | The correct number of tabs are opened - 2 should equal 2
11:36:55     INFO -  03-20 11:20:16.329 D/GeckoTabs(  786): handleMessage: Content:StateChange
11:36:55     INFO -  03-20 11:20:16.329 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:16.329 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:16.329 D/GeckoToolbar(  786): onTabChanged: START
11:36:55     INFO -  03-20 11:20:16.329 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: START
11:36:55     INFO -  03-20 11:20:17.070 D/GeckoTabs(  786): handleMessage: SessionHistory:New
11:36:55     INFO -  03-20 11:20:17.459 D/GeckoTabs(  786): handleMessage: Content:LocationChange
11:36:55     INFO -  03-20 11:20:17.459 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:17.459 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:17.499 D/GeckoToolbar(  786): onTabChanged: LOCATION_CHANGE
11:36:55     INFO -  03-20 11:20:17.499 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: LOCATION_CHANGE
11:36:55     INFO -  03-20 11:20:17.519 D/GeckoTabs(  786): handleMessage: Content:SecurityChange
11:36:55     INFO -  03-20 11:20:17.529 D/GeckoToolbar(  786): onTabChanged: SECURITY_CHANGE
11:36:55     INFO -  03-20 11:20:17.529 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: SECURITY_CHANGE
11:36:55     INFO -  03-20 11:20:17.770 D/GeckoTabs(  786): handleMessage: DOMTitleChanged
11:36:55     INFO -  03-20 11:20:17.770 D/GeckoToolbar(  786): onTabChanged: TITLE
11:36:55     INFO -  03-20 11:20:17.770 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: TITLE
11:36:55     INFO -  03-20 11:20:17.820 D/GeckoTabs(  786): handleMessage: Link:Favicon
11:36:55     INFO -  03-20 11:20:17.820 D/GeckoToolbar(  786): onTabChanged: LINK_FAVICON
11:36:55     INFO -  03-20 11:20:17.820 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: LINK_FAVICON
11:36:55     INFO -  03-20 11:20:17.980 D/GeckoTabs(  786): handleMessage: DOMContentLoaded
11:36:55     INFO -  03-20 11:20:17.980 D/GeckoToolbar(  786): onTabChanged: LOADED
11:36:55     INFO -  03-20 11:20:17.980 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: LOADED
11:36:55     INFO -  03-20 11:20:18.040 D/GeckoTabs(  786): handleMessage: Content:PageShow
11:36:55     INFO -  03-20 11:20:18.040 D/GeckoToolbar(  786): onTabChanged: PAGE_SHOW
11:36:55     INFO -  03-20 11:20:18.040 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: PAGE_SHOW
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): Error reading favicon
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): java.net.UnknownHostException: mochi.test
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at java.net.InetAddress.lookupHostByName(InetAddress.java:497)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at java.net.InetAddress.getAllByNameImpl(InetAddress.java:294)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at java.net.InetAddress.getAllByName(InetAddress.java:256)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:136)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:164)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:119)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:359)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:555)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:487)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:465)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at android.net.http.AndroidHttpClient.execute(AndroidHttpClient.java:243)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.favicons.LoadFaviconTask.tryDownloadRecurse(LoadFaviconTask.java:124)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.favicons.LoadFaviconTask.downloadAndDecodeImage(LoadFaviconTask.java:222)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.favicons.LoadFaviconTask.downloadFavicon(LoadFaviconTask.java:201)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.favicons.LoadFaviconTask.doInBackground$2d4c763b(LoadFaviconTask.java:407)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.favicons.LoadFaviconTask.doInBackground$42af7916(LoadFaviconTask.java:42)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.util.UiAsyncTask$BackgroundTaskRunnable.run(UiAsyncTask.java:48)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at android.os.Handler.handleCallback(Handler.java:587)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at android.os.Handler.dispatchMessage(Handler.java:92)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at android.os.Looper.loop(Looper.java:130)
11:36:55     INFO -  03-20 11:20:18.099 E/LoadFaviconTask(  786): 	at org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:32)
11:36:55     INFO -  03-20 11:20:18.119 D/GeckoToolbar(  786): onTabChanged: FAVICON
11:36:55     INFO -  03-20 11:20:18.119 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: FAVICON
11:36:55     INFO -  03-20 11:20:18.139 D/GeckoTabs(  786): handleMessage: Tab:ViewportMetadata
11:36:55     INFO -  03-20 11:20:18.139 D/GeckoToolbar(  786): onTabChanged: VIEWPORT_CHANGE
11:36:55     INFO -  03-20 11:20:18.139 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: VIEWPORT_CHANGE
11:36:55     INFO -  03-20 11:20:18.199 D/GeckoTabs(  786): handleMessage: Content:StateChange
11:36:55     INFO -  03-20 11:20:18.199 D/GeckoToolbar(  786): onTabChanged: STOP
11:36:55     INFO -  03-20 11:20:18.209 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: STOP
11:36:55     INFO -  03-20 11:20:18.249 E/Profiler(  786): BPUnw: [9 total] thread_register_for_profiling(me=0x357950, stacktop=0x580ffc97)
11:36:55     INFO -  03-20 11:20:18.711 D/GeckoThumbnailHelper(  786): Using new thumbnail size: 242544 (width 326)
11:36:55     INFO -  03-20 11:20:18.711 D/GeckoThumbnailHelper(  786): Sending thumbnail event: 326, 186
11:36:55     INFO -  03-20 11:20:19.160 D/GeckoThumbnailHelper(  786): handleThumbnailData: 242544
11:36:55     INFO -  03-20 11:20:21.379 I/Robocop (  786): long-clicking at 512.0, 103.0
11:36:55     INFO -  03-20 11:20:22.239 E/GeckoConsole(  786): Sending message
11:36:55     INFO -  03-20 11:20:24.389 E/Profiler(  786): BPUnw: [8 total] thread_unregister_for_profiling(me=0x2e7428) 
11:36:55     INFO -  03-20 11:20:25.670 I/Robocop (  786): Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  03-20 11:20:25.800 I/Robocop (  786): Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  03-20 11:20:25.964 I/Robocop (  786): Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  03-20 11:20:25.990 E/GeckoConsole(  786): observe {"guid":"","button":6,"list":[6],"__guid__":"{9b9c58cb-58a3-4be4-a778-908413ab4284}"}
11:36:55     INFO -  03-20 11:20:26.090 I/Robocop (  786): Clipboard text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html , expected text = http://mochi.test:8888/tests/robocop/robocop_blank_02.html
11:36:55     INFO -  03-20 11:20:26.109 I/Robocop (  786): 22 INFO TEST-PASS | testPictureLinkContextMenu | Checking if the text is correctly copied - The text was correctly copied
11:36:55     INFO -  03-20 11:20:26.199 W/InputManagerService(   64): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@4060f2a8
11:36:55     INFO -  03-20 11:20:27.219 I/Robocop (  786): long-clicking at 512.0, 103.0
11:36:55     INFO -  03-20 11:20:28.010 E/GeckoConsole(  786): Sending message
11:36:55     INFO -  03-20 11:20:30.628 I/Gecko   (  786): periodic check for webapp updates
11:36:55     INFO -  03-20 11:20:31.489 E/GeckoConsole(  786): observe {"guid":"","button":7,"list":[7],"__guid__":"{3907a7e2-dcb5-4228-9737-3450019d1ee4}"}
11:36:55     INFO -  03-20 11:20:31.539 I/ActivityManager(   64): Starting: Intent { act=android.intent.action.CHOOSER flg=0x4000000 cmp=android/com.android.internal.app.ChooserActivity (has extras) } from pid 786
11:36:55     INFO -  03-20 11:20:31.850 D/GeckoHealthRec(  786): Recording session end: P
11:36:55     INFO -  03-20 11:20:32.059 V/GeckoHealthRec(  786): Recorded session entry for env 1, current is 1
11:36:55     INFO -  03-20 11:20:32.059 D/GeckoSessInfo(  786): Recording session done: 1395339592322
11:36:55     INFO -  03-20 11:20:32.259 D/GeckoBrowserProvider(  786): Expiring history.
11:36:55     INFO -  03-20 11:20:32.329 W/InputManagerService(   64): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@408a36e8
11:36:55     INFO -  03-20 11:20:32.329 D/GeckoBrowserProvider(  786): Expiring thumbnails.
11:36:55     INFO -  03-20 11:20:33.529 I/GeckoHealth(  786): fennec :: HealthReportBroadcastService :: Registering HealthReportPruneService.
11:36:55     INFO -  03-20 11:20:33.529 I/GeckoHealth(  786): fennec :: BackgroundService :: Setting inexact repeating alarm for interval 86400000
11:36:55     INFO -  03-20 11:20:34.159 I/ActivityManager(   64): Displayed android/com.android.internal.app.ChooserActivity: +2s47ms
11:36:55     INFO -  03-20 11:20:34.459 I/Robocop (  786): 23 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the share pop-up is displayed - The pop-up has been displayed
11:36:55     INFO -  03-20 11:20:34.810 W/KeyCharacterMap(  786): No keyboard for id 0
11:36:55     INFO -  03-20 11:20:34.810 W/KeyCharacterMap(  786): Using default keymap: /system/usr/keychars/qwerty.kcm.bin
11:36:55     INFO -  03-20 11:20:35.271 W/GeckoBatteryManager(  786): Already started!
11:36:55     INFO -  03-20 11:20:35.403 D/GeckoSessInfo(  786): Recording start of session: 1395339635406
11:36:55     INFO -  03-20 11:20:35.559 W/InputManagerService(   64): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@408acd00
11:36:55     INFO -  03-20 11:20:36.159 I/Robocop (  786): long-clicking at 512.0, 103.0
11:36:55     INFO -  03-20 11:20:37.589 E/Profiler(  786): BPUnw: [7 total] thread_unregister_for_profiling(me=0x357950) 
11:36:55     INFO -  03-20 11:20:37.910 E/GeckoConsole(  786): Sending message
11:36:55     INFO -  03-20 11:20:40.940 E/GeckoConsole(  786): observe {"guid":"","button":8,"list":[8],"__guid__":"{0802fdc4-c3b5-4ba0-81f3-895694dd59b1}"}
11:36:55     INFO -  03-20 11:20:41.169 W/InputManagerService(   64): Window already focused, ignoring focus gain of: com.android.internal.view.IInputMethodClient$Stub$Proxy@40661700
11:36:55     INFO -  03-20 11:20:41.830 I/Robocop (  786): 24 INFO TEST-PASS | testPictureLinkContextMenu | Waiting for the Bookmark added toaster notification - The notification has been displayed
11:36:55     INFO -  03-20 11:20:41.920 I/Robocop (  786): 25 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): Exception caught during test!
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): junit.framework.AssertionFailedError: 25 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at junit.framework.Assert.fail(Assert.java:47)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:110)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:139)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at org.mozilla.gecko.tests.ContentContextMenuTest.verifyBookmarkLinkOption(ContentContextMenuTest.java:82)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at org.mozilla.gecko.tests.testPictureLinkContextMenu.testPictureLinkContextMenu(testPictureLinkContextMenu.java:33)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at java.lang.reflect.Method.invokeNative(Native Method)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at java.lang.reflect.Method.invoke(Method.java:507)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:152)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at junit.framework.TestCase.runBare(TestCase.java:127)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at junit.framework.TestResult$1.protect(TestResult.java:106)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at junit.framework.TestResult.runProtected(TestResult.java:124)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at junit.framework.TestResult.run(TestResult.java:109)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at junit.framework.TestCase.run(TestCase.java:118)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:529)
11:36:55     INFO -  03-20 11:20:42.159 I/Robocop (  786): 	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1448)
11:36:55     INFO -  03-20 11:20:42.189 I/Robocop (  786): 26 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Exception caught - junit.framework.AssertionFailedError: 25 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking if the link has been added as a bookmark - The link has been bookmarked
11:36:55     INFO -  03-20 11:20:42.539 D/GeckoTransProvider(  786): Cleaning up deleted records from bookmarks
11:36:55     INFO -  03-20 11:20:42.589 I/Robocop (  786): 27 INFO TEST-END | testPictureLinkContextMenu | finished in 159361ms
11:36:55     INFO -  03-20 11:20:42.589 I/Robocop (  786): 28 INFO TEST-START | Shutdown
11:36:55     INFO -  03-20 11:20:42.599 I/Robocop (  786): 29 INFO Passed: 23
11:36:55     INFO -  03-20 11:20:42.610 I/Robocop (  786): 30 INFO Failed: 2
11:36:55     INFO -  03-20 11:20:42.610 I/Robocop (  786): 31 INFO Todo: 0
11:36:55     INFO -  03-20 11:20:42.619 I/Robocop (  786): 32 INFO SimpleTest FINISHED
11:36:55     INFO -  03-20 11:20:43.243 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.251 W/ActivityManager(   64): Activity pause timeout for HistoryRecord{4071e248 org.mozilla.fennec/.App}
11:36:55     INFO -  03-20 11:20:43.251 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 0: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.263 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.263 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 1: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.280 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.280 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 2: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.351 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.351 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 0: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.399 D/GeckoToolbar(  786): onTabChanged: MENU_UPDATED
11:36:55     INFO -  03-20 11:20:43.429 D/GeckoBrowserApp(  786): BrowserApp.onTabChanged: 1: MENU_UPDATED

Comment 1

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Verified this still fails, if enabled:

https://tbpl.mozilla.org/php/getParsedLog.php?id=41584935&tree=Ash&full=1#error0

00:53:36     INFO -  1 INFO TEST-START | testPictureLinkContextMenu
00:53:36     INFO -  2 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
00:53:36     INFO -  EventExpecter: no longer listening for Gecko:Ready
00:53:36     INFO -  3 INFO TEST-PASS | testPictureLinkContextMenu | waiting for urlbar text to gain focus - urlbar text gained focus
00:53:36     INFO -  4 INFO TEST-PASS | testPictureLinkContextMenu | URL typed properly - http://mochi.test:8888/tests/robocop/robocop_picture_link.html should equal http://mochi.test:8888/tests/robocop/robocop_picture_link.html
00:53:36     INFO -  5 INFO TEST-PASS | testPictureLinkContextMenu | Given message occurred for registered event: {"errorType":"","bgColor":"transparent","type":"DOMContentLoaded","tabID":0} - DOMContentLoaded should equal DOMContentLoaded
00:53:36     INFO -  EventExpecter: no longer listening for DOMContentLoaded
00:53:36     INFO -  PaintExpecter: no longer listening for events
00:53:36     INFO -  6 INFO TEST-PASS | testPictureLinkContextMenu | Page title is correct - Picture Link should equal Picture Link
00:53:36     INFO -  long-clicking at 512.0, 103.0
00:53:36     INFO -  7 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Copy Image Location is available - The option is available
00:53:36     INFO -  8 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Share Image is available - The option is available
00:53:36     INFO -  9 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Set Image As is available - The option is available
00:53:36     INFO -  10 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Save Image is available - The option is available
00:53:36     INFO -  11 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Image is available - The option is available
00:53:36     INFO -  12 INFO TEST-PASS | testPictureLinkContextMenu | Checking that the option: Link is available - The option is available
00:53:36     INFO -  Clipboard text =  , expected text = Firefox.jpg
00:53:36     INFO -  Clipboard text = http://mochi.test:8888/tests/robocop/Firefox.jpg , expected text = Firefox.jpg
00:53:36     INFO -  13 INFO TEST-PASS | testPictureLinkContextMenu | Checking if the text is correctly copied - The text was correctly copied
00:53:36     INFO -  long-clicking at 512.0, 103.0
00:53:36     INFO -  waitForText timeout on Picture Link
00:53:36     INFO -  waitForText timeout on Share Image
00:53:36     INFO -  14 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking that the share pop-up is displayed - The pop-up has been displayed
00:53:36     INFO -  Exception caught during test!
00:53:36     INFO -  junit.framework.AssertionFailedError: 14 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking that the share pop-up is displayed - The pop-up has been displayed
00:53:36     INFO -  	at junit.framework.Assert.fail(Assert.java:47)
00:53:36     INFO -  	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:111)
00:53:36     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:140)
00:53:36     INFO -  	at org.mozilla.gecko.tests.ContentContextMenuTest.verifyShareOption(ContentContextMenuTest.java:93)
00:53:36     INFO -  	at org.mozilla.gecko.tests.testPictureLinkContextMenu.testPictureLinkContextMenu(testPictureLinkContextMenu.java:29)
00:53:36     INFO -  	at java.lang.reflect.Method.invokeNative(Native Method)
00:53:36     INFO -  	at java.lang.reflect.Method.invoke(Method.java:507)
00:53:36     INFO -  	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204)
00:53:36     INFO -  	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194)
00:53:36     INFO -  	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186)
00:53:36     INFO -  	at org.mozilla.gecko.tests.BaseTest.runTest(BaseTest.java:125)
00:53:36     INFO -  	at junit.framework.TestCase.runBare(TestCase.java:127)
00:53:36     INFO -  	at junit.framework.TestResult$1.protect(TestResult.java:106)
00:53:36     INFO -  	at junit.framework.TestResult.runProtected(TestResult.java:124)
00:53:36     INFO -  	at junit.framework.TestResult.run(TestResult.java:109)
00:53:36     INFO -  	at junit.framework.TestCase.run(TestCase.java:118)
00:53:36     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)
00:53:36     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)
00:53:36     INFO -  	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:529)
00:53:36     INFO -  	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1448)
00:53:36     INFO -  15 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Exception caught - junit.framework.AssertionFailedError: 14 INFO TEST-UNEXPECTED-FAIL | testPictureLinkContextMenu | Checking that the share pop-up is displayed - The pop-up has been displayed
00:53:36     INFO -  16 INFO TEST-END | testPictureLinkContextMenu | finished in 122340ms

Comment 2

[Geoff Brown [:gbrown] (pto Apr 11-18)]

I can reproduce this in the emulator running on my laptop. The correct context menu is displayed and contains "Share Image". The test clicks on "Share Image" and a dialog immediately opens to email the image, whereas the test expects a Share Image "pop-up", offering different ways to share. I suppose the difference is that Email is the only share option available on the emulator (no Gmail, Bluetooth, Skype, etc available).

So this looks like an oversight in the test, rather than a problem with the emulator environment.

Comment 3

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Attachment: expand fake share handlers to handle images also

As I recall, :wesj solved this problem for "Share Link" by introducing the fake share handlers. If I add image mime types to those handlers, they show up for "Share Image" also, and all is well (local testing, Android 2.3).

More complete test underway: https://tbpl.mozilla.org/?tree=Try&rev=eab3a055d285

Comment 4

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Comment on attachment 8439936 [details] [diff] [review]
expand fake share handlers to handle images also

Transferring to snorp in hopes of expediting review.

Comment 5

[Geoff Brown [:gbrown] (pto Apr 11-18)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ca8674ccd9bd

Comment 6

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/ca8674ccd9bd

Comment 7

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Comment on attachment 8439936 [details] [diff] [review]
expand fake share handlers to handle images also

This seemed to work fine. I don't think there are any remaining concerns.