Closed Bug 1553932 Opened 5 years ago Closed 5 years ago

Intermittent subprocess.CalledProcessError: Command '['/builds/task_1558633286/workspace/testing/mozproxy/host-utils-68.0a1.en-US.linux-x86_64/certutil', '-d', 'sql:/tmp/tmp5784Or.mozrunner/', '-L']' returned non-zero exit status 255

Categories

(Testing :: Raptor, defect, P1)

Version 3
defect

Tracking

(firefox-esr60 unaffected, firefox-esr68 unaffected, firefox68 wontfix, firefox69 fixed, firefox70 fixed)

RESOLVED FIXED
mozilla70
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox68 --- wontfix
firefox69 --- fixed
firefox70 --- fixed

People

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

References

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disable-recommended])

Attachments

(1 file)

Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=248011710&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/Vr3PMQEzRDag1hGsMtsexw/runs/0/artifacts/public/logs/live_backing.log


17:43:27 ERROR - Traceback (most recent call last):
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 1230, in <module>
17:43:27 INFO - main()
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 1198, in main
17:43:27 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 960, in run_tests
17:43:27 INFO - return super(RaptorAndroid, self).run_tests(tests, test_names)
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 186, in run_tests
17:43:27 INFO - self.run_test(test, timeout=int(test['page_timeout']))
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 979, in run_test
17:43:27 INFO - self.run_test_cold(test, timeout)
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 1034, in run_test_cold
17:43:27 INFO - self.start_playback(test)
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/tests/raptor/raptor/raptor.py", line 357, in start_playback
17:43:27 INFO - self.playback.start()
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/venv/lib/python2.7/site-packages/mozproxy/backends/mitm.py", line 125, in start
17:43:27 INFO - self.setup()
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/venv/lib/python2.7/site-packages/mozproxy/backends/mitm.py", line 384, in setup
17:43:27 INFO - self.install_mitmproxy_cert(self.browser_path)
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/venv/lib/python2.7/site-packages/mozproxy/backends/mitm.py", line 535, in install_mitmproxy_cert
17:43:27 INFO - if not self.is_mitmproxy_cert_installed():
17:43:27 INFO - File "/builds/task_1558633286/workspace/build/venv/lib/python2.7/site-packages/mozproxy/backends/mitm.py", line 552, in is_mitmproxy_cert_installed
17:43:27 INFO - cmd_output = subprocess.check_output(command, env=os.environ.copy())
17:43:27 INFO - File "/usr/lib/python2.7/subprocess.py", line 574, in check_output
17:43:27 INFO - raise CalledProcessError(retcode, cmd, output=output)
17:43:27 INFO - subprocess.CalledProcessError: Command '['/builds/task_1558633286/workspace/testing/mozproxy/host-utils-68.0a1.en-US.linux-x86_64/certutil', '-d', 'sql:/tmp/tmp5784Or.mozrunner/', '-L']' returned non-zero exit status 255
17:43:27 INFO - certutil: could not change trust on certificate: SEC_ERROR_PKCS11_DEVICE_ERROR: A PKCS #11 module returned CKR_DEVICE_ERROR, indicating that a problem has occurred with the token or slot.
17:43:27 ERROR - Return code: 1
17:43:27 WARNING - setting return code to 1
17:43:27 INFO - Killing logcat pid 465.
17:43:27 CRITICAL - PERFHERDER_DATA was seen 0 times, expected 1.
17:43:27 INFO - copying raptor results to upload dir:
17:43:27 INFO - /builds/task_1558633286/workspace/build/blobber_upload_dir/perfherder-data.json
17:43:27 INFO - copying raptor results from /builds/task_1558633286/workspace/build/raptor.json to /builds/task_1558633286/workspace/build/blobber_upload_dir/perfherder-data.json
17:43:27 CRITICAL - Error copying results /builds/task_1558633286/workspace/build/raptor.json to upload dir /builds/task_1558633286/workspace/build/blobber_upload_dir/perfherder-data.json
17:43:27 INFO - [Errno 2] No such file or directory: u'/builds/task_1558633286/workspace/build/raptor.json'
17:43:27 INFO - Running post-action listener: _package_coverage_data
17:43:27 INFO - Running post-action listener: _resource_record_post_action
17:43:27 INFO - Running post-action listener: process_java_coverage_data
17:43:27 INFO - Running post-action listener: stop_device
17:43:30 INFO - Killing logcat pid 465.
17:43:30 INFO - [mozharness: 2019-05-23 17:43:30.031711Z] Finished run-tests step (success)
17:43:30 INFO - Running post-run listener: _resource_record_post_run
17:43:30 INFO - Total resource usage - Wall time: 71s; CPU: 41.0%; Read bytes: 0; Write bytes: 7399153664; Read time: 0; Write time: 86768584
17:43:30 INFO - TinderboxPrint: CPU usage<br/>41.2%
17:43:30 INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
17:43:30 INFO - TinderboxPrint: I/O write bytes / time<br/>7,399,153,664 / 86,768,584
17:43:30 INFO - TinderboxPrint: CPU idle<br/>123.9 (43.0%)
17:43:30 INFO - TinderboxPrint: CPU iowait<br/>45.8 (15.9%)
17:43:30 INFO - TinderboxPrint: CPU softirq<br/>6.8 (2.4%)
17:43:30 INFO - TinderboxPrint: CPU system<br/>21.8 (7.6%)
17:43:30 INFO - TinderboxPrint: CPU user<br/>89.7 (31.2%)
17:43:30 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
17:43:30 INFO - install - Wall time: 13s; CPU: 41.0%; Read bytes: 0; Write bytes: 159391744; Read time: 0; Write time: 2196820
17:43:30 INFO - run-tests - Wall time: 56s; CPU: 40.0%; Read bytes: 0; Write bytes: 6496309248; Read time: 0; Write time: 83958844
17:43:30 WARNING - returning nonzero exit status 1
cleanup

  • cleanup
  • local rv=1
  • [[ -s /builds/worker/.xsession-errors ]]
  • false
  • exit 1

In the last 7 days there were 49 failures associated with this bug: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-07-07&endday=2019-07-14&tree=trunk&bug=1553932
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=256417309&repo=mozilla-inbound&lineNumber=1256
Occurs on android-hw-p2-8-0-android-aarch64, android-hw-p2-8-0-arm7-api-16, android-hw-g5-7-0-arm7-api-16 build type.

Flags: needinfo?(rwood)

:bebe can you please have a look and investigate this as it pertains to mozproxy, thanks!

Flags: needinfo?(rwood) → needinfo?(fstrugariu)
Assignee: nobody → fstrugariu
Flags: needinfo?(fstrugariu)
Whiteboard: [stockwell disable-recommended] → [stockwell needswork]
Status: NEW → ASSIGNED
Flags: needinfo?(fstrugariu)
Priority: P5 → P1

Robert, Dave, could you please review Florin's patch for these failures? This is on the disabled recommeded list for quite a while now and it has 281 total failures in the last 30 days. Thank you.

Flags: needinfo?(rwood)
Flags: needinfo?(dave.hunt)

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

Robert, Dave, could you please review Florin's patch for these failures? This is on the disabled recommeded list for quite a while now and it has 281 total failures in the last 30 days. Thank you.

I've reviewed the patch, but I'm not clear how this would resolve the error. It looks to me that it might highlight the error message in the logs, which will make it easier to identify, but I don't see a fix here.

Flags: needinfo?(dave.hunt)
Flags: needinfo?(rwood)

Hi Florin, Are there any updates here?

Flags: needinfo?(fstrugariu)

Hi Joel, can you please take a look at this bug?

Flags: needinfo?(jmaher)
Pushed by fstrugariu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4fcbb2234b02
Update mozproxy certutil usage r=tarek
Flags: needinfo?(jmaher)
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla70
Flags: needinfo?(fstrugariu)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: