1365636 - geckoview_example unit test: Automation Error: No crash directory (/storage/sdcard/tests/gv-profile/minidumps) found on remote device ... because -profile not used by geckoview_example

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Testing, defect, P1)

Description

[Geoff Brown [:gbrown]]

I think bug 1323296 changed the order or timing of logcat messages which this test waits for. Since those changes, the test doesn't wait long enough for the crashreporter to me initialized, so the harness cannot verify crashes.

Regrettably, the job appears to succeed -- green in treeherder -- so this has gone unnoticed for a long time.

https://public-artifacts.taskcluster.net/bcKdy6v0Rf6S9kxU_i_wJQ/0/public/logs/live_backing.log

[task 2017-04-21T22:15:16.690839Z] 22:15:16     INFO -  SUITE-START | Running 3 tests
[task 2017-04-21T22:15:16.691220Z] 22:15:16     INFO -  TEST-START | geckoview_example installed
[task 2017-04-21T22:15:18.209269Z] 22:15:18     INFO -  TEST-PASS | geckoview_example installed | took 1518ms
[task 2017-04-21T22:15:18.210084Z] 22:15:18     INFO -  TEST-START | geckoview_example starts
[task 2017-04-21T22:15:21.680574Z] 22:15:21     INFO -  TEST-PASS | geckoview_example starts | took 3472ms
[task 2017-04-21T22:15:21.680989Z] 22:15:21     INFO -  TEST-START | startup logcat messages
[task 2017-04-21T22:15:50.433835Z] 22:15:50     INFO -  TEST-PASS | startup logcat messages | took 28752ms
[task 2017-04-21T22:15:50.433901Z] 22:15:50     INFO -  Passed: 3
[task 2017-04-21T22:15:50.433945Z] 22:15:50     INFO -  Failed: 0
[task 2017-04-21T22:15:50.433983Z] 22:15:50     INFO -  SUITE-END | took 33s
[task 2017-04-21T22:15:53.838769Z] 22:15:53     INFO -  Automation Error: No crash directory (/storage/sdcard/tests/gv-profile/minidumps) found on remote device
[task 2017-04-21T22:15:54.092079Z] 22:15:54    ERROR - Return code: 1

Comment 1

[Geoff Brown [:gbrown]]

It's not timing related: Even if I wait a couple of minutes, geckoview_example never seems to create a crash directory. That might happen if the crashreporter is not initialized. Another thought is that maybe "--es args '-profile /sdcard/tests/gv-profile'" is not being respected, so the default profile location is still being used?

:snorp -- Any idea?

Comment 2

[Geoff Brown [:gbrown]]

Attachment: cause geckoview job to fail when no crash directory is found

This addresses one part of the problem here: The test job should fail when no crash directory is found. I re-arrange the check_for_crashes() call so that the test summary is not printed when the crash directory is missing or check_for_crashes() otherwise fails.

The geckoview job starts failing properly with this change:

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

Now I need to fix the missing crash directory...still hoping snorp has an idea.

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8868772 [details] [diff] [review]
cause geckoview job to fail when no crash directory is found

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

::: testing/mochitest/rungeckoview.py
@@ +165,5 @@
> +        if crashed:
> +            fail_count = 1
> +        else:
> +            self.log.info("Passed: %d" % pass_count)
> +            self.log.info("Failed: %d" % fail_count)

do we still want to output passed/failed statistics?

Comment 4

[Geoff Brown [:gbrown]]

(In reply to Joel Maher ( :jmaher) from comment #3)
> do we still want to output passed/failed statistics?

No. That's actually why this change works:

https://public-artifacts.taskcluster.net/SvqFlmKYQZCzvazAiP5ZMQ/0/public/logs/live_backing.log

[task 2017-05-17T21:43:30.467228Z] 21:43:30     INFO -  SUITE-START | Running 3 tests
[task 2017-05-17T21:43:30.467464Z] 21:43:30     INFO -  TEST-START | geckoview_example installed
[task 2017-05-17T21:43:31.885677Z] 21:43:31     INFO -  TEST-PASS | geckoview_example installed | took 1419ms
[task 2017-05-17T21:43:31.885979Z] 21:43:31     INFO -  TEST-START | geckoview_example starts
[task 2017-05-17T21:43:35.058915Z] 21:43:35     INFO -  TEST-PASS | geckoview_example starts | took 3173ms
[task 2017-05-17T21:43:35.059608Z] 21:43:35     INFO -  TEST-START | startup logcat messages
[task 2017-05-17T21:43:37.399835Z] 21:43:37     INFO -  TEST-PASS | startup logcat messages | took 2341ms
[task 2017-05-17T21:43:37.518301Z] 21:43:37     INFO -  Automation Error: No crash directory (/storage/sdcard/tests/gv-profile/minidumps) found on remote device
[task 2017-05-17T21:43:37.518500Z] 21:43:37     INFO -  SUITE-END | took 7s
[task 2017-05-17T21:43:40.148153Z] 21:43:40    ERROR - Return code: 1
[task 2017-05-17T21:43:40.148518Z] 21:43:40    ERROR - No tests run or test summary not found
...
[task 2017-05-17T21:43:40.204785Z] 21:43:40  WARNING - # TBPL WARNING #
[task 2017-05-17T21:43:40.204984Z] 21:43:40  WARNING - setting return code to 1
...
[task 2017-05-17T21:43:40.426510Z] 21:43:40  WARNING - returning nonzero exit status 1

The missing summary ("Passed: ... Failed: ...") triggers the "No tests run or test summary not found" in mozharness, which turns the job orange.

Comment 5

[Geoff Brown [:gbrown]]

The main cause of the missing minidumps directory appears to be that the default profile directory is used, despite the -profile specification. When I run rungeckoview.py locally, I see /data/data/org.mozilla.geckoview_example/files/mozilla/<profile>/minidumps created.

So now my question for snorp is: How can geckoview_example be fixed to respect the -profile argument?

Comment 6

[James Willcox (:snorp) ([e-mail]) (he/him)]

Yeah, we can support the -profile argument in the intent args. Dylan, make it so!

Comment 7

[Dylan Roeh (:droeh) (he/him)]

Attachment: geckoview-profileFromIntent.patch

I'm having trouble running rungeckoview.py, but it looks to me like the problem is that we only get a profile from the intent if the context passed to GeckoProfile.get() is an Activity; right now we explicitly pass the application context instead. Jim, is it going to cause any problems to just pass the context from the constructor into GeckoProfile.get() rather than the application context?

Comment 8

[Geoff Brown [:gbrown]]

(In reply to Dylan Roeh (:droeh) from comment #7)
> I'm having trouble running rungeckoview.py

Anything I can help with? I just run an emulator, install geckoview_example.apk, and then 'python testing/mochitest/rungeckoview.py'.

Comment 9

[(inactive) Jim Chen [:jchen] [:darchons]]

Comment on attachment 8874603 [details] [diff] [review]
geckoview-profileFromIntent.patch

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

Hm this should be handled in geckoview_example IMO. We can't assume every GeckoView consumer will want to use the "args" extra the way we do it.

Comment 10

[Dylan Roeh (:droeh) (he/him)]

Attachment: geckoview-profileFromIntent.patch

This passes the intent args to GeckoView.preload(), and changes GeckoView.preload() to call GeckoProfile.initFromArgs(appContext, geckoArgs) rather than GeckoProfile.get(appContext).

I tested this via intent since I can't get rungeckoview.py working and it looks good.

Comment 11

[Bob Clary [:bc] (inactive)]

You can test autophone via

try: -b o -p android-api-15-gradle -u autophone-mochitest-geckoview-e10s,autophone-s1s2geckoview,autophone-s1s2geckoview-e10s -t none

Comment 12

[Dylan Roeh (:droeh) (he/him)]

I'm getting failures, but it does not look like they're related to a missing crash directory -- I can't really figure out what's going on here, I'll take a closer look tomorrow morning:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=5c5d9a7e644503c7ec0cd4f408ee64806f736556&selectedJob=105018371

Comment 13

[Dylan Roeh (:droeh) (he/him)]

Am I missing something here? I see the same failures with no patch at all, and again nothing about a missing crash directory:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e0f6083089f375ee2d1ab928ca0eba1927a221c3&selectedJob=105237152

Geoff, any ideas?

Comment 14

[Geoff Brown [:gbrown]]

I'm not sure what's happening in those autophone geckoview jobs. Maybe :bc can tell us?

I added the emulator geckoview test to your try push - the "gv" job. It does contain the "No crash directory" error (the job is green but should fail with that error).

https://public-artifacts.taskcluster.net/YifiOLqpQZ6OEFDQU8Eohg/0/public/logs/live_backing.log


If you want to run the emulator geckoview test in other try pushes, just use "-p android-api-15-gradle -u geckoview".

Comment 15

[Bob Clary [:bc] (inactive)]

I did a test on try
https://treeherder.allizom.org/#/jobs?repo=try&revision=d5466d294673af214200cecadcdede7ee326abe2

Android 4.0/sdk 15
TEST-UNEXPECTED-FAIL | startup logcat messages | 'Displayed org.mozilla.geckoview_example/.GeckoViewActivity'

Android 4.0/sdk 15 - Android 25/sdk 25
Automation Error: No crash directory (/sdcard/tests/autophone/gv-profile/minidumps) found on remote device

The lack of error lines is the long standing autophone issue with reporting errors on Ubuntu.

Comment 16

[Dylan Roeh (:droeh) (he/him)]

I put up a test on try this morning with some additional logging to try and figure out what's going on here, and got a rather strange output:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e91925e15e23d4ba16601153e60f97ed73c9faba&selectedJob=109222743
https://public-artifacts.taskcluster.net/Rdqc2k7lTg2JJT6NM1LTHw/0/public/test_info//logcat-emulator-5554.log

I've added code that should print some stuff to logcat in XRE_mainStartup; when I run this locally I get (as expected) the "DYLAN -- MOZ_CRASHREPORTER not defined" in logcat, but as you can see above that doesn't show up at all in try output. Is there a possibility we're somehow losing logcat output or killing the GV example app too soon for it to hit this point?

Comment 17

[Geoff Brown [:gbrown]]

I think the logcat output is accurate.

It looks like the app is killed too soon. rungeckoview.py runs its tests, kills the app, then checks for crashes (including checking for the crash directory). Weeks (months?) ago, I remember the started() test waited for startup effectively:

https://dxr.mozilla.org/mozilla-central/source/testing/mochitest/rungeckoview.py#127

I think the "zerdatime" message is logged earlier now, and maybe there was another message it was waiting for before?

Perhaps the timing works out on your computer, but startup takes longer on try?


Anyway, you could try just adding something like time.sleep(30) before cleanup() is called. If that works out, perhaps a reasonable strategy would be to wait until the crash directory is created before cleaning up. Want me to write that part?

Comment 18

[Dylan Roeh (:droeh) (he/him)]

Yeah, it looks like we were killing it too soon[0]. Unfortunately the minidumps folder still isn't getting created, but I can at least get more logging to try and figure out what's happening.

[0] - https://treeherder.mozilla.org/#/jobs?repo=try&revision=6ecb765ac6d86b1a05a638421ec871db6cbcbe84&selectedJob=109609420

Comment 19

[Geoff Brown [:gbrown]]

Attachment: wait for crash dump directory to be created

Follow-up on comment 16 and comment 17: In case the tests finish before startup has completed, wait up to 60 seconds more until the minidumps directory is found.

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

Comment 20

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8881905 [details] [diff] [review]
wait for crash dump directory to be created

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

ack, 60 seconds delay for every job- but it solves the problem!

Comment 21

[Geoff Brown [:gbrown]]

Well, up to 60 seconds...in practice it looks like 20 to 25 seconds delay.

Comment 22

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/42a578e0abe7
Cause geckoview job to fail when no crash directory found; r=jmaher
https://hg.mozilla.org/integration/mozilla-inbound/rev/5cdc4fba12d1
Wait for geckoview crash directory to be created; r=jmaher
https://hg.mozilla.org/integration/mozilla-inbound/rev/3245ee705be3
Use args-provided profile in GeckoView example app. r=snorp

Comment 23

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/42a578e0abe7
https://hg.mozilla.org/mozilla-central/rev/5cdc4fba12d1
https://hg.mozilla.org/mozilla-central/rev/3245ee705be3