Closed Bug 886498 Opened 7 years ago Closed 6 years ago

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

Categories

(Firefox Build System :: General, defect)

x86_64
Linux
defect
Not set

Tracking

(Not tracked)

RESOLVED WORKSFORME
mozilla25

People

(Reporter: johns, Unassigned)

References

Details

(Whiteboard: [mach])

Attachments

(1 file)

+++ 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.
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
Here is an alternate fix. If this works, I'd prefer it over unbuffered
output.

Please test and report back.
Assignee: nobody → gps
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 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+
https://hg.mozilla.org/mozilla-central/rev/9b3b362ac62b
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla25
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.
Unfortunately I just hit this error with the exact same stack as comment 0 on the current m-c :(
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Assignee: gps → nobody
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
Closed: 7 years ago6 years ago
Resolution: --- → WORKSFORME
Product: Core → Firefox Build System
You need to log in before you can comment on or make changes to this bug.