7021753: Add a build times report

Report the build times at end of a jdkroot build.

Reviewed-by: ohair

Makefile

@@ -36,12 +36,6 @@ ifndef JDK_MAKE_SHARED_DIR
   JDK_MAKE_SHARED_DIR=$(JDK_TOPDIR)/make/common/shared
 endif
 
-# For start and finish echo lines
-TITLE_TEXT = Control $(PLATFORM) $(ARCH) $(RELEASE)
-DATE_STAMP = `$(DATE) '+%y-%m-%d %H:%M'`
-START_ECHO  = echo "$(TITLE_TEXT) $@ build started: $(DATE_STAMP)"
-FINISH_ECHO = echo "$(TITLE_TEXT) $@ build finished: $(DATE_STAMP)"
-
 default: all
 
 include $(JDK_MAKE_SHARED_DIR)/Defs-control.gmk
@@ -57,10 +51,6 @@ include ./make/install-rules.gmk
 include ./make/sponsors-rules.gmk
 include ./make/deploy-rules.gmk
 
-# What "all" means
-all::
-	@$(START_ECHO)
-
 all:: sanity
 
 ifeq ($(SKIP_FASTDEBUG_BUILD), false)
@@ -73,13 +63,7 @@ endif
 
 all:: all_product_build 
 
-all:: 
-	@$(FINISH_ECHO)
-
 # Everything for a full product build
-all_product_build::
-	@$(START_ECHO)
-
 ifeq ($(SKIP_PRODUCT_BUILD), false)
 
   all_product_build:: product_build
@@ -100,13 +84,21 @@ ifeq ($(SKIP_PRODUCT_BUILD), false)
 
 endif
 
-all_product_build:: 
+define StartTimer
-	@$(FINISH_ECHO)
+	$(MKDIR) -p $(BUILDTIMESDIR)
+	$(RM) $(BUILDTIMESDIR)/build_time_*
+	$(call RecordStartTime,TOTAL)
+endef
+
+define StopTimer
+	$(if $(REPORT_BUILD_TIMES),$(call RecordEndTime,TOTAL) && $(call ReportBuildTimes,$1),)
+endef
 
 # Generic build of basic repo series
 generic_build_repo_series::
 	$(MKDIR) -p $(OUTPUTDIR)
 	$(MKDIR) -p $(OUTPUTDIR)/j2sdk-image
+	@$(call StartTimer)
 
 ifeq ($(BUILD_LANGTOOLS), true)
   generic_build_repo_series:: langtools
@@ -143,6 +135,9 @@ ifeq ($(BUILD_DEPLOY), true)
   clobber:: deploy-clobber
 endif
 
+generic_build_repo_series::
+	@$(call StopTimer,$(if $(DEBUG_NAME),$(DEBUG_NAME)_build,all_product_build))
+
 # The debug build, fastdebug or debug. Needs special handling.
 #  Note that debug builds do NOT do INSTALL steps, but must be done
 #  after the product build and before the INSTALL step of the product build.
@@ -167,28 +162,22 @@ FRESH_BOOTDIR=$(ABS_BOOTDIR_OUTPUTDIR)/j2sdk-image
 FRESH_DEBUG_BOOTDIR=$(ABS_BOOTDIR_OUTPUTDIR)/../$(PLATFORM)-$(ARCH)-$(DEBUG_NAME)/j2sdk-image
   
 create_fresh_product_bootdir: FRC
-	@$(START_ECHO)
 	$(MAKE) ALT_OUTPUTDIR=$(ABS_BOOTDIR_OUTPUTDIR) \
 		GENERATE_DOCS=false \
 		BOOT_CYCLE_SETTINGS= \
 		build_product_image
-	@$(FINISH_ECHO)
 
 create_fresh_debug_bootdir: FRC
-	@$(START_ECHO)
 	$(MAKE) ALT_OUTPUTDIR=$(ABS_BOOTDIR_OUTPUTDIR) \
 		GENERATE_DOCS=false \
 		BOOT_CYCLE_DEBUG_SETTINGS= \
 		build_debug_image
-	@$(FINISH_ECHO)
 
 create_fresh_fastdebug_bootdir: FRC
-	@$(START_ECHO)
 	$(MAKE) ALT_OUTPUTDIR=$(ABS_BOOTDIR_OUTPUTDIR) \
 		GENERATE_DOCS=false \
 		BOOT_CYCLE_DEBUG_SETTINGS= \
 		build_fastdebug_image
-	@$(FINISH_ECHO)
 
 # Create boot image?
 ifeq ($(SKIP_BOOT_CYCLE),false)
@@ -197,6 +186,8 @@ ifeq ($(SKIP_BOOT_CYCLE),false)
   endif
 endif
 
+
+
 ifeq ($(DO_BOOT_CYCLE),true)
   
   # Create the bootdir to use in the build
@@ -221,27 +212,23 @@ else
 endif
 
 build_product_image:
-	@$(START_ECHO)
 	$(MAKE) \
 	        SKIP_FASTDEBUG_BUILD=true \
 	        SKIP_DEBUG_BUILD=true \
 	        $(BOOT_CYCLE_SETTINGS) \
 	        generic_build_repo_series
-	@$(FINISH_ECHO)
 
 #   NOTE: On windows, do not use $(ABS_OUTPUTDIR)-$(DEBUG_NAME).
 #         Due to the use of short paths in $(ABS_OUTPUTDIR), this may 
 #         not be the same location.
 
 generic_debug_build:
-	@$(START_ECHO)
 	$(MAKE) \
 		ALT_OUTPUTDIR=$(ABS_OUTPUTDIR)/../$(PLATFORM)-$(ARCH)-$(DEBUG_NAME) \
 	        DEBUG_NAME=$(DEBUG_NAME) \
 		GENERATE_DOCS=false \
 	        $(BOOT_CYCLE_DEBUG_SETTINGS) \
 		generic_build_repo_series
-	@$(FINISH_ECHO)
 
 build_debug_image:
 	$(MAKE) DEBUG_NAME=debug generic_debug_build
@@ -254,6 +241,7 @@ product_build:: build_product_image
 debug_build:: build_debug_image
 fastdebug_build:: build_fastdebug_image
 
+clobber:: REPORT_BUILD_TIMES=
 clobber:: 
 	$(RM) -r $(OUTPUTDIR)/*
 	$(RM) -r $(OUTPUTDIR)/../$(PLATFORM)-$(ARCH)-debug/*

make/Defs-internal.gmk

@@ -28,23 +28,65 @@
 # not contain rules.
 #
 
-# Indicate that we are visiting a separate repo or component 
+# The build times report is turned off by setting REPORT_BUILD_TIMES to nothing.
+# This is necessary for the target clobber/clean which will erase the
+# directories where the buildtimes are stored.
+REPORT_BUILD_TIMES=1
+# Store the build times in this directory.
+BUILDTIMESDIR=$(ABS_OUTPUTDIR)/tmp/buildtimes
+
+# Record starting time for build of a sub repository.
+define RecordStartTime
+$(MKDIR) -p $(BUILDTIMESDIR)
+$(DATE) '+%Y %m %d %H %M %S' | $(NAWK) '{ print $$1,$$2,$$3,$$4,$$5,$$6,($$4*3600+$$5*60+$$6) }' > $(BUILDTIMESDIR)/build_time_start_$1
+$(DATE) '+%Y-%m-%d %H:%M:%S' > $(BUILDTIMESDIR)/build_time_start_$1_human_readable
+endef
+
+# Indicate that we started to build a sub repository and record starting time. 
 define MakeStart
-$(PRINTF) "\n\n%s\n%s\n##### %-60.60s #####\n%s\n" \
+$(call RecordStartTime,$1)
+$(PRINTF) "\n\n%s\n%s\n##### %-60.60s #####\n%s\n\n" \
 "########################################################################" \
 "########################################################################" \
-"Entering $1 for target $2" \
+"Entering $1 for target(s) $2" \
 "########################################################################"
 endef
 
+# Record ending time and calculate the difference and store it in a
+# easy to read format. Handles builds that cross midnight. Expects
+# that a build will never take 24 hours or more. 
+define RecordEndTime
+$(DATE) '+%Y %m %d %H %M %S' | $(NAWK) '{ print $$1,$$2,$$3,$$4,$$5,$$6,($$4*3600+$$5*60+$$6) }' > $(BUILDTIMESDIR)/build_time_end_$1
+$(DATE) '+%Y-%m-%d %H:%M:%S' > $(BUILDTIMESDIR)/build_time_end_$1_human_readable
+$(ECHO) `$(CAT) $(BUILDTIMESDIR)/build_time_start_$1` `$(CAT) $(BUILDTIMESDIR)/build_time_end_$1` $1 | \
+  $(NAWK) '{ F=$$7; T=$$14; if (F > T) { T+=3600*24 }; D=T-F; H=int(D/3600); \
+             M=int((D-H*3600)/60); S=D-H*3600-M*60; printf("%02d:%02d:%02d %s\n",H,M,S,$$15); }' \
+  > $(BUILDTIMESDIR)/build_time_diff_$1
+endef
+
+# Indicate that we are done.
+# Record ending time and print out the total time it took to build.
 define MakeFinish 
-$(PRINTF) "%s\n##### %-60.60s #####\n%s\n%s\n\n" \
+$(if $(REPORT_BUILD_TIMES),$(call RecordEndTime,$1),) 
+$(PRINTF) "%s\n##### %-60.60s #####\n%s\n##### %-60.60s #####\n%s\n\n" \
 "########################################################################" \
-"Leaving $1 for target $2" \
+"Leaving $1 for target(s) $2" \
 "########################################################################" \
+$(if $(REPORT_BUILD_TIMES),"Build time `$(CAT) $(BUILDTIMESDIR)/build_time_diff_$1` for target(s) $2","") \
 "########################################################################" 
 endef
 
+# Find all build_time_* files and print their contents in a list sorted
+# on the name of the sub repository.
+define ReportBuildTimes
+$(PRINTF) "-- Build times ----------\nTarget %s\nStart %s\nEnd   %s\n%s\n%s\n-------------------------\n" \
+$1 \
+"`$(CAT) $(BUILDTIMESDIR)/build_time_start_TOTAL_human_readable`" \
+"`$(CAT) $(BUILDTIMESDIR)/build_time_end_TOTAL_human_readable`" \
+"`$(LS) $(BUILDTIMESDIR)/build_time_diff_* | $(GREP) -v _TOTAL | $(XARGS) $(CAT) | $(SORT) -k 2`" \
+"`$(CAT) $(BUILDTIMESDIR)/build_time_diff_TOTAL`"
+endef
+
 ifdef OPENJDK
   ifneq ($(OPENJDK),true)
     x:=$(error "OPENJDK (if defined) can only be set to true")

make/install-rules.gmk

@@ -66,30 +66,30 @@ endif
 update-patcher:
 ifeq ($(BUILD_INSTALL), true)
 	if [ -r $(INSTALL_TOPDIR)/make/update/Makefile ]; then \
-	  $(call MakeStart, install update, all); \
+	  $(call MakeStart,install_update,all); \
 	  ( $(CD) $(INSTALL_TOPDIR)/make/update && \
 	    $(MAKE) all $(INSTALL_BUILD_ARGUMENTS) ); \
-	  $(call MakeFinish, install, all); \
+	  $(call MakeFinish,install_update,all); \
 	fi
 endif
 
 update-patchgen:
 ifeq ($(BUILD_INSTALL), true)
 	if [ -r $(INSTALL_TOPDIR)/make/update/Makefile ]; then \
-	  $(call MakeStart, install update, patchgen); \
+	  $(call MakeStart,install_update,patchgen); \
 	  ( $(CD) $(INSTALL_TOPDIR)/make/update && \
 	    $(MAKE) patchgen $(INSTALL_BUILD_ARGUMENTS) ); \
-	  $(call MakeFinish, install, patchgen); \
+	  $(call MakeFinish,install_update,patchgen); \
 	fi
 endif
 
 installer:
 ifeq ($(BUILD_INSTALL), true)
 	if [ -r $(INSTALL_TOPDIR)/make/installer/Makefile ]; then \
-	  $(call MakeStart, install installer, all); \
+	  $(call MakeStart,install_installer,all); \
 	  ( $(CD) $(INSTALL_TOPDIR)/make/installer && \
 	    $(MAKE) all $(INSTALL_BUILD_ARGUMENTS) ); \
-	  $(call MakeFinish, install, all); \
+	  $(call MakeFinish,install_installer,all); \
 	fi
 endif