RFC: reduce compiler output in console

[refack]

I want improve the the CI's console output.
1st step was to patch GYP to output the interesting stuff near the begenning of the line, so -
old (output and input files at the end):

ccache g++-4.9 '-DV8_GYP_BUILD' '-DV8_TYPED_ARRAY_MAX_SIZE_IN_HEAP=0' '-DV8_TARGET_ARCH_S390' '-DV8_TARGET_ARCH_S390X' '-DV8_EMBEDDER_STRING="-node.2"' '-DENABLE_DISASSEMBLER' '-DV8_PROMISE_INTERNAL_FIELD_COUNT' '-Dv8_promise_internal_field_count' '-DV8_INTL_SUPPORT' '-DV8_CONCURRENT_MARKING' '-DDISABLE_UNTRUSTED_CODE_MITIGATIONS' -I../deps/v8  -pthread -Wall -Wextra -Wno-unused-parameter -m64 -march=z196 -march=z196 -fno-strict-aliasing -m64 -fdata-sections -ffunction-sections -O3 -O3 -fno-omit-frame-pointer -fno-rtti -fno-exceptions -std=gnu++1y -MMD -MF /data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/.deps//data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o.d.raw   -c -o /data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o ../deps/v8/src/base/bits.cc

new (output first with target in the path, next input file):

ccache g++-4.9 -o /data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o ../deps/v8/src/base/bits.cc '-DV8_GYP_BUILD' '-DV8_TYPED_ARRAY_MAX_SIZE_IN_HEAP=0' '-DV8_TARGET_ARCH_S390' '-DV8_TARGET_ARCH_S390X' '-DV8_EMBEDDER_STRING="-node.2"' '-DENABLE_DISASSEMBLER' '-DV8_PROMISE_INTERNAL_FIELD_COUNT' '-Dv8_promise_internal_field_count' '-DV8_INTL_SUPPORT' '-DV8_CONCURRENT_MARKING' '-DDISABLE_UNTRUSTED_CODE_MITIGATIONS' -I../deps/v8  -pthread -Wall -Wextra -Wno-unused-parameter -m64 -march=z196 -march=z196 -fno-strict-aliasing -m64 -fdata-sections -ffunction-sections -O3 -O3 -fno-omit-frame-pointer -fno-rtti -fno-exceptions -std=gnu++1y -MMD -MF /data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/.deps//data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o.d.raw   -c
                                                                                              ^^^^^^^^^^^^^^^^^^^^^^^^^^^                  ^^^^^^                     ^^^^^^^

Next I want tee the output to a file (publish as atrifact), and to mangle the stdout:

 Makefile | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/Makefile b/Makefile
index b0628d975a..bbcfb5d05a 100644
--- a/Makefile
+++ b/Makefile
@@ -472,7 +472,7 @@ test-ci: | clear-stalled build-addons build-addons-napi doc-only
 # Related CI jobs: most CI tests, excluding node-test-commit-arm-fanned
 build-ci:
 	$(PYTHON) ./configure --verbose $(CONFIG_FLAGS)
-	$(MAKE) ci-all
+	$(MAKE) ci-all 2>&1 | tee make.log | cut -c -250
 
 .PHONY: run-ci
 # Run by CI tests, exceptions:

Maybe even use | sed -e "s/'.*$//" -e "s|$PWD||"
to get:

ccache g++-4.9 -o out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o ../deps/v8/src/base/bits.cc

Seeking feedback
/CC @nodejs/build-files

[richardlau]

I'm hesitant by default to make the build logs in Jenkins less verbose as often it's the only thing we have to attempt to work out why a build has failed (especially for those of us without access to the machines).

[refack]

I'm hesitant by default to make the build logs in Jenkins less verbose

I totally agree, the key is to tee the full output into a file and publish as artifact.

[richardlau]

The proposed Makefile changes potentially affect downstream packagers.

cc @nodejs/delivery-channels

[refack]

Trying to minimize outside effect, I'm proposing changing only the build-ci target.
If anyone who builds node downstream has any feedback, it will be most welcome.

[joyeecheung]

Can we use V= to minimize the command used to produce each object, or is that too minimal?

[refack]

Can we use V= to minimize the command used to produce each object, or is that too minimal?

IMHO V=0 is too minimal, and doesn't give an alternative (verbose) channel like tee does...

[mhdawson]

Were do you have in mind to push the artifact?

[refack]

Were do you have in mind to push the artifact?

Jenkins gives us artifact storage, for example see the first few lines in: https://ci.nodejs.org/job/node-compile-windows/21337/label=win-vs2017/

[mhdawson]

Ok if its as simple a clicking a link in the job page to get the full output then thats probably good. I assume the artifacts are retained as long as the job is?

[richardlau]

Having thought about this a bit more I'm yet to be convinced. The usual reason for looking at the build console log is that the job has failed in some way or is taking a long time and you want to see how far it has got.

For the first case you want all the information in one place (the proposed change would hive off part of the build output to the log file which would have to be downloaded separately and would not contain any of the log outside of the redirected output).

For the latter case the console log would stop after 250 lines and the redirected log would not be available until the build completes (maybe it's available via the workspace in the Jenkins UI but that's non-obvious).

[refack]

@richardlau thank you for thinking about this more!

The usual reason for looking at the build console log is that the job has failed in some way or is taking a long time and you want to see how far it has got.

as I see it going to the console is just our fallback since ATM it's the only output we have. I believe that if we had better output (like JUnit instead of the inconvenient TAP ) users will adopt the better UX...

For the first case you want all the information in one place (the proposed change would hive off part of the build output to the log file which would have to be downloaded separately and would not contain any of the log outside of the redirected output).

I've thought about this also, and had this idea; if compilation fails, just cat make.log into the console... (Similar to what we already do in the linter job).

For the latter case the console log would stop after 250 lines and the redirected log would not be available until the build completes (maybe it's available via the workspace in the Jenkins UI but that's non-obvious).

Hmmm... that's an interesting case, but is the full compiler line that more informative than a "gist" line? i.e.

ccache g++-4.9 -o /data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o ../deps/v8/src/base/bits.cc '-DV8_GYP_BUILD' '-DV8_TYPED_ARRAY_MAX_SIZE_IN_HEAP=0' '-DV8_TARGET_ARCH_S390' '-DV8_TARGET_ARCH_S390X' '-DV8_EMBEDDER_STRING="-node.2"' '-DENABLE_DISASSEMBLER' '-DV8_PROMISE_INTERNAL_FIELD_COUNT' '-Dv8_promise_internal_field_count' '-DV8_INTL_SUPPORT' '-DV8_CONCURRENT_MARKING' '-DDISABLE_UNTRUSTED_CODE_MITIGATIONS' -I../deps/v8  -pthread -Wall -Wextra -Wno-unused-parameter -m64 -march=z196 -march=z196 -fno-strict-aliasing -m64 -fdata-sections -ffunction-sections -O3 -O3 -fno-omit-frame-pointer -fno-rtti -fno-exceptions -std=gnu++1y -MMD -MF /data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/.deps//data/iojs/build/workspace/node-test-commit-linuxone/nodes/rhel72-s390x/out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o.d.raw   -c

instead of:

ccache g++-4.9 -o out/Release/obj.host/v8_libbase/deps/v8/src/base/bits.o ../deps/v8/src/base/bits.cc

---

I'll create a POC, then we could evaluate and iterate on actual jobs. See if this hold water.

[richardlau]

as I see it going to the console is just our fallback since ATM it's the only output we have. I believe that if we had better output (like JUnit instead of the inconvenient TAP ) users will adopt the better UX...

If the concern is the amount of output then maybe an argument could be made to separate the build step (where the ccache lines come from) from the test step (where the TAP is output) like the (Windows/arm) fanned jobs do.

[refack]

If the concern is the amount of output then maybe an argument could be made to separate the build step (where the ccache lines come from) from the test step (where the TAP is output) like the (Windows/arm) fanned jobs do.

That an interesting idea as well... It has several benefits... I'm not sure how simple it is to implement.

One concern I was hoping to eliminate was actually live console watching. ATM it's a mess of duplicated info. I find it hard to figure out what is being compiled, and hence deduce what point in the process the build is at. I got the inspiration from GYP's ninja output that puts all the reused parameters into an .rsp file so that you get a succinct output to console

[github-actions]

This issue is stale because it has been open many days with no activity. It will be closed soon unless the stale label is remove or a comment is made.