1600537 - Perma refbrow raptor-main Critical: TEST-UNEXPECTED-FAIL: no raptor test results were found for raptor-tp6m-amazon-refbrow-cold

Status: RESOLVED FIXED

(Testing :: Raptor, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=278986813&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/atwV6S3uQA27EnnsU2BbLQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - Status: ok
[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - Activity: org.mozilla.reference.browser.raptor/org.mozilla.reference.browser.BrowserActivity
[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - ThisTime: 847
[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - TotalTime: 1499
[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - WaitTime: 1515
[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - Complete
[task 2019-12-02T03:33:13.982Z] 03:30:26 INFO - adb shell_output: adb -s ZY3223BKR3 wait-for-device shell pidof org.mozilla.reference.browser.raptor, timeout: None, root: False, timedout: None, exitcode: 0, output: 8119
[task 2019-12-02T03:33:13.982Z] 03:30:29 INFO - raptor-control-server Info: received webext_status: raptor runner.js is loaded!
[task 2019-12-02T03:33:13.982Z] 03:30:29 INFO - raptor-control-server Info: reading test settings from json/raptor-tp6m-amazon-refbrow-cold.json
[task 2019-12-02T03:33:13.982Z] 03:30:29 INFO - raptor-control-server Info: sent test settings to webext runner
[task 2019-12-02T03:33:13.982Z] 03:30:29 INFO - raptor-control-server Info: received webext_status: * pausing 30 seconds to let browser settle... *
[task 2019-12-02T03:33:13.982Z] 03:30:59 INFO - raptor-control-server Info: received webext_status: running 1 pagecycles of https://www.amazon.com
[task 2019-12-02T03:33:13.982Z] 03:31:00 INFO - raptor-control-server Info: received webext_status: begin pagecycle 1
[task 2019-12-02T03:33:13.982Z] 03:31:01 INFO - raptor-control-server Info: received webext_status: update tab: 0
[task 2019-12-02T03:33:13.982Z] 03:31:01 INFO - raptor-control-server Info: received webext_status: test tab updated: 0
[task 2019-12-02T03:33:22.641Z] 03:33:13 INFO - adb shell_output: adb -s ZY3223BKR3 wait-for-device shell am force-stop org.mozilla.reference.browser.raptor, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:13 CRITICAL - raptor-main Critical: Tests failed to finish! Application timed out.
[task 2019-12-02T03:33:22.641Z] 03:33:13 ERROR - raptor-main Error: Test failed to finish. Application timed out after 170 seconds
[task 2019-12-02T03:33:22.641Z] 03:33:13 INFO - raptor-main Info: removing reverse socket connections
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb command_output: adb -s ZY3223BKR3 wait-for-device reverse --remove-all, timeout: None, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb shell_bool: adb -s ZY3223BKR3 wait-for-device shell test -d /sdcard/raptor/profile/minidumps, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb shell_output: adb -s ZY3223BKR3 wait-for-device shell sync, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb shell_bool: adb -s ZY3223BKR3 wait-for-device shell test -d /sdcard/raptor/profile/minidumps, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb command_output: adb -s ZY3223BKR3 wait-for-device pull /sdcard/raptor/profile/minidumps /tmp/tmpOE6p1z/minidumps, timeout: None, timedout: None, exitcode: 0, output: /sdcard/raptor/profile/minidumps/: 0 files pulled.
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 826
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - raptor-mitmproxy Info: Successfully killed the mitmproxy playback process
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - raptor-main Info: removing webext /builds/task_1575257048/workspace/build/tests/raptor/raptor/../webext/raptor
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - perftest-results-handler Info: summarizing raptor test results
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - perftest-output Error: no raptor test results found for raptor-tp6m-amazon-refbrow-cold
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - perftest-output Info: error: no raptor test results found, so no need to combine browser cycles
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - perftest-output Error: no summarized raptor results found for raptor-tp6m-amazon-refbrow-cold
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - perftest-results-handler Critical: PERFHERDER_DATA was seen 0 times, expected 1.
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - raptor-main Info: removing test folder for raptor: /sdcard/raptor
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb shell_output: adb -s ZY3223BKR3 wait-for-device shell sync, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:14 INFO - adb shell_output: adb -s ZY3223BKR3 wait-for-device shell rm -r /sdcard/raptor, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - adb shell_output: adb -s ZY3223BKR3 wait-for-device shell sync, timeout: None, root: False, timedout: None, exitcode: 0, output:
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - adb shell_bool: adb -s ZY3223BKR3 wait-for-device shell test -e /sdcard/raptor, timeout: None, root: False, timedout: None, exitcode: 1, output:
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - raptor-control-server Info: shutting down control server
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - raptor-main Info: finished
[task 2019-12-02T03:33:22.641Z] 03:33:15 ERROR - raptor-main Critical: TEST-UNEXPECTED-FAIL: no raptor test results were found for raptor-tp6m-amazon-refbrow-cold
[task 2019-12-02T03:33:22.641Z] 03:33:15 ERROR - Return code: 1
[task 2019-12-02T03:33:22.641Z] 03:33:15 WARNING - setting return code to 1
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Killing logcat pid 590.
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Copying Raptor results to upload dir:
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - /builds/task_1575257048/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Copying raptor results from /builds/task_1575257048/workspace/build/raptor.json to /builds/task_1575257048/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2019-12-02T03:33:22.641Z] 03:33:15 CRITICAL - Error copying results /builds/task_1575257048/workspace/build/raptor.json to upload dir /builds/task_1575257048/workspace/build/blobber_upload_dir/perfherder-data.json
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - [Errno 2] No such file or directory: u'/builds/task_1575257048/workspace/build/raptor.json'
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Running post-action listener: _package_coverage_data
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Running post-action listener: _resource_record_post_action
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Running post-action listener: process_java_coverage_data
[task 2019-12-02T03:33:22.641Z] 03:33:15 INFO - Running post-action listener: stop_device
[task 2019-12-02T03:33:35.022Z] 03:33:22 INFO - /data/anr/traces.txt deleted
[task 2019-12-02T03:33:35.022Z] 03:33:28 INFO - /data/tombstones/dsps deleted
[task 2019-12-02T03:33:35.022Z] 03:33:30 INFO - /data/tombstones/lpass deleted
[task 2019-12-02T03:33:35.022Z] 03:33:32 INFO - /data/tombstones/modem deleted
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - /data/tombstones/wcnss deleted
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - Killing logcat pid 590.
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - [mozharness: 2019-12-02 03:33:34.651443Z] Finished run-tests step (success)
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - Running post-run listener: _resource_record_post_run
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - Total resource usage - Wall time: 278s; CPU: 3.0%; Read bytes: 0; Write bytes: 1585295360; Read time: 0; Write time: 1846156
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: CPU usage<br/>2.8%
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: I/O write bytes / time<br/>1,585,295,360 / 1,846,156
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: CPU idle<br/>1,059.7 (95.7%)
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: CPU iowait<br/>17.2 (1.6%)
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: CPU user<br/>18.8 (1.7%)
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - install - Wall time: 21s; CPU: 3.0%; Read bytes: 0; Write bytes: 243826688; Read time: 0; Write time: 376052
[task 2019-12-02T03:33:35.022Z] 03:33:34 INFO - run-tests - Wall time: 239s; CPU: 3.0%; Read bytes: 0; Write bytes: 1316487168; Read time: 0; Write time: 1462616
[task 2019-12-02T03:33:35.022Z] 03:33:34 WARNING - returning nonzero exit status

Comment 1

[Cosmin Sabou [:CosminS]]

This first failed on this TH merge to central but on the push before it did not run until backfilled so one of the changes here might be the culprit: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=classified&fromchange=cc63cec24824858451cd39af605565a80e4b8749&tochange=2d52a5a00e007ff7f78a053a446e246828cf3d60&searchStr=refbrow&selectedJob=278920319

Mitmproxy log: https://firefoxci.taskcluster-artifacts.net/atwV6S3uQA27EnnsU2BbLQ/0/public/test_info/mitmproxy.log

As this shows it's also on failing on retriggers where initially the job was green: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&resultStatus=success%2Cpending%2Crunning%2Ctestfailed%2Cbusted%2Cexception&searchStr=rap-refbrow&revision=b4b10ae558b9ca109218935d2bf48844cbfd7857&selectedJob=278850139

Robert, could you please take a look over this and maybe redirect it to someone? Thank you.

Comment 2

[Intermittent Failures Robot]

21 failures in 4331 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 21

Platform breakdown:

• android-hw-g5-7-0-arm7-api-16: 7
• android-hw-p2-8-0-arm7-api-16: 7
• android-hw-p2-8-0-android-aarch64: 7

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

Comment 3

[Robert Wood [:rwood]]

(In reply to Cosmin Sabou [:CosminS] from comment #1)

Robert, could you please take a look over this and maybe redirect it to someone? Thank you.

Thanks Cosmin.

:bebe, can you please have someone look into this? Thanks!

Comment 4

[Intermittent Failures Robot]

12 failures in 5144 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 12

Platform breakdown:

• android-hw-p2-8-0-android-aarch64: 4
• android-hw-g5-7-0-arm7-api-16: 4
• android-hw-p2-8-0-arm7-api-16: 4

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

Comment 5

[Florin Strugariu [:Bebe]]

I think this was fixed by the backout:
https://hg.mozilla.org/mozilla-central/rev/9420b5dc27e0cdf30a65b1b733400a970b3cb708

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• android-hw-g5-7-0-arm7-api-16: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1600537&startday=2019-12-09&endday=2019-12-15&tree=all