Closed
Bug 1921555
Opened 1 year ago
Closed 1 year ago
Intermittent perftest startup-fenix-cvns [tier 2][taskcluster:error] exit status 1 | after mozperftest.system.android_startup.AndroidStartUpMatchingError: Expected to match 1 process start string but matched 0
Categories
(Testing :: mozperftest, defect, P5)
Testing
mozperftest
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=476069377&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QKtYqlXtRTex4BuZLSxi3Q/runs/0/artifacts/public/logs/live_backing.log
[task 2024-09-27T20:03:39.004Z] browsertime installed successfully!
[task 2024-09-27T20:03:39.004Z]
[task 2024-09-27T20:03:39.004Z] NOTE: Your local browsertime binary is at /builds/worker/.mozbuild/browsertime/node_modules/.bin/browsertime
[task 2024-09-27T20:03:39.004Z]
[task 2024-09-27T20:03:39.004Z] Traceback (most recent call last):
[task 2024-09-27T20:03:39.004Z] File "python/mozperftest/mozperftest/runner.py", line 299, in <module>
[task 2024-09-27T20:03:39.004Z] sys.exit(main())
[task 2024-09-27T20:03:39.004Z] File "python/mozperftest/mozperftest/runner.py", line 295, in main
[task 2024-09-27T20:03:39.004Z] run_tests(mach_cmd, args, user_args)
[task 2024-09-27T20:03:39.004Z] File "python/mozperftest/mozperftest/runner.py", line 188, in run_tests
[task 2024-09-27T20:03:39.004Z] e.run(metadata)
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/environment.py", line 92, in run
[task 2024-09-27T20:03:39.004Z] metadata = testlayer(syslayer(metadata))
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/layers.py", line 157, in __call__
[task 2024-09-27T20:03:39.004Z] metadata = layer(metadata)
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/layers.py", line 69, in __call__
[task 2024-09-27T20:03:39.004Z] metadata = self.run(metadata)
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 153, in run
[task 2024-09-27T20:03:39.004Z] self.get_measurements(metadata)
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 162, in get_measurements
[task 2024-09-27T20:03:39.004Z] measurements = self.install_apk_onto_device_and_run()
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 199, in install_apk_onto_device_and_run
[task 2024-09-27T20:03:39.004Z] return self.run_tests()
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 228, in run_tests
[task 2024-09-27T20:03:39.004Z] test_measurements.append(self.get_measurement(self.test_name, process))
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 259, in get_measurement
[task 2024-09-27T20:03:39.004Z] return self.get_measurement_from_nav_start_logcat(proc)
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 322, in get_measurement_from_nav_start_logcat
[task 2024-09-27T20:03:39.004Z] __get_page_start_datetime() - __get_proc_start_datetime()
[task 2024-09-27T20:03:39.004Z] File "/builds/task_172746644774284/checkouts/gecko/python/mozperftest/mozperftest/system/android_startup.py", line 290, in __get_proc_start_datetime
[task 2024-09-27T20:03:39.004Z] raise AndroidStartUpMatchingError(
[task 2024-09-27T20:03:39.004Z] mozperftest.system.android_startup.AndroidStartUpMatchingError: Expected to match 1 process start string but matched 0
[task 2024-09-27T20:03:39.004Z] script.py: command finished
[task 2024-09-27T20:03:39.005Z]
[task 2024-09-27T20:03:39.005Z] netstat -aop
[task 2024-09-27T20:03:39.005Z] Active Internet connections (servers and established)
[task 2024-09-27T20:03:39.005Z] Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name Timer
[task 2024-09-27T20:03:39.005Z] tcp 0 0 localhost:8099 0.0.0.0:* LISTEN 77/taskcluster-prox off (0.00/0/0)
[task 2024-09-27T20:03:39.005Z] tcp 0 0 127.0.0.11:42503 0.0.0.0:* LISTEN - off (0.00/0/0)
[task 2024-09-27T20:03:39.005Z] tcp 0 0 localhost:5037 localhost:54829 TIME_WAIT - timewait (37.13/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:60697 TIME_WAIT - timewait (37.15/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:37113 TIME_WAIT - timewait (37.12/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:43831 TIME_WAIT - timewait (54.59/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:50353 TIME_WAIT - timewait (37.13/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:59619 TIME_WAIT - timewait (17.03/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:41351 TIME_WAIT - timewait (16.85/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:45225 TIME_WAIT - timewait (35.97/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:55549 TIME_WAIT - timewait (35.90/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:40917 TIME_WAIT - timewait (18.10/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:52503 TIME_WAIT - timewait (54.59/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:58345 TIME_WAIT - timewait (35.82/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:51867 TIME_WAIT - timewait (16.86/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:53367 TIME_WAIT - timewait (35.90/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:50317 TIME_WAIT - timewait (18.04/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:44519 TIME_WAIT - timewait (35.96/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:51985 TIME_WAIT - timewait (16.78/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:55843 TIME_WAIT - timewait (35.90/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:41961 TIME_WAIT - timewait (37.57/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:49979 TIME_WAIT - timewait (35.82/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:46823 TIME_WAIT - timewait (35.88/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 bitbar-ubuntu-199:42756 137.80.201.35.bc.:https ESTABLISHED 26/generic-worker keepalive (4.09/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:35373 TIME_WAIT - timewait (18.04/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:53225 TIME_WAIT - timewait (54.68/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:40773 TIME_WAIT - timewait (37.10/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:39029 TIME_WAIT - timewait (16.81/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:41363 TIME_WAIT - timewait (37.10/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:38009 TIME_WAIT - timewait (18.06/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:57351 TIME_WAIT - timewait (18.73/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:57519 TIME_WAIT - timewait (35.92/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:54927 TIME_WAIT - timewait (16.61/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:43037 TIME_WAIT - timewait (54.54/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:34623 TIME_WAIT - timewait (17.98/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:42261 TIME_WAIT - timewait (0.00/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:34513 TIME_WAIT - timewait (16.61/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:50529 TIME_WAIT - timewait (16.81/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:57069 TIME_WAIT - timewait (18.06/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:58259 TIME_WAIT - timewait (35.92/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:47773 TIME_WAIT - timewait (18.06/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:34969 TIME_WAIT - timewait (16.61/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:51307 TIME_WAIT - timewait (16.72/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:44041 TIME_WAIT - timewait (36.06/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:39745 TIME_WAIT - timewait (16.70/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:34277 TIME_WAIT - timewait (16.72/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:46707 TIME_WAIT - timewait (59.93/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:44799 TIME_WAIT - timewait (37.10/0/0)
[task 2024-09-27T20:03:39.006Z] tcp 0 0 localhost:5037 localhost:53345 TIME_WAIT - timewait (35.76/0/0)
[task 2024-09-27T20:03:39.006Z] tcp6 0 0 [::]:60099 [::]:* LISTEN 70/livelog off (0.00/0/0)
[task 2024-09-27T20:03:39.006Z] tcp6 0 0 [::]:60098 [::]:* LISTEN 70/livelog off (0.00/0/0)
[task 2024-09-27T20:03:39.006Z] tcp6 0 0 localhost:51020 localhost:60098 ESTABLISHED 26/generic-worker keepalive (12.60/0/0)
[task 2024-09-27T20:03:39.006Z] tcp6 0 0 localhost:60098 localhost:51020 ESTABLISHED 70/livelog keepalive (2.46/0/0)
[task 2024-09-27T20:03:39.006Z] udp 0 0 127.0.0.11:40515 0.0.0.0:* - off (0.00/0/0)
[task 2024-09-27T20:03:39.006Z] Active UNIX domain sockets (servers and established)
[task 2024-09-27T20:03:39.006Z] Proto RefCnt Flags Type State I-Node PID/Program name Path
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z] df -h
[task 2024-09-27T20:03:39.006Z] Filesystem Size Used Avail Use% Mounted on
[task 2024-09-27T20:03:39.006Z] overlay 914G 63G 813G 8% /
[task 2024-09-27T20:03:39.006Z] tmpfs 64M 0 64M 0% /dev
[task 2024-09-27T20:03:39.006Z] shm 64M 0 64M 0% /dev/shm
[task 2024-09-27T20:03:39.006Z] /dev/mapper/ubuntu--vg-ubuntu--lv 914G 63G 813G 8% /test
[task 2024-09-27T20:03:39.006Z] tmpfs 32G 0 32G 0% /proc/asound
[task 2024-09-27T20:03:39.006Z] tmpfs 32G 0 32G 0% /proc/acpi
[task 2024-09-27T20:03:39.006Z] tmpfs 32G 0 32G 0% /proc/scsi
[task 2024-09-27T20:03:39.006Z] tmpfs 32G 0 32G 0% /sys/firmware
[task 2024-09-27T20:03:39.006Z] tmpfs 32G 0 32G 0% /sys/devices/virtual/powercap
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z]
[task 2024-09-27T20:03:39.006Z] script.py: exiting with exitcode 1.
[taskcluster 2024-09-27T20:03:39.119Z] Exit Code: 1
[taskcluster 2024-09-27T20:03:39.119Z] User Time: 1m23.763663s
[taskcluster 2024-09-27T20:03:39.119Z] Kernel Time: 53.304629s
[taskcluster 2024-09-27T20:03:39.119Z] Wall Time: 16m10.644675204s
[taskcluster 2024-09-27T20:03:39.119Z] Result: FAILED
[taskcluster 2024-09-27T20:03:39.119Z] === Task Finished ===
[taskcluster 2024-09-27T20:03:39.119Z] Task Duration: 16m10.64665284s
[taskcluster 2024-09-27T20:03:39.120Z] [mounts] Preserving cache: Moving "/builds/task_172746644774284/checkouts" to "caches/S1qfa6rNQmG97WBKYspGSA"
[taskcluster 2024-09-27T20:03:39.201Z] Uploading redirect artifact public/logs/live.log to URL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QKtYqlXtRTex4BuZLSxi3Q/runs/0/artifacts/public%2Flogs%2Flive_backing.log with mime type "text/plain; charset=utf-8" and expiry 2025-09-27T17:01:59.178Z
[taskcluster:error] exit status 1
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
|
Reporter | |
Comment 3•1 year ago
|
||
| treeherder | ||
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=489885499&repo=mozilla-central
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 5•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: REOPENED → RESOLVED
Closed: 1 year ago → 1 year ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•