Filed by: csabou [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=163279369&repo=mozilla-central https://queue.taskcluster.net/v1/task/NpmaWgNeSdqyn3Wmxqpsiw/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/NpmaWgNeSdqyn3Wmxqpsiw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1 task 2018-02-20T20:27:13.362Z] 20:27:13 INFO - INFO - File grcov-linux-standalone-x86_64.tar.bz2 not present in local cache folder /builds/worker/tooltool-cache [task 2018-02-20T20:27:13.363Z] 20:27:13 INFO - INFO - Attempting to fetch from 'https://tooltool.mozilla-releng.net/'... [task 2018-02-20T20:28:51.634Z] 20:28:51 INFO - INFO - File grcov-linux-standalone-x86_64.tar.bz2 fetched from https://tooltool.mozilla-releng.net/ as /tmp/tmpDxynbb/tmpnRKvfU [task 2018-02-20T20:28:51.634Z] 20:28:51 INFO - ERROR - ''tmpnRKvfU' is present and invalid' [task 2018-02-20T20:28:51.634Z] 20:28:51 INFO - ERROR - The following files failed: 'grcov-linux-standalone-x86_64.tar.bz2' [task 2018-02-20T20:28:51.640Z] 20:28:51 ERROR - Return code: 1 [task 2018-02-20T20:28:51.681Z] 20:28:51 ERROR - Exception during pre-action for run-tests: Traceback (most recent call last): [task 2018-02-20T20:28:51.682Z] 20:28:51 ERROR - File "/builds/worker/workspace/mozharness/mozharness/base/script.py", line 1973, in run_action [task 2018-02-20T20:28:51.682Z] 20:28:51 ERROR - method(action) [task 2018-02-20T20:28:51.682Z] 20:28:51 ERROR - File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/codecoverage.py", line 133, in _set_gcov_prefix [task 2018-02-20T20:28:51.683Z] 20:28:51 ERROR - with tarfile.open(os.path.join(self.grcov_dir, tar_file)) as tar: [task 2018-02-20T20:28:51.683Z] 20:28:51 ERROR - File "/usr/lib/python2.7/tarfile.py", line 1673, in open [task 2018-02-20T20:28:51.683Z] 20:28:51 ERROR - return func(name, "r", fileobj, **kwargs) [task 2018-02-20T20:28:51.683Z] 20:28:51 ERROR - File "/usr/lib/python2.7/tarfile.py", line 1738, in gzopen [task 2018-02-20T20:28:51.684Z] 20:28:51 ERROR - fileobj = gzip.GzipFile(name, mode, compresslevel, fileobj) [task 2018-02-20T20:28:51.684Z] 20:28:51 ERROR - File "/usr/lib/python2.7/gzip.py", line 94, in __init__ [task 2018-02-20T20:28:51.684Z] 20:28:51 ERROR - fileobj = self.myfileobj = __builtin__.open(filename, mode or 'rb') [task 2018-02-20T20:28:51.684Z] 20:28:51 ERROR - IOError: [Errno 2] No such file or directory: '/tmp/tmpDxynbb/grcov-linux-standalone-x86_64.tar.bz2' [task 2018-02-20T20:28:51.685Z] 20:28:51 INFO - Running post-action listener: _package_coverage_data [task 2018-02-20T20:28:51.685Z] 20:28:51 INFO - Running command: ['zip', '-q', '-0', '-r', '/builds/worker/workspace/code-coverage-gcda.zip', '.'] in /tmp/tmpic0p3E [task 2018-02-20T20:28:51.685Z] 20:28:51 INFO - Copy/paste: zip -q -0 -r /builds/worker/workspace/code-coverage-gcda.zip . [task 2018-02-20T20:28:51.743Z] 20:28:51 INFO - zip error: Nothing to do! (try: zip -q -0 -r /builds/worker/workspace/code-coverage-gcda.zip . -i .) [task 2018-02-20T20:28:51.744Z] 20:28:51 ERROR - Return code: 12 [task 2018-02-20T20:28:51.744Z] 20:28:51 INFO - Downloading https://queue.taskcluster.net/v1/task/Y1f1GrYXS7qAMAsKJ5vrZA/artifacts/public/build/chrome-map.json to chrome-map.json [task 2018-02-20T20:28:51.745Z] 20:28:51 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Y1f1GrYXS7qAMAsKJ5vrZA/artifacts/public/build/chrome-map.json', 'file_name': 'chrome-map.json'}, attempt #1 [task 2018-02-20T20:28:52.602Z] 20:28:52 INFO - Downloaded 1250037 bytes. [task 2018-02-20T20:28:52.642Z] 20:28:52 INFO - Running command: ['zip', '-q', '/builds/worker/workspace/build/blobber_upload_dir/code-coverage-jsvm.zip', 'jsvm_lcov_output.info'] [task 2018-02-20T20:28:52.642Z] 20:28:52 INFO - Copy/paste: zip -q /builds/worker/workspace/build/blobber_upload_dir/code-coverage-jsvm.zip jsvm_lcov_output.info [task 2018-02-20T20:28:52.646Z] 20:28:52 INFO - zip I/O error: No such file or directory [task 2018-02-20T20:28:52.646Z] 20:28:52 INFO - zip error: Could not create output file (/builds/worker/workspace/build/blobber_upload_dir/code-coverage-jsvm.zip) [task 2018-02-20T20:28:52.647Z] 20:28:52 ERROR - Return code: 15 [task 2018-02-20T20:28:52.647Z] 20:28:52 INFO - Downloading https://queue.taskcluster.net/v1/task/Y1f1GrYXS7qAMAsKJ5vrZA/artifacts/public/build/target.code-coverage-gcno.zip to /tmp/tmpDxynbb/target.code-coverage-gcno.zip [task 2018-02-20T20:28:52.647Z] 20:28:52 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Y1f1GrYXS7qAMAsKJ5vrZA/artifacts/public/build/target.code-coverage-gcno.zip', 'file_name': '/tmp/tmpDxynbb/target.code-coverage-gcno.zip'}, attempt #1 [task 2018-02-20T20:28:54.317Z] 20:28:54 INFO - Downloaded 90750215 bytes. [task 2018-02-20T20:28:54.317Z] 20:28:54 INFO - Getting output from command: ['/tmp/tmpDxynbb/grcov', '-t', 'lcov', '-p', '/builds/worker/workspace/build/src/', '--ignore-dir', 'gcc', '/tmp/tmpDxynbb/target.code-coverage-gcno.zip', '/builds/worker/workspace/code-coverage-gcda.zip'] [task 2018-02-20T20:28:54.317Z] 20:28:54 INFO - Copy/paste: /tmp/tmpDxynbb/grcov -t lcov -p /builds/worker/workspace/build/src/ --ignore-dir gcc /tmp/tmpDxynbb/target.code-coverage-gcno.zip /builds/worker/workspace/code-coverage-gcda.zip [task 2018-02-20T20:28:54.347Z] 20:28:54 ERROR - An additional exception occurred during post-action for run-tests: Traceback (most recent call last): [task 2018-02-20T20:28:54.348Z] 20:28:54 ERROR - File "/builds/worker/workspace/mozharness/mozharness/base/script.py", line 1985, in run_action [task 2018-02-20T20:28:54.348Z] 20:28:54 ERROR - method(action, success=False) [task 2018-02-20T20:28:54.348Z] 20:28:54 ERROR - File "/builds/worker/workspace/mozharness/mozharness/mozilla/testing/codecoverage.py", line 208, in _package_coverage_data [task 2018-02-20T20:28:54.348Z] 20:28:54 ERROR - throw_exception=True, [task 2018-02-20T20:28:54.349Z] 20:28:54 ERROR - File "/builds/worker/workspace/mozharness/mozharness/base/script.py", line 1555, in get_output_from_command [task 2018-02-20T20:28:54.349Z] 20:28:54 ERROR - cwd=cwd, stderr=tmp_stderr, env=env) [task 2018-02-20T20:28:54.349Z] 20:28:54 ERROR - File "/usr/lib/python2.7/subprocess.py", line 711, in __init__ [task 2018-02-20T20:28:54.350Z] 20:28:54 ERROR - errread, errwrite) [task 2018-02-20T20:28:54.350Z] 20:28:54 ERROR - File "/usr/lib/python2.7/subprocess.py", line 1343, in _execute_child [task 2018-02-20T20:28:54.350Z] 20:28:54 ERROR - raise child_exception [task 2018-02-20T20:28:54.350Z] 20:28:54 ERROR - OSError: [Errno 2] No such file or directory [task 2018-02-20T20:28:54.351Z] 20:28:54 INFO - Running post-action listener: _resource_record_post_action [task 2018-02-20T20:28:54.351Z] 20:28:54 FATAL - Aborting due to exception in pre-action listener. [task 2018-02-20T20:28:54.351Z] 20:28:54 FATAL - Running post_fatal callback... [task 2018-02-20T20:28:54.352Z] 20:28:54 FATAL - Exiting -1 [task 2018-02-20T20:28:54.352Z] 20:28:54 INFO - Running post-run listener: _resource_record_post_run [task 2018-02-20T20:28:54.415Z] 20:28:54 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json [task 2018-02-20T20:28:54.420Z] 20:28:54 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 16.15418149466192}, {"name": "io_write_bytes", "value": 4083064832}, {"name": "io.read_bytes", "value": 761856}, {"name": "io_write_time", "value": 800396}, {"name": "io_read_time", "value": 368}], "extraOptions": ["e10s", "taskcluster-c3.xlarge"], "name": "reftest.reftest-no-accel.1.overall"}, {"subtests": [{"name": "time", "value": 180.35407209396362}, {"name": "cpu_percent", "value": 25.090138888888887}], "name": "reftest.reftest-no-accel.1.install"}, {"subtests": [{"name": "time", "value": 0.0005772113800048828}], "name": "reftest.reftest-no-accel.1.stage-files"}, {"subtests": [{"name": "time", "value": 101.03518509864807}, {"name": "cpu_percent", "value": 0.17875}], "name": "reftest.reftest-no-accel.1.run-tests"}]} [task 2018-02-20T20:28:54.421Z] 20:28:54 INFO - Total resource usage - Wall time: 281s; CPU: 0.0%; Read bytes: 761856; Write bytes: 4083064832; Read time: 368; Write time: 800396

Analyzed the logs and it appears that the worker already had (or he thought it had) some sort of file named "grcov-linux-standalone-x86_64.tar.bz2" fetched from "https://tooltool.mozilla-releng.net/" present but invalid and when it tries to unzip it it could not find the file thus giving the "IOError: [Errno 2] No such file or directory:..." error. The occurrence happened in 2018-02-20, talked with csabou and since that, no recurrence has been found and the issue seems fixed. I will close this bug for now, please reopen if it resurfaces.

We're seeing this pretty often on Mac. E.g. https://treeherder.mozilla.org/#/jobs?repo=try&revision=6101fb3b55a50c72e365f846bfc5ed27aee83ae0&selectedJob=187569883.

Didn't find anything obvious in the logs, a retry of the job can help.

(In reply to Marco Castelluccio [:marco] from comment #4) > We're seeing this pretty often on Mac. > E.g. > https://treeherder.mozilla.org/#/ > jobs?repo=try&revision=6101fb3b55a50c72e365f846bfc5ed27aee83ae0&selectedJob=1 > 87569883. Did you still have this problem? Did a re-trigger helped?

(In reply to Bogdan Crisan [:bcrisan] (UTC +3, EEST) from comment #7) > (In reply to Marco Castelluccio [:marco] from comment #4) > > We're seeing this pretty often on Mac. > > E.g. > > https://treeherder.mozilla.org/#/ > > jobs?repo=try&revision=6101fb3b55a50c72e365f846bfc5ed27aee83ae0&selectedJob=1 > > 87569883. > > Did you still have this problem? > > Did a re-trigger helped? It didn't happen when I retriggered. It happens intermittently. Both me, Calixte and Gabriel have seen this in our try pushes.

Today I've found this error regarding raptor-mitmproxy : https://treeherder.mozilla.org/logviewer.html#?job_id=193507481&repo=mozilla-central&lineNumber=721

I'm going to close this since we overhauled the way we download grcov (it's now a toolchain task).

New occurrences; https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=215146088&repo=autoland&lineNumber=554

Hey Razvan, that is a different issue.