MantisBT - CMake
View Issue Details
IDProjectCategoryView StatusDate SubmittedLast Update
0012991CMakeCMakepublic2012-02-21 14:382015-07-08 08:57
ReporterChristopher Sean Morrison 
Assigned ToBrad King 
PrioritynormalSeveritytextReproducibilityalways
StatusclosedResolutionfixed 
PlatformOSOS Version
Product VersionCMake 2.8.5 
Target VersionCMake 3.3Fixed in VersionCMake 3.3 
Summary0012991: Parallel build output mess
DescriptionUnder Additional Information and attached as an image is an example of the interleaved mess currently being output with a parallel build. The percentages are apparently printed independently from the statements that follow causing interleaved output and wrong ansi-color coding (on the percentages).

The percentage should be buffered with their statement so that they're printed/colored together.

Also of note, the final "make: *** [all] Error 2" has absolutely nothing to do with the 200+ lines being shown... The actual error was several hundred lines before.
Steps To Reproduce
Additional Information[...massive snip...]
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_stxt.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_tcl.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_stack.c.o
Building C object src/liboptical/CMakeFiles/liboptical.dir/sh_treetherm.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_text.c.o
/usr/bin/ld: warning: librt.so.1, needed by /usr/lib64/libdrm.so.2, may conflict with librt.so.19
[ 67%] [ 67%] [ 67%] [ 67%] [ 67%] [ 67%] [ 67%] [ 67%] [ 67%] Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_toyota.c.o
Building C object src/liboptical/CMakeFiles/liboptical.dir/sh_wood.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_treetherm.c.o
Linking C executable ../../bin/tabinterp
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_wood.c.o
Built target nirt
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_toon.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/sh_xxx.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/shade.c.o
Building C object src/liboptical/CMakeFiles/liboptical.dir/sh_xxx.c.o
[ 67%] Building C object src/liboptical/CMakeFiles/liboptical-static.dir/turb.c.o
[ 67%] Built target secpass
[ 67%] Built target vdeck
[ 67%] [ 67%] Building C object src/liboptical/CMakeFiles/liboptical-static.dir/vers.c.o
Building C object src/liboptical/CMakeFiles/liboptical-static.dir/wray.c.o
[ 67%] Building C object src/liboptical/CMakeFiles/liboptical.dir/shade.c.o
[ 67%] [ 67%] Building C object src/liboptical/CMakeFiles/liboptical.dir/turb.c.o
Building C object src/liboptical/CMakeFiles/liboptical.dir/vers.c.o
[ 67%] Linking C static library ../../lib/librtserver.a
Linking C executable ../../bin/firpass
Building C object src/liboptical/CMakeFiles/liboptical.dir/wray.c.o
[ 67%] Built target tabinterp
[ 67%] [ 67%] [ 67%] Built target libmultispectral
Built target rtserver-static
Built target rtserver
[ 67%] Built target firpass
Linking CXX static library ../../lib/libpc.a
Linking C executable ../../bin/burst
Linking C executable ../../bin/lgt
Linking CXX static library ../../lib/libwdb.a
/usr/bin/ld: warning: librt.so.1, needed by /usr/lib64/libdrm.so.2, may conflict with librt.so.19
[ 67%] Built target burst
[ 67%] Built target libpc-static
/usr/bin/ld: warning: librt.so.1, needed by /usr/lib64/libdrm.so.2, may conflict with librt.so.19
[ 67%] Built target lgt
Linking CXX shared library ../../lib/libpc.so
Linking C static library ../../lib/liboptical.a
Linking C shared library ../../lib/liboptical.so
[ 67%] Built target libwdb-static
Linking CXX shared library ../../lib/libwdb.so
Linking C executable ../../../bin/g-iges
[ 67%] Built target liboptical
[ 67%] Built target g-iges
[ 67%] Built target liboptical-static
[ 67%] [ 67%] Built target libwdb
Built target libpc
make: *** [all] Error 2
[sean@gcc1-power7 .cmake]$
TagsNo tags attached.
Relationships
Attached Filespng messy.png (246,496) 2012-02-21 14:38
https://public.kitware.com/Bug/file/4231/messy.png
png
Issue History
Date ModifiedUsernameFieldChange
2012-02-21 14:38Christopher Sean MorrisonNew Issue
2012-02-21 14:38Christopher Sean MorrisonFile Added: messy.png
2012-02-21 14:50Brad KingNote Added: 0028687
2012-02-21 14:51Brad KingNote Added: 0028688
2012-02-21 14:51Brad KingStatusnew => backlog
2013-01-13 17:02Wolfgang BangerthNote Added: 0032100
2013-02-06 17:02YuriNote Added: 0032206
2013-02-06 17:02YuriNote Edited: 0032206bug_revision_view_page.php?bugnote_id=32206#r1027
2015-02-03 00:24Dave YostNote Added: 0037882
2015-02-03 09:56Tyler BrockNote Added: 0037886
2015-02-03 10:03Brad KingNote Added: 0037887
2015-02-03 11:45Dave YostNote Added: 0037888
2015-02-03 11:54Brad KingNote Added: 0037891
2015-02-03 19:12Dave YostNote Added: 0037900
2015-02-03 19:12Dave YostNote Edited: 0037900bug_revision_view_page.php?bugnote_id=37900#r1693
2015-02-04 00:35Christopher Sean MorrisonNote Added: 0037901
2015-02-05 13:23Tyler BrockNote Added: 0037926
2015-02-06 09:22Brad KingAssigned To => Brad King
2015-02-06 09:22Brad KingStatusbacklog => assigned
2015-02-06 09:22Brad KingTarget Version => CMake 3.3
2015-02-06 09:23Brad KingNote Added: 0037930
2015-02-06 09:41Christopher Sean MorrisonNote Added: 0037931
2015-02-06 16:24Christopher Sean MorrisonNote Added: 0037942
2015-02-06 16:45Brad KingNote Added: 0037943
2015-02-10 09:51Brad KingStatusassigned => resolved
2015-02-10 09:51Brad KingResolutionopen => fixed
2015-02-10 09:51Brad KingFixed in Version => CMake 3.3
2015-02-10 09:54Tyler BrockNote Added: 0037952
2015-02-10 09:54Tyler BrockNote Edited: 0037886bug_revision_view_page.php?bugnote_id=37886#r1701
2015-07-08 08:57Robert MaynardNote Added: 0039047
2015-07-08 08:57Robert MaynardStatusresolved => closed

Notes
(0028687)
Brad King   
2012-02-21 14:50   
cmMakefileTargetGenerator::WriteObjectBuildFile calls AppendProgress and AppendEcho consecutively to report progress and the object file build output. There are of course other cases, but this is an example. They need to be combined. However, currently they generate separate calls to CMake:

  $(CMAKE_COMMAND) -E cmake_progress_report ...
  $(CMAKE_COMMAND) -E cmake_echo_color ...

A new internal "cmake -E" command that can do both of these needs to be implemented.

Finally, Source/kwsys/Terminal.c needs to be refactored so that the output written by SetVT100Color and cfprintf can be combined into a single atomic write.
(0028688)
Brad King   
2012-02-21 14:51   
This has been a long-standing bug but no one has taken the time to fix it since it is mostly aesthetics. Moving to backlog to wait for a volunteer.
(0032100)
Wolfgang Bangerth   
2013-01-13 17:02   
There is an easier way to achieve this goal (which I, too, think is ugly if you have a lot of processors -- like the 48 on my development machine):

Instead of having separate commands in the Makefile of the kind
        $(CMAKE_COMMAND) -E cmake_progress_report ...
        $(CMAKE_COMMAND) -E cmake_echo_color ...
you can write it as
        echo "`$(CMAKE_COMMAND) -E cmake_progress_report ...`\n`$(CMAKE_COMMAND) -E cmake_echo_color ...`"

This way, 'echo' sees only a single string to output and will print it atomically. In other
words, all that would need to be changed is the generator of the Unix Makefiles -- no
changes to the -E commands of cmake are necessary.
(0032206)
Yuri   
2013-02-06 17:02   
I also keep seeing same during FreeBSD port builds.
(0037882)
Dave Yost   
2015-02-03 00:24   
Has anybode tried the simple suggested fix?
(0037886)
Tyler Brock   
2015-02-03 09:56   
(edited on: 2015-02-10 09:54)
Let's get this fixed guys. It is super annoying to debug cmake builds because you have to choose between compiling with 1 core or garbled output.
(0037887)
Brad King   
2015-02-03 10:03   
Re 0012991:0037886: I outlined what needs to be done in 0012991:0028687. The approach in 0012991:0032100 is neat but is not very clean and may not work on all platforms.
(0037888)
Dave Yost   
2015-02-03 11:45   
I think it would make sense simply not to display the percentage when parallel make is happening. Is that doable easily?
(0037891)
Brad King   
2015-02-03 11:54   
Nothing short of the full refactoring suggested in 0012991:0028687 is an acceptable solution for upstream.
(0037900)
Dave Yost   
2015-02-03 19:12   
Why must we wait for a full refactoring? Why can't you just turn off the percentages when building in parallel? The percentages are meaningless when building in parallel anyway.

When I spring this new cmake-based build system on our developers, I would rather not have them get a bad first impression from confused output.
(0037901)
Christopher Sean Morrison   
2015-02-04 00:35   
Even as a jumbled mess in parallel build output, the percentages are still meaningful and useful. Particularly with large complicated build systems with thousands of lines output, the percentages provide a rough ETA. I would not be fond of having them turned off.

Wolfgang's solution seems like a stellar workaround even if it only applies to Makefile generation and even if it's only a temporary solution. It's a fix that'd take mere minutes. I somehow doubt anyone can point to a significant cmake platform environment lacking echo or that wouldn't be solved with something similar to AC_PROG_ECHO or even something like: $(CMAKE_COMMAND) -E echo "`$(CMAKE_COMMAND) -E cmake_progress_report ...`\n`$(CMAKE_COMMAND) -E cmake_echo_color ...`"
(0037926)
Tyler Brock   
2015-02-05 13:23   
Ok, so what are the next steps? Is this something that is scheduled for the next release?
(0037930)
Brad King   
2015-02-06 09:23   
I've implemented the refactoring suggested in 0012991:0028687:

 Makefile: Fix output during parallel builds
 http://cmake.org/gitweb?p=cmake.git;a=commitdiff;h=8521fdf5 [^]

It turns out the changes to Source/kwsys/Terminal.c are not needed because stdout has line buffering anyway.
(0037931)
Christopher Sean Morrison   
2015-02-06 09:41   
Woo hoo! Thank you Brad!
(0037942)
Christopher Sean Morrison   
2015-02-06 16:24   
One of our guys tested and confirms that the line fix works as far as not having multiple percents on one line, but the color occasionally bleeds into the next line. It's livable, but thought you might like to know while it's in context. Progress! Thanks again!
(0037943)
Brad King   
2015-02-06 16:45   
Re 0012991:0037942: Thanks. This should fix that:

 Makefile: Print all color escape sequences before newline
 http://cmake.org/gitweb?p=cmake.git;a=commitdiff;h=c6ada827 [^]
(0037952)
Tyler Brock   
2015-02-10 09:54   
Amazing! Thank you guys.
(0039047)
Robert Maynard   
2015-07-08 08:57   
Closing resolved issues that have not been updated in more than 4 months.