If you think a bug might affect users in the 57 release, please set the correct tracking and status flags for Release Management.

Mach sometimes hits an IOError in footer.draw() when building rapidly

RESOLVED WORKSFORME

Status

()

Core
Build Config
RESOLVED WORKSFORME
4 years ago
4 years ago

People

(Reporter: johns, Unassigned)

Tracking

unspecified
mozilla25
x86_64
Linux
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [mach])

Attachments

(1 attachment)

(Reporter)

Description

4 years ago
+++ This bug was initially created as a clone of Bug #884028 +++

I'm still seeing the issue originally reported in bug 884028, but now with a different stack!

>  5:05.36 nsCP1250ToUnicode.cpp
>  5:05.36 nsCP1251ToUnicode.cpp
>  5:05.36 nsCP1253ToUnicode.cpp
>  5:05.36 nsCP1254ToUnicode.cpp
> Exception in thread Thread-1:
> Traceback (most recent call last):
>   File "/usr/lib/python2.7/threading.py", line 808, in __bootstrap_inner
>     self.run()
>   File "/usr/lib/python2.7/threading.py", line 761, in run
>     self.__target(*self.__args, **self.__kwargs)
>   File "/home/johns/moz/moz-git-build/testing/mozbase/mozprocess/mozprocess/processhandler.py", line 698, in _processOutput
>     self.processOutputLine(line.rstrip())
>   File "/home/johns/moz/moz-git-build/testing/mozbase/mozprocess/mozprocess/processhandler.py", line 663, in processOutputLine
>     handler(line)
>   File "/home/johns/moz/moz-git-build/python/mach/mach/mixin/process.py", line 86, in handleLine
>     line_handler(line)
>   File "/home/johns/moz/moz-git-build/python/mozbuild/mozbuild/mach_commands.py", line 249, in on_line
>     self.log(logging.INFO, 'build_output', {'line': line}, '{line}')
>   File "/home/johns/moz/moz-git-build/python/mach/mach/mixin/logging.py", line 54, in log
>     extra={'action': action, 'params': params})
>   File "/usr/lib/python2.7/logging/__init__.py", line 1213, in log
>     self._log(level, msg, args, **kwargs)
>   File "/usr/lib/python2.7/logging/__init__.py", line 1268, in _log
>     self.handle(record)
>   File "/usr/lib/python2.7/logging/__init__.py", line 1278, in handle
>     self.callHandlers(record)
>   File "/usr/lib/python2.7/logging/__init__.py", line 1318, in callHandlers
>     hdlr.handle(record)
>   File "/usr/lib/python2.7/logging/__init__.py", line 749, in handle
>     self.emit(record)
>   File "/home/johns/moz/moz-git-build/python/mozbuild/mozbuild/mach_commands.py", line 79, in emit
>     self.footer.draw()
>   File "/home/johns/moz/moz-git-build/python/mozbuild/mozbuild/mach_commands.py", line 190, in draw
>     self._fh.flush()
> IOError: [Errno 5] Input/output error

As with before this is with large -j values (64) on a distcc network, so output is scrolling very rapidly. Python is v2.7.5.

Comment 1

4 years ago
Can someone experiencing this try mucking around with unbuffered stdout and reporting the experience?

http://stackoverflow.com/questions/107705/python-output-buffering

e.g. PYTHONUNBUFFERED=1 python mach build

Comment 2

4 years ago
Created attachment 768111 [details] [diff] [review]
Attempt to fix IOError code 5 during mach build

Here is an alternate fix. If this works, I'd prefer it over unbuffered
output.

Please test and report back.

Updated

4 years ago
Assignee: nobody → gps
(Reporter)

Comment 3

4 years ago
I managed to do a full build with this patch without hitting any IOErrors, though the failure rate wasn't 100% earlier. I'll keep this applied and let you know if the error returns.
So far as I can tell (And the bug was killing well over half of my build attempted unless I used the environment var to disable the footer) this has fixed the problem.
Yay!

Comment 5

4 years ago
Comment on attachment 768111 [details] [diff] [review]
Attempt to fix IOError code 5 during mach build

Review of attachment 768111 [details] [diff] [review]:
-----------------------------------------------------------------

2/2 for curing the illness means review time!
Attachment #768111 - Flags: review?(ted)
Comment on attachment 768111 [details] [diff] [review]
Attempt to fix IOError code 5 during mach build

Review of attachment 768111 [details] [diff] [review]:
-----------------------------------------------------------------

::: python/mozbuild/mozbuild/mach_commands.py
@@ +253,5 @@
> +            self.handler.acquire()
> +            try:
> +                self.refresh()
> +            finally:
> +                self.handler.release()

This feels like it wants to be a context manager, but I guess logging.Handler doesn't implement that, so this is in-line with the standard library. Weird.
Attachment #768111 - Flags: review?(ted) → review+

Comment 7

4 years ago
https://hg.mozilla.org/mozilla-central/rev/9b3b362ac62b
Status: NEW → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla25

Updated

4 years ago
Blocks: 889963
Hate to be a party pooper, but as of today this patch has started causing this to occur:

Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python2.7/threading.py", line 808, in __bootstrap_inner
    self.run()
  File "/usr/lib/python2.7/threading.py", line 761, in run
    self.__target(*self.__args, **self.__kwargs)
  File "/home/chris/Fennec/Fennec/testing/mozbase/mozprocess/mozprocess/processhandler.py", line 698, in _processOutput
    self.processOutputLine(line.rstrip())
  File "/home/chris/Fennec/Fennec/testing/mozbase/mozprocess/mozprocess/processhandler.py", line 663, in processOutputLine
    handler(line)
  File "/home/chris/Fennec/Fennec/python/mach/mach/mixin/process.py", line 86, in handleLine
    line_handler(line)
  File "/home/chris/Fennec/Fennec/python/mozbuild/mozbuild/mach_commands.py", line 253, in on_line
    self.handler.acquire()
AttributeError: 'BuildOutputManager' object has no attribute 'handler'


Every time I build with Mach.... Looks like the patch worked yesterday but today has decided to become strange...
Ah-Ha! The above problem exists exclusively when you run Mach with MACH_NO_TERMINAL_FOOTER set after applying the patch. Running Mach without this environment variable after the patch exhibits neither this nor the original problem.
(In reply to Chris Kitching [:ckitching] from comment #9)
> Ah-Ha! The above problem exists exclusively when you run Mach with
> MACH_NO_TERMINAL_FOOTER set after applying the patch. Running Mach without
> this environment variable after the patch exhibits neither this nor the
> original problem.

Was fixed in bug 889963.
(Reporter)

Comment 11

4 years ago
Unfortunately I just hit this error with the exact same stack as comment 0 on the current m-c :(
Status: RESOLVED → REOPENED
Resolution: FIXED → ---

Updated

4 years ago
Assignee: gps → nobody
(Reporter)

Comment 12

4 years ago
I haven't hit this at all in a few months of -j104 builds, I'll re-open if I can repro reliably
Status: REOPENED → RESOLVED
Last Resolved: 4 years ago4 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.