Pipe build output during build process

ReinhardKeil commented 3 months ago

The Problem To Be Solved

Larger applications takes several seconds to build. During that time, cbuild does not show any messages which makes the user believe that the system crashed.

Other build systems pipe output during the build process. The user sees that files are compiled.

soumeh01 commented 2 months ago

During my investigation into this issue, I discovered that the problem does not lie with cbuild. To isolate the issue, I deconstructed the command cbuild ./Hello.csolution.yml into the series of commands

csolution.exe convert ./Hello.csolution.yml
cbuild2cmake.exe ./Hello.cbuild-idx.yml
cmake.exe -G Ninja -S ./tmp -B ./tmp -Wdev
cmake.exe --build ./tmp -j 8 --target Hello.Debug+AVH

and executed each underlying command individually. The same behavior (long waits/delayed logs) was observed. The reason being Ninja buffers console logs. This behavior is documented in Ninja's documentation.

Command output is always buffered. This means commands running in parallel don’t interleave their output, and when a command fails we can print its failure output next to the full command line that produced the failure.

When building the same example with other generator tools, we receive real-time console logs.

jkrech commented 2 months ago

Reproducing the above using make.exe as alternative builder. Make sure the binary is in your path.

  cbuild hello.csolution.yml -S -g "Unix Makefiles" -r

The output gets streamed and is not buffered

Unless we decide to move away from ninja, there does not seem to be away to solve this problem.

ReinhardKeil commented 2 months ago

I believe the solution is to set USES_TERMINAL_BUILD ON in the CMakeLists.txt.

 # Create external project, set configure and build steps
  ExternalProject_Add(${CONTEXT}
    PREFIX                ${DIR}
    SOURCE_DIR            ${DIR}
    BINARY_DIR            ${N}
    INSTALL_COMMAND       ""
    TEST_COMMAND          ""
    CONFIGURE_COMMAND     ${CMAKE_COMMAND} -G Ninja -S <SOURCE_DIR> -B <BINARY_DIR> ${ARGS} 
    BUILD_COMMAND         ${CMAKE_COMMAND} -E echo "Building CMake target '${CONTEXT}'"
    COMMAND               ${CMAKE_COMMAND} --build <BINARY_DIR>
    BUILD_ALWAYS          TRUE
    BUILD_BYPRODUCTS      ${OUTPUTS_${N}}
    LOG_CONFIGURE         ON
    LOG_OUTPUT_ON_FAILURE ON
    USES_TERMINAL_BUILD   ON              ### THIS IS THE CHANGE ###
  )

It works for me when using the manual CMake invocation described here: https://github.com/Open-CMSIS-Pack/cmsis-toolbox/blob/main/docs/build-operation.md#cmake-invocation

It sets in build.ninja the value pool = console for the build process.

Not sure if we should:

Add an cbuild option to enable/disable terminal progress output. I saw no significant difference in build times. However there is a difference in output behavior: VS Code shows just the current object file that is build; errors/warnings stay (quite nice). ToDo: Check behavior in CI test system such as GitHub actions.
Need other USES_TERMINAL controls in CMakeLists.txt

A good test example is: https://github.com/Arm-Examples/mlek-cmsis-pack-examples

EaselinkBachmann commented 2 months ago

I believe the solution is to set USES_TERMINAL_BUILD ON in the CMakeLists.txt.
 # Create external project, set configure and build steps
  ExternalProject_Add(${CONTEXT}
    PREFIX                ${DIR}
    SOURCE_DIR            ${DIR}
    BINARY_DIR            ${N}
    INSTALL_COMMAND       ""
    TEST_COMMAND          ""
    CONFIGURE_COMMAND     ${CMAKE_COMMAND} -G Ninja -S <SOURCE_DIR> -B <BINARY_DIR> ${ARGS} 
    BUILD_COMMAND         ${CMAKE_COMMAND} -E echo "Building CMake target '${CONTEXT}'"
    COMMAND               ${CMAKE_COMMAND} --build <BINARY_DIR>
    BUILD_ALWAYS          TRUE
    BUILD_BYPRODUCTS      ${OUTPUTS_${N}}
    LOG_CONFIGURE         ON
    LOG_OUTPUT_ON_FAILURE ON
    USES_TERMINAL_BUILD   ON              ### THIS IS THE CHANGE ###
  )
It works for me when using the manual CMake invocation described here: https://github.com/Open-CMSIS-Pack/cmsis-toolbox/blob/main/docs/build-operation.md#cmake-invocation

See also https://www.scivision.dev/cmake-external-project-ninja-verbose/

It sets in build.ninja the value pool = console for the build process.

Not sure if we should:
* Add an cbuild option to enable/disable terminal progress output. I saw no significant difference in build times. However there is a difference in output behavior: VS Code shows just the current object file that is build; errors/warnings stay (quite nice).  ToDo: Check behavior in CI test system such as GitHub actions.

* Need other USES_TERMINAL controls in CMakeLists.txt
A good test example is: https://github.com/Arm-Examples/mlek-cmsis-pack-examples

I can confirm that adding USES_TERMINAL_BUILD works great to show progress on compiling the subprojects.

Open-CMSIS-Pack / devtools

Pipe build output during build process #1676