scon -j 2 does not serialize output from multiple builders

[bdbaddog]

This issue was originally created at: 2005-06-15 23:57:55. This issue was reported by: blep.

blep said at 2005-06-15 23:57:55

Buildling a project containg error using scons -j 2 leads to the strange error message below. The output bug starts at the line [****]. Looking at it closely, we can see that the first builder starts to report the error, and a few character after, the second also print out the error. This result in the output from two builders being interleaved.

This look like a "common" multi-threading bug were access to the output is not serialized.

cl -GR -GX /nologo /Iinclude
/IE:\prg\vc\Lib\qt\4.0.0-rc1\include
/Ibuildscons\msvc71\src\qttestdriver /Isrc\qttestdrive
r /c src\qttestdriver\addtestrunnerdlg.cpp
/Fobuildscons\msvc71\src\qttestdriver\addtestrunnerdlg.obj
addtestrunnerdlg.cpp
main.cpp
e:\prg\vc\Lib\cppunit2\src\qttestdriver\addtestrunnerdlg.h(13)
: error C2143: syntax error : missing ')' before '&'
e:\prg\vc\Lib\cppunit2\src\qttestdriver\addtestrunneer:d\lpgr.gh\(v1c3\)L
i:b \ecrprpourn iCt221\4s3r:c \sqytntteasxt de
rrirvoerr \:a dmditsessitnrg ';' beforeunner d'l&g'.
h(13) : error C2143: syntax error : missing ')' before '&'
e:\prg\vc\Lib\cppunit2\src\qttestdriver\addtestrunnerdlg.h(13)
: error C2143: syntax error : missing ';' before '&'
[****]
e:\prg\ev:c\\pLrigb\\vccp\pLuinbi\tc2p\psurnit2c\s\rqttesct\dqrtitveesrt\dardidvteers\tardudntneesrtdrlugnnerdlg.h(1.3h)
( 1:3 )e r:r oerr rCo2r4 6C02:4 6'0Q:T
T'eQsTtTDersitvDerri:v:eArd:d:TAedsdtTReusntnReurnDniearlDoiga:l:oAgd:d:TAedsdtTR
eusntnReurnPnleurgPInl'u g:I nu's e:s  u'sQeTsT
e'sQtTDTreisvteDrr:i:vAedrd:T:eAsdtdRTuensnteRruDninaelroDgi'a,l
owgh'i,
c hw hisi cbhe iinsg  bdeeifnign edde
fined
        e:\prg\vc\Lib\cpp u n i t 2 \ s
rec:\\qptrtge\svtcd\rLiivbe\rc\papdudntiets2t\rsurncn\eqrtdtlegs.thd(r9i)v
e:r \
seaed ddteecsltarruantnieornd logf. h'(Q9T)T e:s
tsDerei vdeercl:a:ratAddiToens toRfu n'nQeTrTDeisatlDorgi'v
er::AddTestRunnerDialog'

Baptiste.

issues@scons said at 2005-06-15 23:57:55

Converted from SourceForge tracker item 1221715

gregnoel said at 2008-05-28 16:33:03

Issue 2067 has been marked as a duplicate of this issue.

gregnoel said at 2008-05-28 16:35:03

Bug party triage.

gregnoel said at 2008-05-30 12:59:34

Issue 1746 has been marked as a duplicate of this issue.

gregnoel said at 2008-12-26 13:20:25

Adjust triage of issues.

fcl said at 2011-07-07 03:48:00

I am considering having a look at this issue as I see it as well on a multi core WS2008R2. I have had a look at the code and as far as I understand the same stdout/stderr is used for all parallel subprocesses.

I am consider the following alternatives:

1. Use subprocess.PIPE for for stdout/stderr. However the following warning in the Python documentation will be a problem

Like Popen.wait(), this will deadlock when using stdout=PIPE and/or stderr=PIPE and the child process generates enough output to a pipe such that it blocks waiting for the OS pipe buffer to accept more data. https://docs.python.org/library/subprocess.html

2. Redirect output to different files for the different subprocesses. But this will mean that I may not have the output ready until after the subprocesses has exited and closed the file handles.

Any direction for design of a solution would help. Once I have clear idea of the best design I should be able to implement and test it.

Are there other people running Scons under Windows that are having this issue?

thosrtanner said at 2012-05-10 03:19:37

For what it's worth, clearmake does this, and outputs a message saying when it starts processing a build rule, then another message and all the output once it finishes. It takes a little getting used to, but it's a major improvement on getting mixed output.

Thus you get

Rebuilding fred.o
Rebuilding jim.o

======= Finished "fred.o" =========
  <output from compilation of fred.o>
=============================

======= Finished "jim.o" =========
  <output from compilation of jim.o>
=============================

Votes for this issue: 16.

gregnoel said this issue is duplicated by #2067 at 2008-05-28 16:33:03.

gregnoel said this issue is duplicated by #1746 at 2008-05-30 12:59:34.

[rico-chet]

Parallel build is essential, and it should come with as few con's as possible. Unreadable build logs can become an issue, and it's the topic here, as far as I see.

I'd like to point out that Make offers a couple options to deal with log readability, which SCons can use as an orientation: https://www.gnu.org/software/make/manual/html_node/Parallel-Output.html

[mwichmann]

Obviously, this topic has come up a number of times before. SCons doesn't normally capture any of the output from the external commands it passes off work to, but it does have the ability to do so in one very specific circumstance - when performing checks for a Configure context. Theoretically that could be expanded, but imagine there would be a fair bit of plumbing.

[bdbaddog]

PR's welcome...

[mwichmann]

Any PR in this area would want to first ratchet forward the intended platform module refactor to use modern interfaces, and then build off that. subprocess.run is a simple interface to run commands, and it uses Popen.communicate() under the covers and so avoids the deadlock-on-filling-pipes problem alluded to above - the current full quote in the documentation is:

Note (on using Popen.wait)

This will deadlock when using stdout=PIPE or stderr=PIPE and the child process generates enough output to a pipe such that it blocks waiting for the OS pipe buffer to accept more data. Use Popen.communicate() when using pipes to avoid that.

Current POSIX platform does use wait and so potentially has problems collecting output; Windows platform uses the os.spawn interface and os.waitpid