# HG changeset patch # User asemenyuk # Date 1490710126 -10800 # Tue Mar 28 17:08:46 2017 +0300 # Node ID f92919449f9ee989d3c7cff346cf6c0311a35118 # Parent a9fce4976c14b8382af88828b70561e99c680093 [mq]: times diff --git a/common/autoconf/basics.m4 b/common/autoconf/basics.m4 --- a/common/autoconf/basics.m4 +++ b/common/autoconf/basics.m4 @@ -1098,6 +1098,7 @@ BASIC_PATH_PROGS(HG, hg) BASIC_PATH_PROGS(STAT, stat) BASIC_PATH_PROGS(TIME, time) + BASIC_PATH_PROGS(FLOCK, flock) # Dtrace is usually found in /usr/sbin on Solaris, but that directory may not # be in the user path. BASIC_PATH_PROGS(DTRACE, dtrace, $PATH:/usr/sbin) diff --git a/common/autoconf/generated-configure.sh b/common/autoconf/generated-configure.sh --- a/common/autoconf/generated-configure.sh +++ b/common/autoconf/generated-configure.sh @@ -932,6 +932,7 @@ IS_GNU_TIME PATCH DTRACE +FLOCK TIME STAT HG @@ -1292,6 +1293,7 @@ HG STAT TIME +FLOCK DTRACE PATCH DSYMUTIL @@ -2256,6 +2258,7 @@ HG Override default value for HG STAT Override default value for STAT TIME Override default value for TIME + FLOCK Override default value for FLOCK DTRACE Override default value for DTRACE PATCH Override default value for PATCH DSYMUTIL Override default value for DSYMUTIL @@ -5173,7 +5176,7 @@ #CUSTOM_AUTOCONF_INCLUDE # Do not change or remove the following line, it is needed for consistency checks: -DATE_WHEN_GENERATED=1489410066 +DATE_WHEN_GENERATED=1490709727 ############################################################################### # @@ -23056,6 +23059,203 @@ fi + + + # Publish this variable in the help. + + + if [ -z "${FLOCK+x}" ]; then + # The variable is not set by user, try to locate tool using the code snippet + for ac_prog in flock +do + # Extract the first word of "$ac_prog", so it can be a program name with args. +set dummy $ac_prog; ac_word=$2 +{ $as_echo "$as_me:${as_lineno-$LINENO}: checking for $ac_word" >&5 +$as_echo_n "checking for $ac_word... " >&6; } +if ${ac_cv_path_FLOCK+:} false; then : + $as_echo_n "(cached) " >&6 +else + case $FLOCK in + [\\/]* | ?:[\\/]*) + ac_cv_path_FLOCK="$FLOCK" # Let the user override the test with a path. + ;; + *) + as_save_IFS=$IFS; IFS=$PATH_SEPARATOR +for as_dir in $PATH +do + IFS=$as_save_IFS + test -z "$as_dir" && as_dir=. + for ac_exec_ext in '' $ac_executable_extensions; do + if as_fn_executable_p "$as_dir/$ac_word$ac_exec_ext"; then + ac_cv_path_FLOCK="$as_dir/$ac_word$ac_exec_ext" + $as_echo "$as_me:${as_lineno-$LINENO}: found $as_dir/$ac_word$ac_exec_ext" >&5 + break 2 + fi +done + done +IFS=$as_save_IFS + + ;; +esac +fi +FLOCK=$ac_cv_path_FLOCK +if test -n "$FLOCK"; then + { $as_echo "$as_me:${as_lineno-$LINENO}: result: $FLOCK" >&5 +$as_echo "$FLOCK" >&6; } +else + { $as_echo "$as_me:${as_lineno-$LINENO}: result: no" >&5 +$as_echo "no" >&6; } +fi + + + test -n "$FLOCK" && break +done + + else + # The variable is set, but is it from the command line or the environment? + + # Try to remove the string !FLOCK! from our list. + try_remove_var=${CONFIGURE_OVERRIDDEN_VARIABLES//!FLOCK!/} + if test "x$try_remove_var" = "x$CONFIGURE_OVERRIDDEN_VARIABLES"; then + # If it failed, the variable was not from the command line. Ignore it, + # but warn the user (except for BASH, which is always set by the calling BASH). + if test "xFLOCK" != xBASH; then + { $as_echo "$as_me:${as_lineno-$LINENO}: WARNING: Ignoring value of FLOCK from the environment. Use command line variables instead." >&5 +$as_echo "$as_me: WARNING: Ignoring value of FLOCK from the environment. Use command line variables instead." >&2;} + fi + # Try to locate tool using the code snippet + for ac_prog in flock +do + # Extract the first word of "$ac_prog", so it can be a program name with args. +set dummy $ac_prog; ac_word=$2 +{ $as_echo "$as_me:${as_lineno-$LINENO}: checking for $ac_word" >&5 +$as_echo_n "checking for $ac_word... " >&6; } +if ${ac_cv_path_FLOCK+:} false; then : + $as_echo_n "(cached) " >&6 +else + case $FLOCK in + [\\/]* | ?:[\\/]*) + ac_cv_path_FLOCK="$FLOCK" # Let the user override the test with a path. + ;; + *) + as_save_IFS=$IFS; IFS=$PATH_SEPARATOR +for as_dir in $PATH +do + IFS=$as_save_IFS + test -z "$as_dir" && as_dir=. + for ac_exec_ext in '' $ac_executable_extensions; do + if as_fn_executable_p "$as_dir/$ac_word$ac_exec_ext"; then + ac_cv_path_FLOCK="$as_dir/$ac_word$ac_exec_ext" + $as_echo "$as_me:${as_lineno-$LINENO}: found $as_dir/$ac_word$ac_exec_ext" >&5 + break 2 + fi +done + done +IFS=$as_save_IFS + + ;; +esac +fi +FLOCK=$ac_cv_path_FLOCK +if test -n "$FLOCK"; then + { $as_echo "$as_me:${as_lineno-$LINENO}: result: $FLOCK" >&5 +$as_echo "$FLOCK" >&6; } +else + { $as_echo "$as_me:${as_lineno-$LINENO}: result: no" >&5 +$as_echo "no" >&6; } +fi + + + test -n "$FLOCK" && break +done + + else + # If it succeeded, then it was overridden by the user. We will use it + # for the tool. + + # First remove it from the list of overridden variables, so we can test + # for unknown variables in the end. + CONFIGURE_OVERRIDDEN_VARIABLES="$try_remove_var" + + # Check if we try to supply an empty value + if test "x$FLOCK" = x; then + { $as_echo "$as_me:${as_lineno-$LINENO}: Setting user supplied tool FLOCK= (no value)" >&5 +$as_echo "$as_me: Setting user supplied tool FLOCK= (no value)" >&6;} + { $as_echo "$as_me:${as_lineno-$LINENO}: checking for FLOCK" >&5 +$as_echo_n "checking for FLOCK... " >&6; } + { $as_echo "$as_me:${as_lineno-$LINENO}: result: disabled" >&5 +$as_echo "disabled" >&6; } + else + # Check if the provided tool contains a complete path. + tool_specified="$FLOCK" + tool_basename="${tool_specified##*/}" + if test "x$tool_basename" = "x$tool_specified"; then + # A command without a complete path is provided, search $PATH. + { $as_echo "$as_me:${as_lineno-$LINENO}: Will search for user supplied tool FLOCK=$tool_basename" >&5 +$as_echo "$as_me: Will search for user supplied tool FLOCK=$tool_basename" >&6;} + # Extract the first word of "$tool_basename", so it can be a program name with args. +set dummy $tool_basename; ac_word=$2 +{ $as_echo "$as_me:${as_lineno-$LINENO}: checking for $ac_word" >&5 +$as_echo_n "checking for $ac_word... " >&6; } +if ${ac_cv_path_FLOCK+:} false; then : + $as_echo_n "(cached) " >&6 +else + case $FLOCK in + [\\/]* | ?:[\\/]*) + ac_cv_path_FLOCK="$FLOCK" # Let the user override the test with a path. + ;; + *) + as_save_IFS=$IFS; IFS=$PATH_SEPARATOR +for as_dir in $PATH +do + IFS=$as_save_IFS + test -z "$as_dir" && as_dir=. + for ac_exec_ext in '' $ac_executable_extensions; do + if as_fn_executable_p "$as_dir/$ac_word$ac_exec_ext"; then + ac_cv_path_FLOCK="$as_dir/$ac_word$ac_exec_ext" + $as_echo "$as_me:${as_lineno-$LINENO}: found $as_dir/$ac_word$ac_exec_ext" >&5 + break 2 + fi +done + done +IFS=$as_save_IFS + + ;; +esac +fi +FLOCK=$ac_cv_path_FLOCK +if test -n "$FLOCK"; then + { $as_echo "$as_me:${as_lineno-$LINENO}: result: $FLOCK" >&5 +$as_echo "$FLOCK" >&6; } +else + { $as_echo "$as_me:${as_lineno-$LINENO}: result: no" >&5 +$as_echo "no" >&6; } +fi + + + if test "x$FLOCK" = x; then + as_fn_error $? "User supplied tool $tool_basename could not be found" "$LINENO" 5 + fi + else + # Otherwise we believe it is a complete path. Use it as it is. + { $as_echo "$as_me:${as_lineno-$LINENO}: Will use user supplied tool FLOCK=$tool_specified" >&5 +$as_echo "$as_me: Will use user supplied tool FLOCK=$tool_specified" >&6;} + { $as_echo "$as_me:${as_lineno-$LINENO}: checking for FLOCK" >&5 +$as_echo_n "checking for FLOCK... " >&6; } + if test ! -x "$tool_specified"; then + { $as_echo "$as_me:${as_lineno-$LINENO}: result: not found" >&5 +$as_echo "not found" >&6; } + as_fn_error $? "User supplied tool FLOCK=$tool_specified does not exist or is not executable" "$LINENO" 5 + fi + { $as_echo "$as_me:${as_lineno-$LINENO}: result: $tool_specified" >&5 +$as_echo "$tool_specified" >&6; } + fi + fi + fi + + fi + + # Dtrace is usually found in /usr/sbin on Solaris, but that directory may not # be in the user path. diff --git a/common/autoconf/spec.gmk.in b/common/autoconf/spec.gmk.in --- a/common/autoconf/spec.gmk.in +++ b/common/autoconf/spec.gmk.in @@ -48,7 +48,7 @@ # The default make arguments MAKE_ARGS = $(MAKE_LOG_FLAGS) -r -R -I $(TOPDIR)/make/common SPEC=$(SPEC) \ - MAKE_LOG_FLAGS="$(MAKE_LOG_FLAGS)" LOG_LEVEL=$(LOG_LEVEL) + MAKE_LOG_FLAGS="$(MAKE_LOG_FLAGS)" $(MAKE_LOG_VARS) OUTPUT_SYNC_SUPPORTED:=@OUTPUT_SYNC_SUPPORTED@ OUTPUT_SYNC:=@OUTPUT_SYNC@ @@ -636,6 +636,7 @@ DSYMUTIL:=@DSYMUTIL@ FIND:=@FIND@ FIND_DELETE:=@FIND_DELETE@ +FLOCK:=@FLOCK@ ECHO:=@ECHO@ EGREP:=@EGREP@ FGREP:=@FGREP@ diff --git a/common/bin/shell-tracer.sh b/common/bin/shell-profiler.sh copy from common/bin/shell-tracer.sh copy to common/bin/shell-profiler.sh --- a/common/bin/shell-tracer.sh +++ b/common/bin/shell-profiler.sh @@ -22,26 +22,48 @@ # questions. # -# Usage: sh shell-tracer.sh +# Usage: sh shell-tracer.sh # # This shell script is supposed to be set as a replacement for SHELL in make, # causing it to be called whenever make wants to execute shell commands. # The is suitable for passing on to the old shell, # typically beginning with -c. # -# This script will make sure the shell command line is executed with -# OLD_SHELL -x, and it will also store a simple log of the the time it takes to -# execute the command in the OUTPUT_FILE, using the "time" utility as pointed -# to by TIME_CMD. If TIME_CMD is "-", no timestamp will be stored. +# This script will run the shell command line and it will also store a simple +# log of the the time it takes to execute the command in the OUTPUT_FILE, using +# utility for time measure specified with TIME_CMD option. +# +# Type of time measure utility is specified with TIME_CMD_TYPE option. +# Recognized options values of TIME_CMD_TYPE option: "gnutime", "flock". -TIME_CMD="$1" -OUTPUT_FILE="$2" -OLD_SHELL="$3" +TIME_CMD_TYPE="$1" +TIME_CMD="$2" +OUTPUT_FILE="$3" shift shift shift -if [ "$TIME_CMD" != "-" ]; then -"$TIME_CMD" -f "[TIME:%E] $*" -a -o "$OUTPUT_FILE" "$OLD_SHELL" -x "$@" +if [ "$TIME_CMD_TYPE" = "gnutime" ]; then + # Escape backslashes (\) and percent chars (%). See man for GNU 'time'. + msg=${@//\\/\\\\} + msg=${msg//%/%%} + "$TIME_CMD" -f "[TIME:%E] $msg" -a -o "$OUTPUT_FILE" "$@" +elif [ "$TIME_CMD_TYPE" = "flock" ]; then + # Emulated GNU 'time' with 'flock' and 'date'. + ts=`date +%s%3N` + "$@" + status=$? + ts2=`date +%s%3N` + millis=$((ts2 - ts)) + ms=$(($millis % 1000)) + seconds=$((millis / 1000)) + ss=$(($seconds % 60)) + minutes=$(($seconds / 60)) + mm=$(($minutes % 60)) + hh=$(($minutes / 60)): + [ $hh != "0:" ] || hh= + # Synchronize on this script. + flock -w 10 "$0" printf "[TIME:${hh}${mm}:${ss}.%.2s] %s\n" $ms "$*" >> "$OUTPUT_FILE" || true + exit $status else -"$OLD_SHELL" -x "$@" + "$@" fi diff --git a/make/Init.gmk b/make/Init.gmk --- a/make/Init.gmk +++ b/make/Init.gmk @@ -117,7 +117,7 @@ # Check that CONF_CHECK is valid. $(eval $(call ParseConfCheckOption)) - # Check that the LOG given is valid, and set LOG_LEVEL, LOG_NOFILE and MAKE_LOG_FLAGS. + # Check that the LOG given is valid, and set LOG_LEVEL, LOG_NOFILE, MAKE_LOG_VARS and MAKE_LOG_FLAGS. $(eval $(call ParseLogLevel)) # After this SPECS contain 1..N spec files (otherwise ParseConfAndSpec fails). @@ -171,7 +171,7 @@ MAKE_INIT_WITH_SPEC_ARGUMENTS := ACTUAL_TOPDIR=$(topdir) \ USER_MAKE_VARS="$(USER_MAKE_VARS)" MAKE_LOG_FLAGS=$(MAKE_LOG_FLAGS) \ - LOG_LEVEL=$(LOG_LEVEL) LOG_NOFILE=$(LOG_NOFILE) LOG_CMDLINES=$(LOG_CMDLINES) \ + $(MAKE_LOG_VARS) \ INIT_TARGETS="$(INIT_TARGETS)" \ SEQUENTIAL_TARGETS="$(SEQUENTIAL_TARGETS)" \ PARALLEL_TARGETS="$(PARALLEL_TARGETS)" @@ -319,6 +319,7 @@ exit 1 ; \ fi $(PRINTF) "Finished building $(TARGET_DESCRIPTION)\n" $(BUILD_LOG_PIPE) + $(call ReportProfileTimes) endif on-failure: @@ -327,6 +328,7 @@ $(call ReportBuildTimes) $(call PrintFailureReports) $(call PrintBuildLogFailures) + $(call ReportProfileTimes) $(PRINTF) "Hint: If caused by a warning, try configure --disable-warnings-as-errors.\n\n" ifneq ($(COMPARE_BUILD), ) $(call CleanupCompareBuild) diff --git a/make/InitSupport.gmk b/make/InitSupport.gmk --- a/make/InitSupport.gmk +++ b/make/InitSupport.gmk @@ -157,7 +157,19 @@ # If the "cmdline" argument is given, act on it and strip it away $$(eval $$(call ParseLogOption, cmdlines, LOG_CMDLINES)) + + # If the "profile-to-log" argument is given, write shell times in build log + $$(eval $$(call ParseLogOption, profile-to-log, LOG_PROFILE_TIMES_LOG)) + # If the "profile" argument is given, write shell times in separate log file + # IMPORTANT: $(ParseLogOption profile-to-log) should go first. Otherwise + # parsing of 'LOG=debug,profile-to-log,nofile' ends up in the following error: + # Error: LOG contains unknown option or log level: debug-to-log. + $$(eval $$(call ParseLogOption, profile, LOG_PROFILE_TIMES_FILE)) + + # Treat LOG=profile-to-log as if it were LOG=profile,profile-to-log + LOG_PROFILE_TIMES_FILE := $$(firstword $$(LOG_PROFILE_TIMES_FILE) $$(LOG_PROFILE_TIMES_LOG)) + LOG_LEVEL := $$(LOG) ifeq ($$(LOG_LEVEL),) @@ -175,7 +187,7 @@ MAKE_LOG_FLAGS := else $$(info Error: LOG contains unknown option or log level: $$(LOG).) - $$(info LOG can be [,[...]] where is nofile | cmdlines) + $$(info LOG can be [,[...]] where is nofile | cmdlines | profile | profile-to-log) $$(info and is warn | info | debug | trace) $$(error Cannot continue) endif @@ -309,7 +321,7 @@ @( cd $$(topdir) && \ $$(MAKE) $$(MAKE_LOG_FLAGS) -r -R -f $$(topdir)/make/Main.gmk \ -I $$(topdir)/make/common SPEC=$(strip $2) NO_RECIPES=true \ - LOG_LEVEL=$$(LOG_LEVEL) \ + $$(MAKE_LOG_VARS) \ create-main-targets-include ) # Now include main-targets.gmk. This will define ALL_MAIN_TARGETS. @@ -334,7 +346,7 @@ # Define basic logging setup BUILD_LOG := $(OUTPUT_ROOT)/build.log - BUILD_TRACE_LOG := $(OUTPUT_ROOT)/build-trace-time.log + BUILD_PROFILE_LOG := $(OUTPUT_ROOT)/build-profile.log BUILD_LOG_PIPE := > >($(TEE) -a $(BUILD_LOG)) 2> >($(TEE) -a $(BUILD_LOG) >&2) && wait @@ -494,9 +506,9 @@ define RotateLogFiles $(RM) $(BUILD_LOG).old 2> /dev/null && \ $(MV) $(BUILD_LOG) $(BUILD_LOG).old 2> /dev/null || true - $(if $(findstring trace, $(LOG_LEVEL)), \ - $(RM) $(BUILD_TRACE_LOG).old 2> /dev/null && \ - $(MV) $(BUILD_TRACE_LOG) $(BUILD_TRACE_LOG).old 2> /dev/null || true \ + $(if $(findstring true, $(LOG_PROFILE_TIMES_FILE)), \ + $(RM) $(BUILD_PROFILE_LOG).old 2> /dev/null && \ + $(MV) $(BUILD_PROFILE_LOG) $(BUILD_PROFILE_LOG).old 2> /dev/null || true \ ) endef @@ -558,6 +570,22 @@ $(BUILD_LOG_PIPE) endef + define ReportProfileTimes + $(if $(findstring true, $(LOG_PROFILE_TIMES_LOG)), \ + [ ! -f $(BUILD_PROFILE_LOG) ] || \ + { $(ECHO) Begin $(notdir $(BUILD_PROFILE_LOG)) && \ + $(CAT) $(BUILD_PROFILE_LOG) && \ + $(ECHO) End $(notdir $(BUILD_PROFILE_LOG)); \ + } \ + $(BUILD_LOG_PIPE) + ) + endef + endif # HAS_SPEC +MAKE_LOG_VARS = $(foreach v, \ + LOG_LEVEL LOG_NOFILE LOG_CMDLINES LOG_PROFILE_TIMES_LOG LOG_PROFILE_TIMES_FILE, \ + $v=$($v) \ +) + endif # _INITSUPPORT_GMK diff --git a/make/common/MakeBase.gmk b/make/common/MakeBase.gmk --- a/make/common/MakeBase.gmk +++ b/make/common/MakeBase.gmk @@ -355,17 +355,28 @@ ################################################################################ define SetupLogging + ifeq ($$(LOG_PROFILE_TIMES_FILE), true) + ifeq ($$(IS_GNU_TIME), yes) + SHELL := $$(BASH) $$(SRC_ROOT)/common/bin/shell-profiler.sh \ + gnutime $$(TIME) \ + $$(OUTPUT_ROOT)/build-profile.log $$(SHELL) + else ifneq ($$(FLOCK), ) + SHELL := $$(BASH) $$(SRC_ROOT)/common/bin/shell-profiler.sh \ + flock $$(FLOCK) \ + $$(OUTPUT_ROOT)/build-profile.log $$(SHELL) + endif + endif + ifeq ($$(LOG_LEVEL), trace) + SHELL_NO_RECURSE := $$(SHELL) # Shell redefinition trick inspired by http://www.cmcrossroads.com/ask-mr-make/6535-tracing-rule-execution-in-gnu-make # For each target executed, will print # Building (from ) ( newer) # but with a limit of 20 on , to avoid cluttering logs too much # (and causing a crash on Cygwin). - # Default shell seems to always be /bin/sh. Must override with bash to get this to work on Solaris. - # Only use time if it's GNU time which supports format and output file. - WRAPPER_SHELL := $$(BASH) $$(SRC_ROOT)/common/bin/shell-tracer.sh $$(if $$(findstring yes,$$(IS_GNU_TIME)),$$(TIME),-) $$(OUTPUT_ROOT)/build-trace-time.log $$(SHELL) - SHELL = $$(warning $$(if $$@,Building $$@,Running shell command) $$(if $$<, (from $$<))$$(if $$?, ($$(wordlist 1, 20, $$?) $$(if $$(wordlist 21, 22, $$?), ... [in total $$(words $$?) files]) newer)))$$(WRAPPER_SHELL) + SHELL = $$(warning $$(if $$@,Building $$@,Running shell command) $$(if $$<, (from $$<))$$(if $$?, ($$(wordlist 1, 20, $$?) $$(if $$(wordlist 21, 22, $$?), ... [in total $$(words $$?) files]) newer)))$$(SHELL_NO_RECURSE) -x endif + # The warn level can never be turned off LogWarn = $$(info $$(strip $$1)) LOG_WARN :=