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

Reporter

Description

•

6 years ago

treeherder

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

Henrik Skupin [:whimboo][⌚️UTC+1]

Comment 1

•

6 years ago

Why should this be firefox ui tests? Moving it to the correct component.

Component: Firefox UI Tests → Reftest

QA Contact: hskupin

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

6 years ago

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

Comment hidden (Intermittent Failures Robot)

2 failures in 2387 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 2

Platform breakdown:
* android-em-7-0-x86: 1
* windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1509207&startday=2018-11-19&endday=2018-11-25&tree=all

Comment hidden (Intermittent Failures Robot)

4 failures in 2808 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-inbound: 3
* mozilla-central: 1

Platform breakdown:
* android-em-7-0-x86: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1509207&startday=2018-11-26&endday=2018-12-02&tree=all

Comment hidden (Intermittent Failures Robot)

2 failures in 2648 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 2

Platform breakdown:
* android-em-7-0-x86: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1509207&startday=2018-12-17&endday=2018-12-23&tree=all

Comment hidden (Intermittent Failures Robot)

1 failures in 1008 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1

Platform breakdown:
* android-em-7-0-x86: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1509207&startday=2018-12-24&endday=2018-12-30&tree=all

Comment hidden (Intermittent Failures Robot)

Joel Maher ( :jmaher ) (UTC -8)

Comment 9

•

5 years ago

: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)

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

Assignee

Comment 10

•

5 years ago

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

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

Assignee

Comment 11

•

5 years ago

Attached patch wait and retry for valid android version — Details — Splinter Review

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)

Bob Clary [:bc] (inactive)

Comment 12

•

5 years ago

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+

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

Assignee

Comment 13

•

5 years ago

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.

Bob Clary [:bc] (inactive)

Comment 14

•

5 years ago

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

Pulsebot

Comment 15

•

5 years ago

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

Daniel Varga [:dvarga]

Comment 16

•

5 years ago

bugherder

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

Status: NEW → RESOLVED

Closed: 5 years ago

status-firefox67: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla67

Comment hidden (Intermittent Failures Robot)