ci: log time in every fold start and end

Annotating the build log with timings will help us to understand better
where the time is spend during the builds and see areas to optimize.

Switching over to the "native" bash functions in Travis, so switching
all scripts to bash.

Signed-off-by: Stefan Schmidt <s.schmidt@samsung.com>
Reviewed-by: Marcel Hollerbach <mail@marcel-hollerbach.de>
Differential Revision: https://phab.enlightenment.org/D11913

.ci/ci-build-test.sh

@@ -1,13 +1,13 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
 if [ "$1" = "codecov" ] || [ "$1" = "coverity" ] || [ "$1" = "mingw" ] || [ "$1" = "release-ready" ]; then
   exit 0
 fi
 
-travis_fold compile_test compile_test
+travis_fold start "app-compile-test"
+travis_time_start "app-compile-test"
 if [ "$DISTRO" != "" ] ; then
   docker exec --env EIO_MONITOR_POLL=1 $(cat $HOME/cid) .ci/build-example.sh
 elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
@@ -16,4 +16,5 @@ elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   export PATH="$(brew --prefix gettext)/bin:$PATH"
   .ci/build-example.sh
 fi
-travis_endfold compile_test
+travis_time_finish "app-compile-test"
+travis_fold end "app-compile-test"

.ci/ci-ccache-stats.sh

@@ -1,9 +1,13 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
 
+travis_fold start "ccache-stats"
+travis_time_start "ccache-stats"
 if [ "$DISTRO" != "" ] ; then
   docker exec $(cat $HOME/cid)  ccache -s
 elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   ccache -s
 fi
+travis_time_finish "ccache-stats"
+travis_fold end "ccache-stats"

.ci/ci-configure.sh

@@ -1,8 +1,9 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
+travis_fold start "meson"
+travis_time_start "meson"
 if [ "$DISTRO" != "" ] ; then
   # Why do we need to disable the imf loaders here?
   OPTS=" -Decore-imf-loaders-disabler=scim,ibus"
@@ -51,38 +52,30 @@ if [ "$DISTRO" != "" ] ; then
     OPTS="$OPTS $RELEASE_READY_LINUX_COPTS"
   elif [ "$1" = "coverity" ]; then
     OPTS="$OPTS $WAYLAND_LINUX_COPTS"
-    travis_fold cov-download cov-download
+    travis_fold start "cov-download"
     docker exec --env COVERITY_SCAN_TOKEN=$COVERITY_SCAN_TOKEN $(cat $HOME/cid) sh -c '.ci/coverity-tools-install.sh'
-    travis_endfold cov-download
+    travis_fold end "cov-download"
   elif [ "$1" = "mingw" ]; then
     OPTS="$OPTS $MINGW_COPTS"
-    travis_fold cross-native cross-native
+    travis_fold start "cross-native"
     docker exec $(cat $HOME/cid) sh -c '.ci/bootstrap-efl-native-for-cross.sh'
-    travis_endfold cross-native
+    travis_fold end "cross-native"
   fi
 
   if [ "$1" = "asan" ]; then
-    travis_fold meson meson
     docker exec --env EIO_MONITOR_POLL=1 --env CC="ccache gcc" \
       --env CXX="ccache g++" --env CFLAGS="-O0 -g" --env CXXFLAGS="-O0 -g" \
       --env LD="ld.gold" $(cat $HOME/cid) sh -c "mkdir build && meson build $OPTS -Db_sanitize=address"
-    travis_endfold meson
   elif [ "$1" = "mingw" ]; then
-    travis_fold meson meson
     docker exec --env EIO_MONITOR_POLL=1 --env PKG_CONFIG_PATH="/ewpi-64-install/lib/pkgconfig/" \
        $(cat $HOME/cid) sh -c "mkdir build && meson build $OPTS"
-    travis_endfold meson
   elif [ "$1" = "coverity" ]; then
-    travis_fold meson meson
     docker exec --env EIO_MONITOR_POLL=1 --env CFLAGS="-fdirectives-only"  --env CC="gcc" --env CXX="g++"\
     --env CXXFLAGS="-fdirectives-only" $(cat $HOME/cid) sh -c "mkdir build && meson build $OPTS"
-    travis_endfold meson
   else
-    travis_fold meson meson
     docker exec --env EIO_MONITOR_POLL=1 --env CC="ccache gcc" \
       --env CXX="ccache g++" --env CFLAGS="-fdirectives-only" --env CXXFLAGS="-fdirectives-only" \
       --env LD="ld.gold" $(cat $HOME/cid) sh -c "mkdir build && meson build $OPTS"
-    travis_endfold meson
   fi
 elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   # Prepare OSX env for build
@@ -99,25 +92,19 @@ elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   zlib_vers=$(grep ZLIB_VERSION /usr/include/zlib.h|head -n1|awk '{print $3}'|cut -d'"' -f2)
   sed -iE "s/REPLACE_THIS/$zlib_vers/" .ci/zlib.pc
   export PKG_CONFIG_PATH="/usr/local/opt/openssl/lib/pkgconfig:/usr/local/Cellar/libffi/$LIBFFI_VER/lib/pkgconfig:$(pwd)/.ci"
-  travis_fold meson meson
   mkdir build && meson build -Dopengl=full -Decore-imf-loaders-disabler=scim,ibus -Dx11=false -Davahi=false -Deeze=false -Dsystemd=false -Dnls=false -Dcocoa=true -Dgstreamer=false
-  travis_endfold meson
 else # Native Ubuntu Linux Travis builds (non-docker)
   OPTS=" -Decore-imf-loaders-disabler=scim,ibus"
 
   if [ "$TRAVIS_CPU_ARCH" = "ppc64le" ]; then
-    travis_fold meson meson
       OPTS="$OPTS -Dbindings="
-    travis_endfold meson
   elif [ "$TRAVIS_CPU_ARCH" = "s390x" ] ; then
-    travis_fold meson meson
       OPTS="$OPTS -Dbindings= -Delua=false -Dlua-interpreter=lua"
-    travis_endfold meson
   fi
   if [ "$1" = "codecov" ]; then
-    travis_fold meson meson
       OPTS="$OPTS -Db_coverage=true"
-    travis_endfold meson
   fi
   mkdir build && meson build $OPTS
 fi
+travis_time_finish "meson"
+travis_fold end "meson"

.ci/ci-exactness.sh

@@ -1,15 +1,16 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
 if [ "$1" != "exactness" ] ; then
   exit 0
 fi
 
-travis_fold exactness "exactness"
+travis_fold start "exactness"
+travis_time_start "exactness"
 if [ "$DISTRO" != "" ] ; then
   docker exec  --env EIO_MONITOR_POLL=1 $(cat $HOME/cid) sh -c 'git -C /exactness-elm-data pull'
   docker exec  --env EIO_MONITOR_POLL=1 --env LD_LIBRARY_PATH=$LD_LIBRARY_PATH:/usr/local/lib:/usr/local/lib64 --env EINA_LOG_LEVELS_GLOB=eina_*:0,ecore*:0,efreet*:0,eldbus:0,elementary:0 $(cat $HOME/cid) exactness -j 20 -b /exactness-elm-data/default-profile -p /exactness-elm-data/default-profile/ci-fedora32-tests.txt
 fi
-travis_endfold exactness
+travis_time_finish "exactness"
+travis_fold end "exactness"

.ci/ci-make-benchmark.sh

@@ -1,15 +1,17 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
+
 if [ "$1" != "default" ] ; then
   exit 0
 fi
-travis_fold benchmark "ninja benchmark"
+travis_fold start "ninja-benchmark"
+travis_time_start "ninja-benchmark"
 if [ "$DISTRO" != "" ] ; then
   docker exec --env EIO_MONITOR_POLL=1 --env ELM_ENGINE=buffer $(cat $HOME/cid) ninja benchmark -C build
 elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   export PATH="/usr/local/opt/ccache/libexec:$(brew --prefix gettext)/bin:$PATH"
   ninja benchmark -C build
 fi
-travis_endfold benchmark
+travis_time_finish "ninja-benchmark"
+travis_fold end "ninja-benchmark"

.ci/ci-make-check.sh

@@ -1,7 +1,6 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
 if [ "$1" = "release-ready" ] || [ "$1" = "mingw" ] || [ "$1" = "coverity" ] || [ "$1" = "options-enabled" ] || [ "$1" = "options-disabled" ] ; then
   exit 0
@@ -9,6 +8,8 @@ fi
 
 NUM_TRIES=5
 
+travis_fold start "ninja-test"
+travis_time_start "ninja-test"
 if [ "$1" = "codecov" ] ; then
   for tries in $(seq 1 ${NUM_TRIES}); do
     export EFL_TEST_ECORE_CON_IPV6=1
@@ -21,7 +22,6 @@ if [ "$1" = "codecov" ] ; then
   exit 0
 fi
 
-travis_fold check "ninja test"
 if [ "$DISTRO" != "" ] ; then
   for tries in $(seq 1 ${NUM_TRIES}); do
     (docker exec --env EINA_LOG_BACKTRACE="0" --env EIO_MONITOR_POLL=1 $(cat $HOME/cid) meson test -t 120 -C build --wrapper dbus-launch ) && break
@@ -31,6 +31,7 @@ if [ "$DISTRO" != "" ] ; then
   done
 fi
 ret=$?
-travis_endfold check
+travis_time_finish "ninja-test"
+travis_fold end "ninja-test"
 
 exit $ret

.ci/ci-make-distcheck.sh

@@ -1,13 +1,13 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
 if [ "$1" != "release-ready" ] ; then
   exit 0
 fi
 
-travis_fold distcheck "ninja dist"
+travis_fold start "ninja-dist"
+travis_time_start "ninja-dist"
 if [ "$DISTRO" != "" ] ; then
   docker exec --env EIO_MONITOR_POLL=1 --env CC="ccache gcc" \
     --env CXX="ccache g++" \
@@ -18,4 +18,5 @@ elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   export PATH="/usr/local/opt/ccache/libexec:$(brew --prefix gettext)/bin:$PATH"
   ninja -C build dist
 fi
-travis_endfold distcheck
+travis_time_finish "ninja-dist"
+travis_fold end "ninja-dist"

.ci/ci-make-install.sh

@@ -1,13 +1,13 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
 if [ "$1" = "release-ready" ] || [ "$1" = "coverity" ] ; then
   exit 0
 fi
 
-travis_fold install "ninja install"
+travis_fold start "ninja-install"
+travis_time_start "ninja-install"
 if [ "$DISTRO" != "" ] ; then
   docker exec --env EIO_MONITOR_POLL=1 $(cat $HOME/cid) ninja -C build install
 elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
@@ -16,4 +16,5 @@ elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
 else
   sudo ninja -C build install
 fi
-travis_endfold install
+travis_time_finish "ninja-install"
+travis_fold end "ninja-install"

.ci/ci-make.sh

@@ -1,13 +1,13 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
-. .ci/travis.sh
 
 if [ "$1" = "release-ready" ] ; then
   exit 0
 fi
 
-travis_fold ninja ninja
+travis_fold start "ninja"
+travis_time_start "ninja"
 if [ "$DISTRO" != "" ] ; then
   if [ "$1" = "coverity" ] ; then
     docker exec --env EIO_MONITOR_POLL=1 --env PATH="/src/cov-analysis-linux64-2019.03/bin:$PATH" $(cat $HOME/cid) sh -c "cov-build --dir cov-int ninja -C build"
@@ -27,4 +27,5 @@ elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
 else
   ninja -C build
 fi
-travis_endfold ninja
+travis_time_finish "ninja"
+travis_fold end "ninja"

.ci/ci-setup-ccache.sh

@@ -1,7 +1,9 @@
-#!/bin/sh
+#!/bin/bash
 
 set -e
 
+travis_fold start "ccache-setup"
+travis_time_start "ccache-setup"
 if [ "$DISTRO" != "" ] ; then
   docker exec $(cat $HOME/cid)  sh -c ".ci/docker-ccache-setup.sh $1"
   docker exec $(cat $HOME/cid)  ccache -pz
@@ -11,3 +13,5 @@ elif [ "$TRAVIS_OS_NAME" = "osx" ]; then
   echo "base_dir = $pwd" >> ~/.ccache/ccache.conf
   ccache -pz
 fi
+travis_time_finish "ccache-setup"
+travis_fold end "ccache-setup"

.ci/travis.sh

@@ -1,24 +0,0 @@
-#!/bin/sh
-
-# https://github.com/travis-ci/travis-rubies/blob/9f7962a881c55d32da7c76baefc58b89e3941d91/build.sh#L38-L44
-
-travis_fold() {
-  echo -e "travis_fold:start:$1\033[33;1m$2\033[0m"
-}
-travis_endfold() {
-  echo -e "\ntravis_fold:end:$1\r"
-}
-
-travis_time_start() {
-  travis_timer_id=$(printf %08x $(( RANDOM * RANDOM )))
-  travis_start_time=$(travis_nanoseconds)
-  echo -en "travis_time:start:$travis_timer_id\r${ANSI_CLEAR}"
-}
-
-travis_time_finish() {
-  local result=$?
-  travis_end_time=$(travis_nanoseconds)
-  local duration=$(($travis_end_time-$travis_start_time))
-  echo -en "\ntravis_time:end:$travis_timer_id:start=$travis_start_time,finish=$travis_end_time,duration=$duration\r${ANSI_CLEAR}"
-  return $result
-}

.travis.yml

@@ -98,6 +98,10 @@ services:
   - docker
 
 before_install:
+  - export -f travis_nanoseconds
+  - export -f travis_fold
+  - export -f travis_time_start
+  - export -f travis_time_finish
   - |
       if [[ "$TRAVIS_OS_NAME" == "osx" ]]; then
         rm -rf $HOME/Library/Caches/Homebrew