[build]: add SONIC_CONFIG_BUILD_LOG_TIMESTAMP to add timestamp in build log (#4269)

add timestamp in each job build log

example:

   [01:39:21] dh clean  --with autotools-dev
   [01:39:22]    dh_auto_clean
   [01:39:27]      make -j16 distclean

Signed-off-by: Guohan Lu <lguohan@gmail.com>

files/build_templates/sonic_debian_extension.j2

@@ -386,11 +386,13 @@ if [[ $CONFIGURED_ARCH == armhf || $CONFIGURED_ARCH == arm64 ]]; then
 fi
 
 {% if installer_images.strip() -%}
+sudo mkdir $FILESYSTEM_ROOT/target
+sudo mount --bind target $FILESYSTEM_ROOT/target
 sudo chroot $FILESYSTEM_ROOT docker $SONIC_NATIVE_DOCKERD_FOR_DOCKERFS info
 {% for image in installer_images.strip().split(' ') -%}
 {% set imagefilename = image.split('/')|last -%}
 {% set imagename = imagefilename.split('.')|first -%}
-sudo LANG=C chroot $FILESYSTEM_ROOT docker $SONIC_NATIVE_DOCKERD_FOR_DOCKERFS load < {{image}}
+sudo LANG=C chroot $FILESYSTEM_ROOT docker $SONIC_NATIVE_DOCKERD_FOR_DOCKERFS load -i {{image}}
 sudo LANG=C chroot $FILESYSTEM_ROOT docker $SONIC_NATIVE_DOCKERD_FOR_DOCKERFS tag {{imagename}}:latest {{imagename}}:$(sonic_get_version)
 {% if imagename.endswith('-dbg') %}
 {% set imagebasename = imagename.replace('-dbg', '') -%}
@@ -398,6 +400,8 @@ sudo LANG=C chroot $FILESYSTEM_ROOT docker $SONIC_NATIVE_DOCKERD_FOR_DOCKERFS ta
 sudo LANG=C chroot $FILESYSTEM_ROOT docker $SONIC_NATIVE_DOCKERD_FOR_DOCKERFS tag {{imagename}}:latest {{imagebasename}}:latest
 {% endif %}
 {% endfor %}
+sudo umount $FILESYSTEM_ROOT/target
+sudo rm -r $FILESYSTEM_ROOT/target
 if [[ $CONFIGURED_ARCH == armhf || $CONFIGURED_ARCH == arm64 ]]; then
     sudo umount $FILESYSTEM_ROOT/dockerfs
     sudo rm -fr $FILESYSTEM_ROOT/dockerfs

rules/config

@@ -16,6 +16,9 @@ SONIC_CONFIG_BUILD_JOBS = 1
 # Corresponding -j argument will be passed to make/dpkg commands that build separate packages
 SONIC_CONFIG_MAKE_JOBS = $(shell nproc)
 
+# SONIC_CONFIG_BUILD_LOG_TIMESTAMP - add timestamp in build log
+# SONIC_CONFIG_BUILD_LOG_TIMESTAMP = y
+
 # SONIC_USE_DOCKER_BUILDKIT - use docker buildkit for build.
 # If set to y SONiC build system will set environment variable DOCKER_BUILDKIT=1
 # to enable docker buildkit.

rules/functions

@@ -17,6 +17,10 @@ GRAY=\033[0m
 endif
 endif
 
+ifeq ($(SONIC_CONFIG_BUILD_LOG_TIMESTAMP),y)
+PROCESS_LOG_OPTION = -t
+endif
+
 # Print red colored output
 # call:
 #       log_red message
@@ -43,7 +47,8 @@ log_green = echo -e "$(GREEN)$(1)$(GRAY)"
 
 FLUSH_LOG = rm -f $@.log
 
-LOG = &>> $(PROJECT_ROOT)/$@.log || { [ $$? -eq 0 ] || pushd $(PROJECT_ROOT) > /dev/null ; ./update_screen.sh -e $@ ; popd > /dev/null ; false ; }
+LOG_SIMPLE = &>> $(PROJECT_ROOT)/$@.log || { [ $$? -eq 0 ] || pushd $(PROJECT_ROOT) > /dev/null ; ./update_screen.sh -e $@ ; popd > /dev/null ; false ; }
+LOG = |& $(PROJECT_ROOT)/scripts/process_log.sh $(PROCESS_LOG_OPTION) &>> $(PROJECT_ROOT)/$@.log ; test $${PIPESTATUS[-2]} -eq 0 || { [ $$? -eq 0 ] || pushd $(PROJECT_ROOT) > /dev/null ; ./update_screen.sh -e $@ ; popd > /dev/null ; false ; }
 
 ###############################################################################
 ## Header and footer for each target

scripts/process_log.sh

@@ -0,0 +1,20 @@
+#!/bin/bash
+
+add_timestamp=""
+
+while getopts ":t" opt; do
+    case $opt in
+        t)
+            add_timestamp="y"
+            ;;
+    esac
+done
+
+while IFS= read -r line; do
+    if [ $add_timestamp ]; then
+        printf '[%s] ' "$(date +%T)"
+    fi
+    printf '%s\n' "$line"
+done
+
+

slave.mk

@@ -397,13 +397,13 @@ $(addprefix $(DEBS_PATH)/, $(SONIC_DPKG_DEBS)) : $(DEBS_PATH)/% : .platform $$(a
 		# Apply series of patches if exist
 		if [ -f $($*_SRC_PATH).patch/series ]; then pushd $($*_SRC_PATH) && QUILT_PATCHES=../$(notdir $($*_SRC_PATH)).patch quilt push -a; popd; fi
 		# Build project
-		pushd $($*_SRC_PATH) $(LOG)
+		pushd $($*_SRC_PATH) $(LOG_SIMPLE)
-		[ ! -f ./autogen.sh ] || ./autogen.sh $(LOG)
+		if [ -f ./autogen.sh ]; then ./autogen.sh $(LOG); fi
 		$(if $($*_DPKG_TARGET),
 			DEB_BUILD_OPTIONS="${DEB_BUILD_OPTIONS_GENERIC} ${$*_DEB_BUILD_OPTIONS}" dpkg-buildpackage -rfakeroot -b -us -uc -j$(SONIC_CONFIG_MAKE_JOBS) --as-root -T$($*_DPKG_TARGET) $(LOG),
 			DEB_BUILD_OPTIONS="${DEB_BUILD_OPTIONS_GENERIC} ${$*_DEB_BUILD_OPTIONS}" dpkg-buildpackage -rfakeroot -b -us -uc -j$(SONIC_CONFIG_MAKE_JOBS) $(LOG)
 		)
-		popd $(LOG)
+		popd $(LOG_SIMPLE)
 		# Clean up
 		if [ -f $($*_SRC_PATH).patch/series ]; then pushd $($*_SRC_PATH) && quilt pop -a -f; popd; fi
 		# Take built package(s)
@@ -493,10 +493,10 @@ $(addprefix $(PYTHON_DEBS_PATH)/, $(SONIC_PYTHON_STDEB_DEBS)) : $(PYTHON_DEBS_PA
 		# Apply series of patches if exist
 		if [ -f $($*_SRC_PATH).patch/series ]; then pushd $($*_SRC_PATH) && QUILT_PATCHES=../$(notdir $($*_SRC_PATH)).patch quilt push -a; popd; fi
 		# Build project
-		pushd $($*_SRC_PATH) $(LOG)
+		pushd $($*_SRC_PATH) $(LOG_SIMPLE)
 		rm -rf deb_dist/* $(LOG)
 		python setup.py --command-packages=stdeb.command bdist_deb $(LOG)
-		popd $(LOG)
+		popd $(LOG_SIMPLE)
 		# Clean up
 		if [ -f $($*_SRC_PATH).patch/series ]; then pushd $($*_SRC_PATH) && quilt pop -a -f; popd; fi
 		# Take built package(s)
@@ -529,14 +529,14 @@ $(addprefix $(PYTHON_WHEELS_PATH)/, $(SONIC_PYTHON_WHEELS)) : $(PYTHON_WHEELS_PA
 	# Skip building the target if it is already loaded from cache
 	if [ -z '$($*_CACHE_LOADED)' ] ; then
 
-		pushd $($*_SRC_PATH) $(LOG)
+		pushd $($*_SRC_PATH) $(LOG_SIMPLE)
 		# apply series of patches if exist
 		if [ -f ../$(notdir $($*_SRC_PATH)).patch/series ]; then QUILT_PATCHES=../$(notdir $($*_SRC_PATH)).patch quilt push -a; fi
-		[ "$($*_TEST)" = "n" ] || python$($*_PYTHON_VERSION) setup.py test $(LOG)
+		if [ ! "$($*_TEST)" = "n" ]; then python$($*_PYTHON_VERSION) setup.py test $(LOG); fi
 		python$($*_PYTHON_VERSION) setup.py bdist_wheel $(LOG)
 		# clean up
 		if [ -f ../$(notdir $($*_SRC_PATH)).patch/series ]; then quilt pop -a -f; fi
-		popd $(LOG)
+		popd $(LOG_SIMPLE)
 		mv $($*_SRC_PATH)/dist/$* $(PYTHON_WHEELS_PATH) $(LOG)
 		
 		# Save the target deb into DPKG cache