7021753: Add a build times report

Summary: Report the build times at end of a jdkroot build.
Reviewed-by: ohair

10 files changed, 91 insertions, 49 deletions

diff --git a/make/Defs-internal.gmk b/make/Defs-internal.gmk
index 8cb28b8..c55675f 100644
--- a/make/Defs-internal.gmk
+++ b/make/Defs-internal.gmk
@@ -28,21 +28,63 @@
 # 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
 
-define MakeFinish
-$(PRINTF) "%s\n##### %-60.60s #####\n%s\n%s\n\n" \
+# 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 
+$(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
diff --git a/make/corba-rules.gmk b/make/corba-rules.gmk
index 2cdeeb4..13671ee 100644
--- a/make/corba-rules.gmk
+++ b/make/corba-rules.gmk
@@ -40,17 +40,17 @@ endif
 corba: corba-build
 corba-build:
 	$(MKDIR) -p $(CORBA_OUTPUTDIR)
-	@$(call MakeStart, corba, all)
+	@$(call MakeStart,corba,all)
 	($(CD) $(CORBA_TOPDIR)/make && \
 	 $(MAKE) $(CORBA_BUILD_ARGUMENTS) all)
-	@$(call MakeFinish, corba, all)
+	@$(call MakeFinish,corba,all)
 
 corba-clobber::
 	$(MKDIR) -p $(CORBA_OUTPUTDIR)
-	@$(call MakeStart, corba, clobber)
+	@$(call MakeStart,corba,clobber)
 	($(CD) $(CORBA_TOPDIR)/make &&  \
 	 $(MAKE) $(CORBA_BUILD_ARGUMENTS) clobber)
-	@$(call MakeFinish, corba, clobber)
+	@$(call MakeFinish,corba,clobber)
 
 .PHONY: corba corba-build corba-clobber 
 
diff --git a/make/deploy-rules.gmk b/make/deploy-rules.gmk
index d05d409..003698c 100644
--- a/make/deploy-rules.gmk
+++ b/make/deploy-rules.gmk
@@ -116,18 +116,18 @@ endif
 
 deploy-build:
 ifeq ($(BUILD_DEPLOY), true)
-	@$(call MakeStart, deploy, $(DEPLOY_BUILD_TARGETS))
+	@$(call MakeStart,deploy,$(DEPLOY_BUILD_TARGETS))
 	($(CD) $(DEPLOY_TOPDIR)/make && \
 	  $(MAKE) $(DEPLOY_BUILD_TARGETS) $(DEPLOY_BUILD_ARGUMENTS))
-	@$(call MakeFinish, deploy, $(DEPLOY_BUILD_TARGETS))
+	@$(call MakeFinish,deploy,$(DEPLOY_BUILD_TARGETS))
 endif
 
 deploy-clobber::
 ifeq ($(BUILD_DEPLOY), true)
-	@$(call MakeStart, deploy, clobber)
+	@$(call MakeStart,deploy,clobber)
 	($(CD) $(DEPLOY_TOPDIR)/make && \
 	  $(MAKE) clobber $(DEPLOY_BUILD_ARGUMENTS))
-	@$(call MakeFinish, deploy, clobber)
+	@$(call MakeFinish,deploy,clobber)
 endif 
 
 deploy-sanity::
diff --git a/make/hotspot-rules.gmk b/make/hotspot-rules.gmk
index 674ce63..8bc6e75 100644
--- a/make/hotspot-rules.gmk
+++ b/make/hotspot-rules.gmk
@@ -96,10 +96,10 @@ endif
 hotspot-build::
 	$(MKDIR) -p $(HOTSPOT_OUTPUTDIR)
 	$(MKDIR) -p $(HOTSPOT_EXPORT_PATH)
-	@$(call MakeStart, hotspot, $(HOTSPOT_TARGET))
+	@$(call MakeStart,hotspot,$(HOTSPOT_TARGET))
 	$(CD) $(HOTSPOT_TOPDIR)/make && \
 	    $(MAKE) $(HOTSPOT_BUILD_ARGUMENTS) $(HOTSPOT_TARGET)
-	@$(call MakeFinish, hotspot, $(HOTSPOT_TARGET))
+	@$(call MakeFinish,hotspot,$(HOTSPOT_TARGET))
 
 #####################
 # .PHONY
diff --git a/make/install-rules.gmk b/make/install-rules.gmk
index 8e1f189..932985e 100644
--- a/make/install-rules.gmk
+++ b/make/install-rules.gmk
@@ -57,39 +57,39 @@ install: install-build
 
 install-build:
 ifeq ($(BUILD_INSTALL), true)
-	@$(call MakeStart, install, $(INSTALL_BUILD_TARGETS))
+	@$(call MakeStart,install,$(INSTALL_BUILD_TARGETS))
 	($(CD) $(INSTALL_TOPDIR)/make && \
 	  $(MAKE) $(INSTALL_BUILD_TARGETS) $(INSTALL_BUILD_ARGUMENTS))
-	@$(call MakeFinish, install, $(INSTALL_BUILD_TARGETS))
+	@$(call MakeFinish,install,$(INSTALL_BUILD_TARGETS))
 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
 
@@ -99,10 +99,10 @@ combo_build:
 
 install-clobber:
 ifeq ($(BUILD_INSTALL), true)
-	@$(call MakeStart, install, clobber)
+	@$(call MakeStart,install,clobber)
 	($(CD) $(INSTALL_TOPDIR)/make && \
 	  $(MAKE) clobber $(INSTALL_BUILD_ARGUMENTS))
-	@$(call MakeFinish, install, clobber)
+	@$(call MakeFinish,install,clobber)
 endif
 
 install-sanity:: 
diff --git a/make/jaxp-rules.gmk b/make/jaxp-rules.gmk
index b37026b..625b2ec 100644
--- a/make/jaxp-rules.gmk
+++ b/make/jaxp-rules.gmk
@@ -40,17 +40,17 @@ endif
 jaxp: jaxp-build
 jaxp-build:
 	$(MKDIR) -p $(JAXP_OUTPUTDIR)
-	@$(call MakeStart, jaxp, all)
+	@$(call MakeStart,jaxp,all)
 	($(CD) $(JAXP_TOPDIR)/make && \
 	 $(MAKE) $(JAXP_BUILD_ARGUMENTS) all)
-	@$(call MakeFinish, jaxp, all)
+	@$(call MakeFinish,jaxp,all)
 
 jaxp-clobber::
 	$(MKDIR) -p $(JAXP_OUTPUTDIR)
-	@$(call MakeStart, jaxp, clobber)
+	@$(call MakeStart,jaxp,clobber)
 	($(CD) $(JAXP_TOPDIR)/make &&  \
 	 $(MAKE) $(JAXP_BUILD_ARGUMENTS) clobber)
-	@$(call MakeFinish, jaxp, clobber)
+	@$(call MakeFinish,jaxp,clobber)
 
 .PHONY: jaxp jaxp-build jaxp-clobber
 
diff --git a/make/jaxws-rules.gmk b/make/jaxws-rules.gmk
index 981ddb0..4956a98 100644
--- a/make/jaxws-rules.gmk
+++ b/make/jaxws-rules.gmk
@@ -40,17 +40,17 @@ endif
 jaxws: jaxws-build
 jaxws-build:
 	$(MKDIR) -p $(JAXWS_OUTPUTDIR)
-	@$(call MakeStart, jaxws, all)
+	@$(call MakeStart,jaxws,all)
 	($(CD) $(JAXWS_TOPDIR)/make && \
 	 $(MAKE) $(JAXWS_BUILD_ARGUMENTS) all)
-	@$(call MakeFinish, jaxws, all)
+	@$(call MakeFinish,jaxws,all)
 
 jaxws-clobber::
 	$(MKDIR) -p $(JAXWS_OUTPUTDIR)
-	@$(call MakeStart, jaxws, clobber)
+	@$(call MakeStart,jaxws,clobber)
 	($(CD) $(JAXWS_TOPDIR)/make &&  \
 	 $(MAKE) $(JAXWS_BUILD_ARGUMENTS) clobber)
-	@$(call MakeFinish, jaxws, clobber)
+	@$(call MakeFinish,jaxws,clobber)
 
 .PHONY: jaxws jaxws-build jaxws-clobber
 
diff --git a/make/jdk-rules.gmk b/make/jdk-rules.gmk
index e814918..cfc56ed 100644
--- a/make/jdk-rules.gmk
+++ b/make/jdk-rules.gmk
@@ -75,16 +75,16 @@ $(JDK_JAVA_EXE):: jdk-build
 
 jdk: jdk-build
 jdk-build:
-	@$(call MakeStart, jdk, $(JDK_BUILD_TARGETS))
+	@$(call MakeStart,jdk,$(JDK_BUILD_TARGETS))
 	( $(CD) $(JDK_TOPDIR)/make && \
 	  $(MAKE) $(JDK_BUILD_TARGETS) $(JDK_BUILD_ARGUMENTS) ; )
-	@$(call MakeFinish, jdk, $(JDK_BUILD_TARGETS))
+	@$(call MakeFinish,jdk,$(JDK_BUILD_TARGETS))
 
 jdk-clobber::
-	@$(call MakeStart, jdk, $(JDK_CLOBBER_TARGETS))
+	@$(call MakeStart,jdk,$(JDK_CLOBBER_TARGETS))
 	( $(CD) $(JDK_TOPDIR)/make && \
 	  $(MAKE) $(JDK_CLOBBER_TARGETS) $(JDK_BUILD_ARGUMENTS) ; )
-	@$(call MakeFinish, jdk, $(JDK_CLOBBER_TARGETS))
+	@$(call MakeFinish,jdk,$(JDK_CLOBBER_TARGETS))
 
 jdk-sanity::
 	( $(CD) $(JDK_TOPDIR)/make && \
@@ -92,17 +92,17 @@ jdk-sanity::
 
 compare-images: compare-image
 compare-image:
-	@$(call MakeStart, jdk, compare-image)
+	@$(call MakeStart,jdk,compare-image)
 	( $(CD) $(JDK_TOPDIR)/make && \
 	  $(MAKE) ALT_OUTPUTDIR=$(ABS_OUTPUTDIR) compare-image )
-	@$(call MakeFinish, jdk, compare-image)
+	@$(call MakeFinish,jdk,compare-image)
 
 compare-images-clobber: compare-image-clobber
 compare-image-clobber:
-	@$(call MakeStart, jdk, compare-image-clobber)
+	@$(call MakeStart,jdk,compare-image-clobber)
 	( $(CD) $(JDK_TOPDIR)/make && \
 	  $(MAKE) ALT_OUTPUTDIR=$(ABS_OUTPUTDIR) compare-image-clobber )
-	@$(call MakeFinish, jdk, compare-image-clobber)
+	@$(call MakeFinish,jdk,compare-image-clobber)
 
 .PHONY: jdk jdk-build jdk-clobber jdk-sanity 
 
diff --git a/make/langtools-rules.gmk b/make/langtools-rules.gmk
index 99ce0c1..a0b2649 100644
--- a/make/langtools-rules.gmk
+++ b/make/langtools-rules.gmk
@@ -35,17 +35,17 @@ LANGTOOLS_BUILD_ARGUMENTS = \
 langtools: langtools-build
 langtools-build:
 	$(MKDIR) -p $(LANGTOOLS_OUTPUTDIR)
-	@$(call MakeStart, langtools, all)
+	@$(call MakeStart,langtools,all)
 	($(CD) $(LANGTOOLS_TOPDIR)/make && \
 	  $(MAKE) $(LANGTOOLS_BUILD_ARGUMENTS) all)
-	@$(call MakeFinish, langtools, all)
+	@$(call MakeFinish,langtools,all)
 
 langtools-clobber::
 	$(MKDIR) -p $(LANGTOOLS_OUTPUTDIR)
-	@$(call MakeStart, langtools, clobber)
+	@$(call MakeStart,langtools,clobber)
 	($(CD) $(LANGTOOLS_TOPDIR)/make &&  \
 	  $(MAKE) $(LANGTOOLS_BUILD_ARGUMENTS) clobber)
-	@$(call MakeFinish, langtools, clobber)
+	@$(call MakeFinish,langtools,clobber)
 
 .PHONY: langtools langtools-build langtools-clobber
 
diff --git a/make/sponsors-rules.gmk b/make/sponsors-rules.gmk
index fd7fb40..4fd60ea 100644
--- a/make/sponsors-rules.gmk
+++ b/make/sponsors-rules.gmk
@@ -59,10 +59,10 @@ endif
 sponsors-build:
 ifeq ($(ARCH_DATA_MODEL), 32)
   ifeq ($(BUILD_SPONSORS), true)
-	@$(call MakeStart, sponsors, $(SPONSORS_BUILD_TARGETS))
+	@$(call MakeStart,sponsors,$(SPONSORS_BUILD_TARGETS))
 	($(CD) $(SPONSORS_TOPDIR)/make && \
 	  $(MAKE) $(SPONSORS_BUILD_TARGETS) $(SPONSORS_BUILD_ARGUMENTS))
-	@$(call MakeFinish, sponsors, $(SPONSORS_BUILD_TARGETS))
+	@$(call MakeFinish,sponsors,$(SPONSORS_BUILD_TARGETS))
   endif
 endif