1552672 - Perma l10n IOError: [Errno 22] Invalid argument | WARNING: Python.h not found. Install Python development headers.

Status: RESOLVED FIXED

(Firefox Build System :: Task Configuration, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=247225305&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/D7aKn__CSfeKkFKSgHlKOQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-05-19T00:06:11.059Z] New python executable in /builds/worker/workspace/build/src/obj-x86_64-pc-linux-gnu/_virtualenvs/init/bin/python2.7
[task 2019-05-19T00:06:11.061Z] Also creating executable in /builds/worker/workspace/build/src/obj-x86_64-pc-linux-gnu/_virtualenvs/init/bin/python
[task 2019-05-19T00:06:12.226Z] Installing setuptools, pip, wheel...done.
[task 2019-05-19T00:06:12.406Z] WARNING: Python.h not found. Install Python development headers.
[task 2019-05-19T00:06:12.406Z] Error processing command. Ignoring because optional. (optional:setup.py:third_party/python/psutil:build_ext:--inplace)
[task 2019-05-19T00:06:12.410Z] Error processing command. Ignoring because optional. (optional:packages.txt:comm/build/virtualenv_packages.txt)

[task 2019-05-19T00:06:12.489Z] 00:06:12 INFO - Running main action method: repackage
[task 2019-05-19T00:06:12.489Z] 00:06:12 INFO - mkdir: /builds/worker/workspace/build/outputs/tl
[task 2019-05-19T00:06:12.489Z] 00:06:12 INFO - Running command: ['/builds/worker/workspace/build/src/obj-x86_64-pc-linux-gnu/_virtualenvs/init/bin/python', 'mach', '--log-no-times', 'repackage', u'mar', u'--arch', u'x86', '--input', u'/builds/worker/fetches/target.tar.bz2', '--mar', u'/builds/worker/fetches/mar', '--output', u'/builds/worker/workspace/build/outputs/tl/target.complete.mar'] in /builds/worker/workspace/build/src
[task 2019-05-19T00:06:12.490Z] 00:06:12 INFO - Copy/paste: /builds/worker/workspace/build/src/obj-x86_64-pc-linux-gnu/_virtualenvs/init/bin/python mach --log-no-times repackage mar --arch x86 --input /builds/worker/fetches/target.tar.bz2 --mar /builds/worker/fetches/mar --output /builds/worker/workspace/build/outputs/tl/target.complete.mar
[task 2019-05-19T00:06:12.728Z] 00:06:12 INFO - Error running mach:
[task 2019-05-19T00:06:12.728Z] 00:06:12 INFO - ['--log-no-times', 'repackage', 'mar', '--arch', 'x86', '--input', '/builds/worker/fetches/target.tar.bz2', '--mar', '/builds/worker/fetches/mar', '--output', '/builds/worker/workspace/build/outputs/tl/target.complete.mar']
[task 2019-05-19T00:06:12.728Z] 00:06:12 INFO - The error occurred in code that was called by the mach command. This is either
[task 2019-05-19T00:06:12.728Z] 00:06:12 INFO - a bug in the called code itself or in the way that mach is calling it.
[task 2019-05-19T00:06:12.728Z] 00:06:12 INFO - You can invoke |./mach busted| to check if this issue is already on file. If it
[task 2019-05-19T00:06:12.728Z] 00:06:12 INFO - isn't, please use |./mach busted file| to report it. If |./mach busted| is
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - misbehaving, you can also inspect the dependencies of bug 1543241.
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - If filing a bug, please include the full output of mach, including this error
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - message.
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - The details of the failure are as follows:
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - IOError: [Errno 22] Invalid argument
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/mach_commands.py", line 3813, in repackage_mar
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - repackage_mar(self.topsrcdir, input, mar, output, format, arch=arch)
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/repackaging/mar.py", line 35, in repackage_mar
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - z = zipfile.ZipFile(package)
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/usr/lib/python2.7/zipfile.py", line 770, in init
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - self._RealGetContents()
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/usr/lib/python2.7/zipfile.py", line 829, in _RealGetContents
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - fp.seek(self.start_dir, 0)
[task 2019-05-19T00:06:12.741Z] 00:06:12 ERROR - Return code: 1
[task 2019-05-19T00:06:12.741Z] 00:06:12 ERROR - 1 not in success codes: [0]
[task 2019-05-19T00:06:12.741Z] 00:06:12 WARNING - setting return code to 2
[task 2019-05-19T00:06:12.742Z] 00:06:12 FATAL - Halting on failure while running ['/builds/worker/workspace/build/src/obj-x86_64-pc-linux-gnu/_virtualenvs/init/bin/python', 'mach', '--log-no-times', 'repackage', u'mar', u'--arch', u'x86', '--input', u'/builds/worker/fetches/target.tar.bz2', '--mar', u'/builds/worker/fetches/mar', '--output', u'/builds/worker/workspace/build/outputs/tl/target.complete.mar']
[task 2019-05-19T00:06:12.742Z] 00:06:12 FATAL - Running post_fatal callback...
[task 2019-05-19T00:06:12.742Z] 00:06:12 FATAL - Exiting 2

Comment 1

[Natalia Csoregi [:nataliaCs]]

:mshal is there any chance you could take a look at this? Could it be the same issue as in https://bugzilla.mozilla.org/show_bug.cgi?id=1435575#c5 ?

Comment 2

[Justin Wood (:Callek)]

I don't know offhand what caused the actual error, but the summary is not an issue (Python.h missing is a warning not fatal)

[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - IOError: [Errno 22] Invalid argument
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/mach_commands.py", line 3813, in repackage_mar
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - repackage_mar(self.topsrcdir, input, mar, output, format, arch=arch)
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/builds/worker/workspace/build/src/python/mozbuild/mozbuild/repackaging/mar.py", line 35, in repackage_mar
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - z = zipfile.ZipFile(package)
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/usr/lib/python2.7/zipfile.py", line 770, in init
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - self._RealGetContents()
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - File "/usr/lib/python2.7/zipfile.py", line 829, in _RealGetContents
[task 2019-05-19T00:06:12.729Z] 00:06:12 INFO - fp.seek(self.start_dir, 0)

Comment 3

[Intermittent Failures Robot]

5 failures in 4658 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 5

Platform breakdown:

• linux32-shippable: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1552672&startday=2019-05-13&endday=2019-05-19&tree=all

Comment 4

[Michael Shal [:mshal]]

(In reply to Natalia Csoregi [:nataliaCs] from comment #1)

:mshal is there any chance you could take a look at this? Could it be the same issue as in https://bugzilla.mozilla.org/show_bug.cgi?id=1435575#c5 ?

Good call, looks like that is the problem. I downloaded the target.tar.bz2 used by the tl repackage task, and both zipfile.is_zipfile and tarfile.is_tarfile return true. I'll post a patch for it once I spot check it.

Comment 5

[Michael Shal [:mshal]]

Attachment: Bug 1552672 - Use is_tarfile() rather than is_zipfile() in mar repackaging; r?Callek

The zipfile.is_zipfile() function is overly lenient, in that non-zip
files that contain the four bytes "PK\005\006" near the end of the file
are reported as zip files even if the zip structure is not valid.
Occasionally, our target.tar.bz2 files randomly contain those 4 bytes at
the expected location, which causes the mar repackaging code to try to
process the package as a zip file instead of a tar file.

The tarfile.is_tarfile() logic looks a little more robust in that it
actually tries to open the file, so if we try tar first before falling
back to zip we should be a little more resilient.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/4a3fcb8ad12c
Use is_tarfile() rather than is_zipfile() in mar repackaging; r=Callek

Comment 7

[Daniel Varga [:dvarga]]

https://hg.mozilla.org/mozilla-central/rev/4a3fcb8ad12c

Comment 8

[Ryan VanderMeulen [:RyanVM]]

Do we know what caused this? Do we need to consider it for backport anywhere?

Comment 9

[Michael Shal [:mshal]]

(In reply to Ryan VanderMeulen [:RyanVM] from comment #8)

Do we know what caused this? Do we need to consider it for backport anywhere?

There isn't really a particular cause - the issue has been present since support for tar.gz was added to the mar repackaging in bug 1376550 (~June 2017), but it only manifests itself in the rare instance where a package is created that happens to contain the magic 4-byte sequence at the spot in the file that python's zipfile.is_zipfile() looks at. For this bug, the 'tl' locale packages just so happened to contain that sequence at the right spot.

I'm not sure if backporting is necessary or not. This bug and bug 1435575 are the only instances I'm aware of where we saw it happen, but maybe sheriffs know of others.

Comment 10

[Ryan VanderMeulen [:RyanVM]]

Given that this can affect release jobs (which can therefore lead to possible delays in build promotion), I think we should uplift this to Beta so it's in 68 for the next ESR.

Comment 11

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/releases/mozilla-beta/rev/678ee917771f