Closed Bug 1509207 Opened 7 years ago Closed 6 years ago

Intermittent ValueError: invalid literal for int() with base 10: '' for adb_android.py

Categories

(Testing :: General, defect, P2)

Product:
Testing
Component:
General
Version:
Version 3
Type:
defect

Tracking

(firefox67 fixed)

Status:
RESOLVED FIXED
Milestone:
mozilla67
Tracking Flags:
Tracking Status
firefox67 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: gbrown)

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

wait and retry for valid android version
1.36 KB, patch
bc
: review+
Details | Diff | Splinter Review
Filed by: aiakab [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=213260176&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/Ko5CafqgT1mUbNxYeDwa7Q/runs/0/artifacts/public/logs/live_backing.log https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/Ko5CafqgT1mUbNxYeDwa7Q/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1 [task 2018-11-21T22:31:41.781Z] 22:31:41 INFO - root 2143 2141 9864 1988 0 73c9b7dc7507 R ps [task 2018-11-21T22:31:41.781Z] 22:31:41 INFO - Running post-action listener: _resource_record_post_action [task 2018-11-21T22:31:41.781Z] 22:31:41 INFO - [mozharness: 2018-11-21 22:31:41.781698Z] Finished verify-device step (success) [task 2018-11-21T22:31:41.781Z] 22:31:41 INFO - [mozharness: 2018-11-21 22:31:41.781808Z] Running install step. [task 2018-11-21T22:31:41.781Z] 22:31:41 INFO - Running pre-action listener: _resource_record_pre_action [task 2018-11-21T22:31:41.781Z] 22:31:41 INFO - Running main action method: install [task 2018-11-21T22:31:43.787Z] 22:31:43 INFO - Finished installing apps for emulator-5554 [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - Running post-action listener: _resource_record_post_action [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - [mozharness: 2018-11-21 22:31:43.787874Z] Finished install step (success) [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - [mozharness: 2018-11-21 22:31:43.787974Z] Running run-tests step. [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - Running pre-action listener: _resource_record_pre_action [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - Running pre-action listener: _set_gcov_prefix [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - Running pre-action listener: timed_screenshots [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - Running main action method: run_tests [task 2018-11-21T22:31:43.788Z] 22:31:43 INFO - Running the command /builds/worker/workspace/build/venv/bin/python -u /builds/worker/workspace/build/tests/reftest/remotereftest.py --app=org.mozilla.geckoview.test --ignore-window-size --remote-webserver=10.0.2.2 --xre-path=/builds/worker/workspace/build/hostutils/host-utils-61.0a1.en-US.linux-x86_64 --utility-path=/builds/worker/workspace/build/hostutils/host-utils-61.0a1.en-US.linux-x86_64 --http-port=8854 --ssl-port=4454 --httpd-path /builds/worker/workspace/build/tests/modules --symbols-path=https://queue.taskcluster.net/v1/task/T3gBrpAfTEerWOzLxLS-6A/artifacts/public/build/target.crashreporter-symbols.zip --suite=crashtest --log-tbpl-level=info --deviceSerial=emulator-5554 -- tests/testing/crashtest/crashtests.list [task 2018-11-21T22:31:43.789Z] 22:31:43 INFO - ##### crashtest log begins [task 2018-11-21T22:31:43.789Z] 22:31:43 INFO - Running command: ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/reftest/remotereftest.py', '--app=org.mozilla.geckoview.test', '--ignore-window-size', '--remote-webserver=10.0.2.2', '--xre-path=/builds/worker/workspace/build/hostutils/host-utils-61.0a1.en-US.linux-x86_64', '--utility-path=/builds/worker/workspace/build/hostutils/host-utils-61.0a1.en-US.linux-x86_64', '--http-port=8854', '--ssl-port=4454', '--httpd-path', '/builds/worker/workspace/build/tests/modules', '--symbols-path=https://queue.taskcluster.net/v1/task/T3gBrpAfTEerWOzLxLS-6A/artifacts/public/build/target.crashreporter-symbols.zip', '--suite=crashtest', '--log-tbpl-level=info', '--deviceSerial=emulator-5554', '--', 'tests/testing/crashtest/crashtests.list'] in /builds/worker/workspace/build/tests/reftest [task 2018-11-21T22:31:43.789Z] 22:31:43 INFO - Copy/paste: /builds/worker/workspace/build/venv/bin/python -u /builds/worker/workspace/build/tests/reftest/remotereftest.py --app=org.mozilla.geckoview.test --ignore-window-size --remote-webserver=10.0.2.2 --xre-path=/builds/worker/workspace/build/hostutils/host-utils-61.0a1.en-US.linux-x86_64 --utility-path=/builds/worker/workspace/build/hostutils/host-utils-61.0a1.en-US.linux-x86_64 --http-port=8854 --ssl-port=4454 --httpd-path /builds/worker/workspace/build/tests/modules --symbols-path=https://queue.taskcluster.net/v1/task/T3gBrpAfTEerWOzLxLS-6A/artifacts/public/build/target.crashreporter-symbols.zip --suite=crashtest --log-tbpl-level=info --deviceSerial=emulator-5554 -- tests/testing/crashtest/crashtests.list [task 2018-11-21T22:31:43.789Z] 22:31:43 INFO - Using env: (same as previous command) [task 2018-11-21T22:31:45.386Z] 22:31:45 INFO - Using adb 1.0.40 [task 2018-11-21T22:31:45.489Z] 22:31:45 INFO - adbd running as root [task 2018-11-21T22:31:45.694Z] 22:31:45 INFO - su 0 supported [task 2018-11-21T22:31:45.899Z] 22:31:45 INFO - /system/bin/ls -1A supported [task 2018-11-21T22:31:46.002Z] 22:31:46 INFO - Native cp support: True [task 2018-11-21T22:31:46.103Z] 22:31:46 INFO - Native chmod -R support: True [task 2018-11-21T22:31:46.206Z] 22:31:46 INFO - Native chown -R support: True [task 2018-11-21T22:31:51.593Z] 22:31:51 INFO - Setting SELinux Permissive [task 2018-11-21T22:31:51.799Z] 22:31:51 INFO - Traceback (most recent call last): [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 440, in <module> [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - sys.exit(run_test_harness(parser, options)) [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 391, in run_test_harness [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - reftest = RemoteReftest(options, SCRIPT_DIRECTORY) [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - File "/builds/worker/workspace/build/tests/reftest/remotereftest.py", line 155, in __init__ [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - verbose=verbose) [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - File "/builds/worker/workspace/build/venv/lib/python2.7/site-packages/mozdevice/adb_android.py", line 100, in __init__ [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - timeout=timeout)) [task 2018-11-21T22:31:51.800Z] 22:31:51 INFO - ValueError: invalid literal for int() with base 10: '' [task 2018-11-21T22:31:51.810Z] 22:31:51 ERROR - Return code: 1 [task 2018-11-21T22:31:51.811Z] 22:31:51 ERROR - No tests run or test summary not found [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - TinderboxPrint: crashtest<br/><em class="testfail">T-FAIL</em> [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - ##### crashtest log ends [task 2018-11-21T22:31:51.811Z] 22:31:51 WARNING - # TBPL WARNING # [task 2018-11-21T22:31:51.811Z] 22:31:51 WARNING - setting return code to 1 [task 2018-11-21T22:31:51.811Z] 22:31:51 WARNING - The crashtest suite: crashtest ran with return status: WARNING [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - Running post-action listener: _package_coverage_data [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - Running post-action listener: _resource_record_post_action [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - Running post-action listener: process_java_coverage_data [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - Running post-action listener: stop_device [task 2018-11-21T22:31:51.811Z] 22:31:51 INFO - Killing logcat pid 982. [task 2018-11-21T22:31:51.812Z] 22:31:51 INFO - Killing every process called emulator64-x86 [task 2018-11-21T22:31:51.817Z] 22:31:51 INFO - Killing pid 489. [task 2018-11-21T22:31:51.817Z] 22:31:51 INFO - [mozharness: 2018-11-21 22:31:51.817830Z] Finished run-tests step (success) [task 2018-11-21T22:31:51.818Z] 22:31:51 INFO - Running post-run listener: _resource_record_post_run [task 2018-11-21T22:31:51.856Z] 22:31:51 INFO - Total resource usage - Wall time: 15s; CPU: 24.0%; Read bytes: 27590656; Write bytes: 15370553344; Read time: 5624; Write time: 3167812 [task 2018-11-21T22:31:51.856Z] 22:31:51 INFO - TinderboxPrint: CPU usage<br/>23.7% [task 2018-11-21T22:31:51.856Z] 22:31:51 INFO - TinderboxPrint: I/O read bytes / time<br/>27,590,656 / 5,624 [task 2018-11-21T22:31:51.856Z] 22:31:51 INFO - TinderboxPrint: I/O write bytes / time<br/>15,370,553,344 / 3,167,812 [task 2018-11-21T22:31:51.856Z] 22:31:51 INFO - TinderboxPrint: CPU guest<br/>2.0 (1.7%) [task 2018-11-21T22:31:51.857Z] 22:31:51 INFO - TinderboxPrint: CPU idle<br/>63.3 (52.3%) [task 2018-11-21T22:31:51.857Z] 22:31:51 INFO - TinderboxPrint: CPU iowait<br/>27.4 (22.7%) [task 2018-11-21T22:31:51.858Z] 22:31:51 INFO - TinderboxPrint: CPU system<br/>5.6 (4.7%) [task 2018-11-21T22:31:51.858Z] 22:31:51 INFO - TinderboxPrint: CPU user<br/>22.5 (18.6%) [task 2018-11-21T22:31:51.859Z] 22:31:51 INFO - TinderboxPrint: Swap in / out<br/>0 / 0 [task 2018-11-21T22:31:51.859Z] 22:31:51 INFO - verify-device - Wall time: 5s; CPU: 22.0%; Read bytes: 212992; Write bytes: 4447344640; Read time: 704; Write time: 926636 [task 2018-11-21T22:31:51.859Z] 22:31:51 INFO - install - Wall time: 2s; CPU: 31.0%; Read bytes: 335872; Write bytes: 575684608; Read time: 1072; Write time: 201640 [task 2018-11-21T22:31:51.859Z] 22:31:51 INFO - run-tests - Wall time: 8s; CPU: 23.0%; Read bytes: 27033600; Write bytes: 8567091200; Read time: 3768; Write time: 1615740 [task 2018-11-21T22:31:51.864Z] 22:31:51 WARNING - returning nonzero exit status 1 [task 2018-11-21T22:31:51.875Z] cleanup [task 2018-11-21T22:31:51.875Z] + cleanup [task 2018-11-21T22:31:51.875Z] + local rv=1 [task 2018-11-21T22:31:51.875Z] + [[ -s /builds/worker/.xsession-errors ]] [task 2018-11-21T22:31:51.875Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log [task 2018-11-21T22:31:51.876Z] + true [task 2018-11-21T22:31:51.876Z] + cleanup_xvfb [task 2018-11-21T22:31:51.877Z] pidof Xvfb [task 2018-11-21T22:31:51.877Z] ++ pidof Xvfb [task 2018-11-21T22:31:51.879Z] + local xvfb_pid=25 [task 2018-11-21T22:31:51.879Z] + local vnc=false [task 2018-11-21T22:31:51.879Z] + local interactive=false [task 2018-11-21T22:31:51.879Z] + '[' -n 25 ']' [task 2018-11-21T22:31:51.879Z] + [[ false == false ]] [task 2018-11-21T22:31:51.879Z] + [[ false == false ]] [task 2018-11-21T22:31:51.879Z] + kill 25 [task 2018-11-21T22:31:51.879Z] + screen -XS xvfb quit [task 2018-11-21T22:31:51.886Z] XIO: fatal IO error 11 (Resource temporarily unavailable) on X server ":0" [task 2018-11-21T22:31:51.887Z] after 1246 requests (1246 known processed) with 0 events remaining. [task 2018-11-21T22:31:51.887Z] compizconfig - Info: Backend : ini [task 2018-11-21T22:31:51.887Z] compizconfig - Info: Integration : true [task 2018-11-21T22:31:51.887Z] compizconfig - Info: Profile : default [task 2018-11-21T22:31:51.972Z] No screen session found. [task 2018-11-21T22:31:51.972Z] + true [task 2018-11-21T22:31:51.973Z] + exit 1 [taskcluster 2018-11-21 22:31:52.271Z] === Task Finished === [taskcluster 2018-11-21 22:31:57.635Z] Unsuccessful task run with exit code: 1 completed in 97.719 seconds
Why should this be firefox ui tests? Moving it to the correct component.
Component: Firefox UI Tests → Reftest
QA Contact: hskupin
Summary: Intermittent ValueError: invalid literal for int() with base 10: '' → Intermittent ValueError: invalid literal for int() with base 10: '' for adb_android.py

:gbrown, should this be an auto retry? from an unfamiliar point of view this looks like we cannot connect to the emulator.

Component: Reftest → General
Flags: needinfo?(gbrown)

We have connected to the emulator and run adb commands earlier, but requesting the api level fails ("getprop ro.build.version.sdk" returns ''). Maybe boot hasn't fully completed, somehow? Let's catch the ValueError, maybe retry in adb.py, and fail with an ADBError if the condition persists. I'll put together a simple patch.

Assignee: nobody → gbrown
Flags: needinfo?(gbrown)
Priority: P5 → P2

I do not know if this will be effective, but I think it is worth a try.

https://treeherder.mozilla.org/#/jobs?repo=try&tier=1%2C2%2C3&revision=ed2c9a03710fdd8c28ce97e239e7f99cdf6fbbee

(This version of the patch has corrected for the f8 error in the try push.)

Attachment #9040756 - Flags: review?(bob)
Comment on attachment 9040756 [details] [diff] [review] wait and retry for valid android version Review of attachment 9040756 [details] [diff] [review]: ----------------------------------------------------------------- r+ ::: testing/mozbase/mozdevice/mozdevice/adb.py @@ +735,5 @@ > + except ValueError: > + self._logger.info("unexpected ro.build.version.sdk: '%s'" % version) > + time.sleep(2) > + if self.version < 1: > + raise ADBTimeoutError("ADBDevice: unable to determine ro.build.version.sdk.") Not sure how I feel about overloading ADBTimeoutError in this way. It has pretty specific semantics now in that it means an adb command didn't return within the specified timeout period, but this doesn't quite fit that. But, the way we use ADBTimeoutError as an unrecoverable exception does fit with what you want here. Otherwise it might require modifying all the different ADBError except blocks in callers. Can you add a comment here explaining the rationale for breaking the convention?
Attachment #9040756 - Flags: review?(bob) → review+

I am open to adding a comment or using a different error, if you prefer.

There is an existing use of ADBTimeoutError just a little earlier, at

https://searchfox.org/mozilla-central/rev/e62b311b2e0e02633afda2004ba4056b09fbcaa4/testing/mozbase/mozdevice/mozdevice/adb.py#685

which was my inspiration.

Good point. I missed that. /nick Roseanne Roseannadanna: Never mind.

Pushed by gbrown@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/0f6e106e3efd In android tests, wait for valid ro.build.version.sdk; r=bc

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

Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox67: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: