476773 - Mochitest stdout is heavily buffered

Status: RESOLVED WORKSFORME

(Testing :: Mochitest, defect)

Description

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Attachment: fix?

automation.py spawns the Mozilla process with lots of buffering on stdout. This means when you're debugging mochitests it's hard to use dump() and friends in conjunction with a debugger or anything interactive because their output is buffered and won't appear when you need it.

The attached patch simply lets the child process write directly to the Python process's stdout. The only problem I can see with this patch is that the "Application pid" line might be mixed up with the child process's output. I'm not sure if that's a real issue.

Comment 1

[Jeff Walden [:Waldo]]

Comment on attachment 360428 [details] [diff] [review]
fix?

I'm all but certain this breaks leaktest ($objdir/build/leaktest.py -l logfile).  :-(

Comment 2

[Robert O'Callahan (:roc) (email my personal email if necessary)]

OK, got any better ideas?

Comment 3

[Jeff Walden [:Waldo]]

Maybe add yet another optional argument to runApp to allow passing in a particular file object to which output is written, defaulting to stdout?  Then leaktest.py.in overrides with the output file, and when leak tests finish it dumps the file to console to make sure it's in tinderbox logs.

Comment 4

[Robert O'Callahan (:roc) (email my personal email if necessary)]

That sounds inconvenient. 

One thing that's weird is that I tried adding fflush(stdout) to nsGlobalWindow::Dump. I thought this should fix the problem, but it didn't seem to do anything.

There's also supposed to be a way to spawn a subprocess so that it thinks it's writing to a tty, although I don't right now remember how that's done. Apparently there's a python module Pexpect that does this.

Comment 5

[Robert O'Callahan (:roc) (email my personal email if necessary)]

This is apparently a relatively recent regression. We should find out what caused it and back it out.

Comment 6

[Jeff Walden [:Waldo]]

It's bug 464191, but I don't think it's a good idea to return to the previous system where we forked process implementation based on the OS, nor to return to a system where runtests.py leaves zombie ssltunnel processes around.

http://svn.python.org/view/python/trunk/Lib/subprocess.py?rev=67543&view=auto

The stdin/stdout properties of the stdin/stdout of the child process are file handles encapsulating numeric file descriptors on non-Windows platforms; we can pass them to fcntl.fcntl() and go to town that way, I think.  Totally evil, of course, but it should work.  I don't know what to do about Windows yet.

Comment 7

[Robert O'Callahan (:roc) (email my personal email if necessary)]

(In reply to comment #6)
> It's bug 464191, but I don't think it's a good idea to return to the previous
> system where we forked process implementation based on the OS,

A fork in the implementation sounds much better than this nasty regression in debuggability.

Comment 8

[(not currently active) Ted Mielczarek]

You can reopen stdout to unbuffer it, not sure if that works for the child stdout, since it's actually a pipe:
http://www.gossamer-threads.com/lists/python/python/658167

(Are we sure it's the child's stdout being buffered, and not runtests.py?)

Comment 9

[Serge Gautherie (:sgautherie)]

I'm not sure whether it's the same issue/bug, but I was just wondering whether we should use '-u' for Mochitests and Reftests, just like we do for xpcshell tests.
(To get: more ordered logs? more complete logs in case of crash? ...)

See
http://mxr.mozilla.org/build/source/buildbotcustom/steps/unittest.py#505
and
http://hg.mozilla.org/mozilla-central/annotate/6d01d25a93bf/testing/testsuite-targets.mk#l56

Comment 10

[Andrew Halberstadt [:ahal]]

I'm fairly certain this is no longer an issue (and if it is, a new bug should be filed with modern context)