Closed Bug 1596967 Opened 3 months ago Closed 3 months ago

Mass android xpcshell test failures due to missing files (copied to wrong directory?)

Categories

(Testing :: General, defect)

Version 3
defect
Not set

Tracking

(firefox72 fixed)

RESOLVED FIXED
mozilla72
Tracking Status
firefox72 --- fixed

People

(Reporter: gbrown, Assigned: gbrown)

References

Details

Attachments

(1 file)

Bug 1568063 tracks intermittent mass xpcshell failures on Android: On some test runs, all xpcshell runs fail.

On some of those failed runs (probably a majority), xpcshell reports missing files.

From a try run with extra diagnostics:

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

[task 2019-11-15T23:03:59.215Z] 23:03:59     INFO -  /sdcard/tests/xpc/xpc/security/manager/ssl/tests/unit:
[task 2019-11-15T23:03:59.215Z] 23:03:59     INFO -  total 2088
[task 2019-11-15T23:03:59.215Z] 23:03:59     INFO -  drwxrwx--x 2 root sdcard_rw  4096 2019-11-15 23:03 bad_certs
[task 2019-11-15T23:03:59.215Z] 23:03:59     INFO -  -rw-rw---- 1 root sdcard_rw 39123 2016-01-01 00:00 head_psm.js
...
[task 2019-11-15T23:04:03.390Z] 23:04:03     INFO -  TEST-START | security/manager/ssl/tests/unit/test_add_preexisting_cert.js
[task 2019-11-15T23:04:03.804Z] 23:04:03  WARNING -  TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/unit/test_add_preexisting_cert.js | xpcshell return code: 0
[task 2019-11-15T23:04:03.804Z] 23:04:03     INFO -  TEST-INFO took 412ms
[task 2019-11-15T23:04:03.805Z] 23:04:03     INFO -  >>>>>>>
[task 2019-11-15T23:04:03.805Z] 23:04:03     INFO -  security/manager/ssl/tests/unit/test_add_preexisting_cert.js | /data/local/xpcb/xpcw[19]: cd: /sdcard/tests/xpc/security/manager/ssl/tests/unit: No such file or directory
[task 2019-11-15T23:04:03.806Z] 23:04:03     INFO -  security/manager/ssl/tests/unit/test_add_preexisting_cert.js | xpcw: cd /sdcard/tests/xpc/security/manager/ssl/tests/unit
[task 2019-11-15T23:04:03.808Z] 23:04:03     INFO -  security/manager/ssl/tests/unit/test_add_preexisting_cert.js | xpcw: xpcshell -r /sdcard/tests/xpc/c/httpd.manifest --greomni /data/local/xpcb/geckoview-androidTest.apk -m -s -e const _HEAD_JS_PATH = "/sdcard/tests/xpc/head.js"; -e const _MOZINFO_JS_PATH = "/sdcard/tests/xpc/p/mozinfo.json"; -e const _PREFS_FILE = "/sdcard/tests/xpc/user.js"; -e const _TESTING_MODULES_DIR = "/sdcard/tests/xpc/m"; -f /sdcard/tests/xpc/head.js -e const _HEAD_FILES = ["/sdcard/tests/xpc/security/manager/ssl/tests/unit/head_psm.js"]; -e const _JSDEBUGGER_PORT = 0; -e const _TEST_FILE = ["test_add_preexisting_cert.js"]; -e const _TEST_NAME = "security/manager/ssl/tests/unit/test_add_preexisting_cert.js"; -e _execute_test(); quit(0);
[task 2019-11-15T23:04:03.809Z] 23:04:03     INFO -  Error: cannot open file '/sdcard/tests/xpc/security/manager/ssl/tests/unit/head_psm.js' for reading at /sdcard/tests/xpc/head.js:684
[task 2019-11-15T23:04:03.810Z] 23:04:03     INFO -  load_file@/sdcard/tests/xpc/head.js:684:11
[task 2019-11-15T23:04:03.810Z] 23:04:03     INFO -  _load_files@/sdcard/tests/xpc/head.js:696:10
[task 2019-11-15T23:04:03.811Z] 23:04:03     INFO -  _execute_test@/sdcard/tests/xpc/head.js:543:14
[task 2019-11-15T23:04:03.811Z] 23:04:03     INFO -  @-e:1:1
[task 2019-11-15T23:04:03.812Z] 23:04:03     INFO -  Error: cannot open file 'test_add_preexisting_cert.js' for reading at /sdcard/tests/xpc/head.js:684
[task 2019-11-15T23:04:03.812Z] 23:04:03     INFO -  load_file@/sdcard/tests/xpc/head.js:684:11
[task 2019-11-15T23:04:03.813Z] 23:04:03     INFO -  _load_files@/sdcard/tests/xpc/head.js:696:10
[task 2019-11-15T23:04:03.813Z] 23:04:03     INFO -  _execute_test@/sdcard/tests/xpc/head.js:545:14
[task 2019-11-15T23:04:03.813Z] 23:04:03     INFO -  @-e:1:1
[task 2019-11-15T23:04:03.814Z] 23:04:03     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2019-11-15T23:04:03.814Z] 23:04:03     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2019-11-15T23:04:03.815Z] 23:04:03     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2019-11-15T23:04:03.815Z] 23:04:03     INFO -  running event loop
[task 2019-11-15T23:04:03.815Z] 23:04:03     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (1)
[task 2019-11-15T23:04:03.816Z] 23:04:03     INFO -  exiting test
[task 2019-11-15T23:04:03.816Z] 23:04:03     INFO -  <<<<<<<

Note the path difference:
/sdcard/tests/xpc/xpc/security/manager/ssl/tests/unit/head_psm.js
/sdcard/tests/xpc/security/manager/ssl/tests/unit/head_psm.js

It appears that adb push created the wrong directory hierarchy.

Success:

[task 2019-11-15T18:39:42.935Z] 18:39:42     INFO -  pushing /builds/worker/workspace/build/tests/xpcshell/tests
[task 2019-11-15T18:39:43.037Z] 18:39:43     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T18:39:43.242Z] 18:39:43     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T18:39:43.345Z] 18:39:43     INFO -  adb shell_bool: adb -s emulator-5554 wait-for-device shell mkdir -p /sdcard/tests/xpc; echo adb_returncode=$?, timeout: None, root: True, timedout: None, exitcode: 0, output:
[task 2019-11-15T18:39:43.449Z] 18:39:43     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T18:39:43.449Z] 18:39:43     INFO -  adb chmod: path=/sdcard/tests/xpc, recursive=True, mask=777, root=True
[task 2019-11-15T18:39:43.449Z] 18:39:43     INFO -  adb Ignoring attempt to chmod external storage
[task 2019-11-15T18:39:43.551Z] 18:39:43     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: 600, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T18:39:44.130Z] 18:39:44     INFO -  adb shell_bool: adb -s emulator-5554 wait-for-device shell ls -a /sdcard/tests/xpc/; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output: .
[task 2019-11-15T18:39:44.130Z] 18:39:44     INFO -  ..
[task 2019-11-15T18:39:50.044Z] 18:39:50     INFO -  adb command_output: adb -s emulator-5554 wait-for-device push /tmp/tmpoQAlPZ/xpc /sdcard/tests, timeout: 600, timedout: None, exitcode: 0, output: /tmp/tmpoQAlPZ/xpc/: 4919 files pushed. 8.2 MB/s (50138037 bytes in 5.854s)

Failure:

[task 2019-11-15T23:03:37.503Z] 23:03:37     INFO -  pushing /builds/worker/workspace/build/tests/xpcshell/tests
[task 2019-11-15T23:03:37.609Z] 23:03:37     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T23:03:37.813Z] 23:03:37     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T23:03:37.915Z] 23:03:37     INFO -  adb shell_bool: adb -s emulator-5554 wait-for-device shell mkdir -p /sdcard/tests/xpc; echo adb_returncode=$?, timeout: None, root: True, timedout: None, exitcode: 0, output:
[task 2019-11-15T23:03:38.019Z] 23:03:38     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T23:03:38.019Z] 23:03:38     INFO -  adb chmod: path=/sdcard/tests/xpc, recursive=True, mask=777, root=True
[task 2019-11-15T23:03:38.020Z] 23:03:38     INFO -  adb Ignoring attempt to chmod external storage
[task 2019-11-15T23:03:38.125Z] 23:03:38     INFO -  adb shell_output: adb -s emulator-5554 wait-for-device shell sync; echo adb_returncode=$?, timeout: 600, root: False, timedout: None, exitcode: 0, output:
[task 2019-11-15T23:03:38.661Z] 23:03:38     INFO -  adb shell_bool: adb -s emulator-5554 wait-for-device shell ls -a /sdcard/tests/xpc/; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: None, output:
[task 2019-11-15T23:03:44.171Z] 23:03:44     INFO -  adb command_output: adb -s emulator-5554 wait-for-device push /tmp/tmpTNEhoH/xpc /sdcard/tests/xpc, timeout: 600, timedout: None, exitcode: 0, output: /tmp/tmpTNEhoH/xpc/: 4919 files pushed. 8.7 MB/s (50138037 bytes in 5.468s)

In both success and failure cases, mkdir -p /sdcard/tests/xpc appears to complete normally, as do the following two syncs.

The subsequent check for directory existence, ls -a /sdcard/tests/xpc/ infrequently intermittently fails:

adb shell_bool: adb -s emulator-5554 wait-for-device shell ls -a /sdcard/tests/xpc/; echo adb_returncode=$?, timeout: None, root: False, timedout: None, exitcode: None, output:

adb.py is using ls instead of test here because of a previously noted emulator-specific bug:

https://searchfox.org/mozilla-central/rev/131338e5017bc0283d86fb73844407b9a2155c98/testing/mozbase/mozdevice/mozdevice/adb.py#2060-2070

The subsequent push has a different destination argument because the directory does not appear to exist.

https://searchfox.org/mozilla-central/rev/131338e5017bc0283d86fb73844407b9a2155c98/testing/mozbase/mozdevice/mozdevice/adb.py#2359-2360

That's appropriate, but causes trouble because the /sdcard/tests/xpc directory actually does exist already, so the push ends up pushing to /sdcard/tests/xpc/xpc.

Currently the xpcshell harness ensures the remote scripts directory, /sdcard/tests/xpc, is
deleted, then re-creates it, then pushes to it. In this bug, confusion arises when a pre-push
check for directory existence intermittently fails (reports the directory does not exist
when in fact it does). Let's simplify this sequence by simply ensuring that the directory
has been deleted, then push to it.

Pushed by gbrown@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/d8bdee06190f
In Android xpcshell tests, do not push tests to existing directory; r=bc
Status: NEW → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla72
Blocks: 1598737
See Also: → 1596072
See Also: → 1564920
You need to log in before you can comment on or make changes to this bug.