1235689 - Intermittent testAppMenuPathways | The menu item Save as PDF is enabled

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Testing, defect)

Description

[Phil Ringnalda (:philor)]

The start of this failure is at least two days ago, but apparently nobody files intermittents anymore.

https://treeherder.mozilla.org/logviewer.html#?job_id=6360937&repo=fx-team

Comment 1

[Michael Comella (:mcomella) [NI reported issues only: ex-Mozilla]]

 12:36:45  WARNING -  TEST-UNEXPECTED-FAIL | testAppMenuPathways | The menu item Save as PDF is enabled -
 12:36:45     INFO -  0 ERROR Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAppMenuPathways | The menu item Save as PDF is enabled -
 12:36:45     INFO -  	at junit.framework.Assert.fail(Assert.java:47)
 12:36:45     INFO -  	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:128)
 12:36:45     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:150)
 12:36:45     INFO -  	at org.mozilla.gecko.tests.helpers.AssertionHelper.fAssertTrue(AssertionHelper.java:98)
 12:36:45     INFO -  	at org.mozilla.gecko.tests.components.AppMenuComponent.pressMenuItem(AppMenuComponent.java:213)
 12:36:45     INFO -  	at org.mozilla.gecko.tests.components.AppMenuComponent.pressSubMenuItem(AppMenuComponent.java:231)
 12:36:45     INFO -  	at org.mozilla.gecko.tests.components.AppMenuComponent.pressMenuItem(AppMenuComponent.java:243)
 12:36:45     INFO -  	at org.mozilla.gecko.tests.testAppMenuPathways._testSaveAsPDFPathway(testAppMenuPathways.java:60)
 12:36:45     INFO -  	at org.mozilla.gecko.tests.testAppMenuPathways.testAppMenuPathways(testAppMenuPathways.java:25)

Comment 2

[Intermittent Failures Robot]

10 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 6
* fx-team: 2
* try: 1
* mozilla-central: 1

Platform breakdown:
* android-2-3-armv7-api9: 10

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2015-12-28&endday=2016-01-03&tree=all

Comment 3

[Intermittent Failures Robot]

23 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 9
* fx-team: 7
* b2g-inbound: 5
* mozilla-central: 2

Platform breakdown:
* android-2-3-armv7-api9: 23

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-01-04&endday=2016-01-10&tree=all

Comment 4

[Intermittent Failures Robot]

10 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 3
* mozilla-central: 3
* fx-team: 2
* try: 1
* b2g-inbound: 1

Platform breakdown:
* android-2-3-armv7-api9: 10

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-01-11&endday=2016-01-17&tree=all

Comment 5

[Intermittent Failures Robot]

20 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 6
* mozilla-central: 5
* fx-team: 4
* b2g-inbound: 4
* try: 1

Platform breakdown:
* android-2-3-armv7-api9: 20

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-01-18&endday=2016-01-24&tree=all

Comment 6

[Intermittent Failures Robot]

26 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 11
* fx-team: 10
* mozilla-central: 3
* mozilla-aurora: 2

Platform breakdown:
* android-2-3-armv7-api9: 26

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-01-25&endday=2016-01-31&tree=all

Comment 7

[Phil Ringnalda (:philor)]

Looks like the failure rate is around 20% now, so this needs to go away one way or another.

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

Margaret, do you have anyone who can look at this?  Its in the top 5 oranges.  Thanks!

Comment 9

[Intermittent Failures Robot]

36 automation job failures were associated with this bug yesterday.

Repository breakdown:
* fx-team: 30
* mozilla-inbound: 5
* mozilla-central: 1

Platform breakdown:
* android-2-3-armv7-api9: 36

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-02-04&endday=2016-02-04&tree=all

Comment 10

[:Margaret Leibovic]

It looks like this failure is happening on the pressMenuItem call here:
http://hg.mozilla.org/mozilla-central/annotate/1dbe350b57b1/mobile/android/tests/browser/robocop/src/org/mozilla/gecko/tests/testAppMenuPathways.java#l60

Maybe instead of using enterAndLoadUrl and we should loading the URL directly. 

mcomella/gbrown, what do you think?

Comment 11

[Intermittent Failures Robot]

57 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* fx-team: 36
* mozilla-inbound: 12
* mozilla-central: 5
* try: 2
* mozilla-aurora: 2

Platform breakdown:
* android-2-3-armv7-api9: 57

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-02-01&endday=2016-02-07&tree=all

Comment 12

[Geoff Brown [:gbrown]]

You know I don't like enterAndLoadUrl, but I'm not sure it is the problem here; the screenshot suggests the page is loaded.

I know I have seen views take time to transition to enabled; I think that's why http://hg.mozilla.org/mozilla-central/annotate/ac338559876d/mobile/android/tests/browser/robocop/src/org/mozilla/gecko/tests/BaseTest.java#l364 was added. I wonder if we should waitFor(view.enabled) instead of simply asserting. Let's see if that helps: https://treeherder.mozilla.org/#/jobs?repo=try&revision=319f2cbb7607

Comment 13

[Geoff Brown [:gbrown]]

That try run still has intermittent failures (maybe less often?). 

https://treeherder.mozilla.org/#/jobs?repo=try&revision=56e1c685cb1f provided more info, showing that our code explicitly disables the Save as PDF item prior to the failures. I don't fully understand, but think I can sort it out.

Comment 14

[Geoff Brown [:gbrown]]

(In reply to Geoff Brown [:gbrown] from comment #13)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=56e1c685cb1f
> provided more info, showing that our code explicitly disables the Save as
> PDF item prior to the failures. 

Ignore that. My logging was exactly wrong; the correct interpretation is "showing that BrowserApp code explicitly enables the Save as PDF item prior to the failures".

Comment 15

[Pulsebot]

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

Comment 16

[Geoff Brown [:gbrown]]

(May as well disable the test while we work this out.)

Comment 17

[Carsten Book [:Tomcat]]

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

Comment 18

[Intermittent Failures Robot]

15 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-aurora: 8
* fx-team: 3
* try: 2
* mozilla-inbound: 1
* mozilla-central: 1

Platform breakdown:
* android-2-3-armv7-api9: 15

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-02-08&endday=2016-02-14&tree=all

Comment 19

[Geoff Brown [:gbrown]]

In https://treeherder.mozilla.org/#/jobs?repo=try&revision=e5d1e7f42cdc, I added sleep() calls and seemed to improve stability. But, there was still one curious testAppMenuPathways failure:

http://archive.mozilla.org/pub/mobile/try-builds/[e-mail]-e5d1e7f42cdcbb75b795072b016cb6d5614fd61a/try-android-api-9/try_ubuntu64_vm_mobile_test-robocop-4-bm118-tests1-linux64-build437.txt.gz

10:00:40     INFO -  TEST-START | testAppMenuPathways
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | Robocop tests need the test device screen to be powered on. -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | Given message occurred for registered event: {"type":"Gecko:Ready"} - Gecko:Ready should equal Gecko:Ready
10:00:40     INFO -  EventExpecter: no longer listening for Gecko:Ready
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | Menu is not open -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | Waiting for menu to open. -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | The parent menu item view is not null - org.mozilla.gecko.menu.MenuItemDefault@40624d08 should not equal null
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | The parent 'page' menu item is enabled -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | The parent 'page' menu item is visible -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | pressMenuItem: Page found -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | The menu item view is not null - org.mozilla.gecko.menu.MenuItemDefault@40624d08 should not equal null
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | Menu is open and Page is visible -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | The menu item Page is enabled -
10:00:40     INFO -  TEST-PASS | testAppMenuPathways | The menu item Page is visible -
10:00:40  WARNING -  TEST-UNEXPECTED-FAIL | testAppMenuPathways | The page menu item is not null - didn't expect null, but got it
10:00:40     INFO -  0 ERROR Exception caught during test! - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAppMenuPathways | The page menu item is not null - didn't expect null, but got it
10:00:40     INFO -  	at junit.framework.Assert.fail(Assert.java:47)
10:00:40     INFO -  	at org.mozilla.gecko.FennecMochitestAssert._logMochitestResult(FennecMochitestAssert.java:128)
10:00:40     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.ok(FennecMochitestAssert.java:150)
10:00:40     INFO -  	at org.mozilla.gecko.FennecMochitestAssert.isnot(FennecMochitestAssert.java:161)
10:00:40     INFO -  	at org.mozilla.gecko.tests.helpers.AssertionHelper.fAssertNotNull(AssertionHelper.java:82)
10:00:40     INFO -  	at org.mozilla.gecko.tests.components.AppMenuComponent.assertMenuItemIsDisabledAndVisible(AppMenuComponent.java:107)
10:00:40     INFO -  	at org.mozilla.gecko.tests.testAppMenuPathways._testSaveAsPDFPathway(testAppMenuPathways.java:30)
10:00:40     INFO -  	at org.mozilla.gecko.tests.testAppMenuPathways.testAppMenuPathways(testAppMenuPathways.java:25)
10:00:40     INFO -  	at java.lang.reflect.Method.invokeNative(Native Method)
10:00:40     INFO -  	at java.lang.reflect.Method.invoke(Method.java:507)
10:00:40     INFO -  	at android.test.InstrumentationTestCase.runMethod(InstrumentationTestCase.java:204)
10:00:40     INFO -  	at android.test.InstrumentationTestCase.runTest(InstrumentationTestCase.java:194)
10:00:40     INFO -  	at android.test.ActivityInstrumentationTestCase2.runTest(ActivityInstrumentationTestCase2.java:186)
10:00:40     INFO -  	at org.mozilla.gecko.tests.BaseRobocopTest.runTest(BaseRobocopTest.java:188)
10:00:40     INFO -  	at junit.framework.TestCase.runBare(TestCase.java:127)
10:00:40     INFO -  	at junit.framework.TestResult$1.protect(TestResult.java:106)
10:00:40     INFO -  	at junit.framework.TestResult.runProtected(TestResult.java:124)
10:00:40     INFO -  	at junit.framework.TestResult.run(TestResult.java:109)
10:00:40     INFO -  	at junit.framework.TestCase.run(TestCase.java:118)
10:00:40     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:169)
10:00:40     INFO -  	at android.test.AndroidTestRunner.runTest(AndroidTestRunner.java:154)
10:00:40     INFO -  	at android.test.InstrumentationTestRunner.onStart(InstrumentationTestRunner.java:529)
10:00:40     INFO -  	at org.mozilla.gecko.FennecInstrumentationTestRunner.onStart(FennecInstrumentationTestRunner.java:60)
10:00:40     INFO -  	at android.app.Instrumentation$InstrumentationThread.run(Instrumentation.java:1448)
10:00:40  WARNING -  TEST-UNEXPECTED-FAIL | testAppMenuPathways | Exception caught - junit.framework.AssertionFailedError: TEST-UNEXPECTED-FAIL | testAppMenuPathways | The page menu item is not null - didn't expect null, but got it
10:00:40     INFO -  TEST-OK | testAppMenuPathways | took 93711ms

The screenshot, http://mozilla-releng-blobs.s3.amazonaws.com/blobs/try/sha512/5b4dc637228b2ba69422ff542d26a4e676dc797231d74f52578f3dd1b8f03b3a62440623b25b485858607984bfd24f58b127d323e4977800c002aaaf6c12e2d6 shows that we have opened a Private Browsing tab. Note that, from the log, we have not attempted to open a page at all -- we have only opened the Page menu to check that Save as PDF is not enabled. So how did this happen?

Comment 20

[Geoff Brown [:gbrown]]

Some interesting experiments:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=27b2cbbfc5e7
https://treeherder.mozilla.org/#/jobs?repo=try&revision=b072552a9751
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cdc00bdbb72d
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f702f0be43d4
https://treeherder.mozilla.org/#/jobs?repo=try&revision=c8122be3197f

I never did reproduce Comment 19. I wonder if http://hg.mozilla.org/mozilla-central/annotate/fcd35e10fa17/mobile/android/tests/browser/robocop/src/org/mozilla/gecko/tests/testAppMenuPathways.java#l47 is safe, calling in to Tabs.handleMessage() directly on the test thread. I won't pursue that now, since it seems I can get reliable results without changing that, and it's not directly related to this bug.

Regarding this bug's failure, I frequently reproduced the case where the Save as PDF menu item view was disabled after loading the test page, despite logs showing that BrowserApp had enabled Save as PDF. Waiting 7500 ms did not help some of these cases. I eventually realized that BrowserApp manipulates a GeckoMenuItem, while the test examines the Android menu item view -- and GeckoMenuItem includes code that prevents changes from being propagated to the associated view: http://hg.mozilla.org/mozilla-central/annotate/709f559b5406/mobile/android/base/java/org/mozilla/gecko/menu/GeckoMenuItem.java#l83. I could not find any problems in that GeckoMenuItem code, and now cannot reproduce those results, so, again, I'm not going to pursue that line of inquiry. (Just mentioning in case this bug gets re-opened.)

Comment 21

[Geoff Brown [:gbrown]]

Attachment: wait for enabled view in pressMenuItem and enable testAppMenuPathways

This just adds a wait to AppMenuComponent's pressMenuItem, to ensure the menu item view is enabled before proceeding. In tests on try, this significantly improves the reliability of testAppMenuPathways on 2.3.

(I am also correcting the indent level in pressMenuItem, but otherwise not changing the remainder of the function.)

It looks like all's well on 4.3 also, so I'm un-skipping testAppMenuPathways entirely.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e9388c05e644

Comment 22

[Sebastian Kaspari (:sebastian; :pocmo)]

Comment on attachment 8720944 [details] [diff] [review]
wait for enabled view in pressMenuItem and enable testAppMenuPathways

Review of attachment 8720944 [details] [diff] [review]:
-----------------------------------------------------------------

Awesome!

Comment 23

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/0f0a0813a323

Comment 24

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/0f0a0813a323

Comment 25

[Intermittent Failures Robot]

10 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-aurora: 10

Platform breakdown:
* android-2-3-armv7-api9: 10

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1235689&startday=2016-02-22&endday=2016-02-28&tree=all

Comment 26

[Geoff Brown [:gbrown]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=f89e9ff686a8

https://hg.mozilla.org/releases/mozilla-aurora/rev/c94535800481