buildsystem: add support for reporting build timing details

Timing detail reporting can be enabled by setting
TRACE_BUILD_TIMING=1

This enables timestamping collecting at various build stages so we
can easily analyze how long eg configure, make/build, install etc
steps take.

Signed-off-by: Matthias Reichl <hias@horus.com>

config/functions

@@ -1803,6 +1803,24 @@ release_update_lock() {
   flock --unlock 97 2>/dev/null
 }
 
+# store current timestamp in TIMESTAMP_xxx variable (xxx set by arg)
+# timestamps are seconds.milliseconds since epoch
+record_timestamp() {
+  if [ -n "${TRACE_BUILD_TIMING}" ]; then
+    typeset -g "TIMESTAMP_$1=$(date +%s.%3N)"
+  fi
+}
+
+# args: text, start timestamp, end timestamp
+show_timestamp_diff() {
+  if [ -n "${TRACE_BUILD_TIMING}" ]; then
+    local start="TIMESTAMP_$2"
+    local end="TIMESTAMP_$3"
+    local timediff=$(echo "${!end}-${!start}" | bc)
+    printf '%20s: %10.3f\n' "$1" "${timediff}"
+  fi
+}
+
 # Use distribution functions if any
 if [ -f "distributions/$DISTRO/config/functions" ]; then
   . distributions/$DISTRO/config/functions

scripts/build

@@ -6,6 +6,8 @@
 
 . config/options "${1}"
 
+record_timestamp BUILD_BEGIN
+
 if [ -z "${1}" ]; then
   die "usage: ${0} package_name[:<host|target|init|bootstrap>] [parent_pkg]"
 fi
@@ -206,6 +208,8 @@ BOOTSTRAP_CONFIGURE_OPTS="${HOST_CONFIGURE_OPTS}"
 BOOTSTRAP_CMAKE_OPTS="${HOST_CMAKE_OPTS}"
 BOOTSTRAP_MESON_OPTS="${HOST_MESON_OPTS}"
 
+record_timestamp BUILD_START
+
 # make autoreconf
 if [ "${PKG_TOOLCHAIN}" = "autotools" ]; then
   ${SCRIPTS}/autoreconf "${PKG_NAME}" "${PARENT_PKG}" $(dirname "${PKG_CONFIGURE_SCRIPT}")
@@ -249,6 +253,8 @@ if [ -n "${PKG_DEPENDS_CONFIG}" -a -n "${PKG_INSTALL}" ]; then
   export PKG_CONFIG_PATH
 fi
 
+record_timestamp BUILD_CONFIGURE
+
 pkg_call_exists_opt pre_configure && pkg_call
 pkg_call_exists_opt pre_configure_${TARGET} && pkg_call
 
@@ -336,6 +342,8 @@ fi
 
 pkg_call_exists_opt post_configure_${TARGET} && pkg_call
 
+record_timestamp BUILD_MAKE
+
 # make
 pkg_call_exists_opt pre_make_${TARGET} && pkg_call
 
@@ -395,6 +403,8 @@ for d in /usr/lib /usr/include /usr/bin /usr/lib/pkgconfig; do
   mkdir -p "${SYSROOT_PREFIX}${d}"
 done
 
+record_timestamp BUILD_MAKEINSTALL
+
 # make install
 pkg_call_exists_opt pre_makeinstall_${TARGET} && pkg_call
 
@@ -440,6 +450,8 @@ fi
 
 pkg_call_exists_opt post_makeinstall_${TARGET} && pkg_call
 
+record_timestamp BUILD_COPY_SYSROOT
+
 # Fixup temporary sysroot references to the shared sysroot
 for i in $(find "${SYSROOT_PREFIX}/usr/lib" -type f -name "*.la" 2>/dev/null); do
   sed -e "s:\(['= ]\)/usr:\\1${PKG_ORIG_SYSROOT_PREFIX}/usr:g" -i "${i}"
@@ -473,6 +485,8 @@ rm -rf "${SYSROOT_PREFIX}"
 
 export SYSROOT_PREFIX="${PKG_ORIG_SYSROOT_PREFIX}"
 
+record_timestamp BUILD_CLEANUP_INSTALL
+
 if [ "${TARGET}" = "target" -o "${TARGET}" = "init" ]; then
   if [ -d ${INSTALL} ]; then
     rm -rf ${INSTALL}/{usr/local/,usr/,}man
@@ -522,3 +536,19 @@ for i in PKG_NAME PKG_DEEPHASH BUILD_WITH_DEBUG; do
 done
 
 pkg_lock_status "UNLOCK" "${PKG_NAME}:${TARGET}" "build" "built"
+
+record_timestamp BUILD_END
+
+if [ -n "${TRACE_BUILD_TIMING}" ]; then
+  (
+    echo "build timing details:"
+    show_timestamp_diff "total" BUILD_BEGIN BUILD_END
+    show_timestamp_diff "unpack" BUILD_BEGIN BUILD_START
+    show_timestamp_diff "pre-build setup" BUILD_START BUILD_CONFIGURE
+    show_timestamp_diff "configure" BUILD_CONFIGURE BUILD_MAKE
+    show_timestamp_diff "make" BUILD_MAKE BUILD_MAKEINSTALL
+    show_timestamp_diff "make install" BUILD_MAKEINSTALL BUILD_COPY_SYSROOT
+    show_timestamp_diff "copy sysroot" BUILD_COPY_SYSROOT BUILD_CLEANUP_INSTALL
+    show_timestamp_diff "cleanup install" BUILD_CLEANUP_INSTALL BUILD_END
+  ) >&${VERBOSE_OUT}
+fi