Index: /trunk/kBuild/footer.kmk
===================================================================
--- /trunk/kBuild/footer.kmk	(revision 2007)
+++ /trunk/kBuild/footer.kmk	(revision 2008)
@@ -35,8 +35,6 @@
 # start-of-file-content
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_FOOTER_START := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_FOOTER_START), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_FOOTER_START), $(_KBUILD_TS_PREV)) - start of footer.kmk)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_FOOTER_START)
+ $(evalcall def_profile_self, start of footer.kmk)
+ _KBUILD_TS_FOOTER_START := $(_KBUILD_TS_PREV)
 endif
 
@@ -849,8 +847,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done keywords)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done keywords)
 endif
 
@@ -930,8 +925,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done target inheritance)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done target inheritance)
 endif
 
@@ -969,8 +961,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done template inheritance)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done template inheritance)
 endif
 
@@ -1173,8 +1162,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done template/target expansion)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done template/target expansion)
 endif
 
@@ -1356,8 +1342,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done tools, sdks and units)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done tools + sdks + units)
 endif
 
@@ -1569,8 +1552,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done pass 1)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done pass 1)
 endif
 
@@ -1972,8 +1952,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done fetching targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done fetching targets)
 endif
 
@@ -2491,8 +2468,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done library targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done library targets)
 endif
 
@@ -2916,8 +2890,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done build program targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done build program targets)
 endif
 
@@ -2938,8 +2909,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done dll targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done dll targets)
 endif
 
@@ -2968,8 +2936,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done import library targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done import library targets)
 endif
 
@@ -2990,8 +2955,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done program targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done program targets)
 endif
 
@@ -3012,8 +2974,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done sysmod targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done sysmod targets)
 endif
 
@@ -3354,8 +3313,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done install targets)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done install targets)
 endif
 
@@ -3393,8 +3349,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done directories)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done directories)
 endif
 
@@ -3404,9 +3357,11 @@
 #
 do-nothing:
+	%$(call MSG_NOTHING)
 ifdef KBUILD_PROFILE_SELF
-	@$(ECHO) 'prof: $(int-sub $(nanots ), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(nanots ), $(_KBUILD_TS_PREV)) - executing $@'
+	@$(ECHO) 'prof: $(call _KBUILD_FMT_ELAPSED_EX, $(nanots ), $(_KBUILD_TS_HEADER_START)) - $(call _KBUILD_FMT_ELAPSED_EX, $(nanots ), $(_KBUILD_TS_PREV)) - executing $@'
+ ifeq ($(KBUILD_PROFILE_SELF),2)
 	@$(ECHO) 'stat: $(make-stats )'
-endif
-	%$(call MSG_NOTHING)
+ endif
+endif
 
 
@@ -3592,8 +3547,5 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - done passes)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, done passes)
 endif
 
@@ -3668,13 +3620,13 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_FOOTER_END := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_FOOTER_END), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_FOOTER_END), $(_KBUILD_TS_PREV)) - end of footer.kmk)
- $(info prof: footer.kmk: $(int-sub $(_KBUILD_TS_FOOTER_END), $(_KBUILD_TS_FOOTER_START)))
- $(info stat: $(make-stats ))
- $(info prof: ALL=$(words $(_ALL_TARGETS)) BLDPROGS=$(words $(_ALL_BLDPROGS)) LIBRARIES=$(words $(_ALL_LIBRARIES)) IMPORT_LIBS=$(words $(IMPORT_LIBS)) DLLS=$(words $(DLLS)) PROGRAMS=$(words $(_ALL_PROGRAMS)) )
- $(info prof: SYSMODS=$(words $(_ALL_SYSMODS)) OTHERS=$(words $(_ALL_OTHERS)) INSTALLS=$(words $(_ALL_INSTALLS)) FETCHES=$(words $(_ALL_FETCHES)) PACKING=$(words $(_PACKING)) TESTING=$(words $(TESTING)) )
- $(info prof: DIRS=$(words $(_DIR_ALL)) TOOLS=$(words $(_TOOLS)) SDKS=$(words $(_SDKS)) USES=$(words $(_USES)) OUT_FILES=$(words $(_OUT_FILES)) OBJS=$(words $(_OBJS)) CLEAN_FILES=$(words $(CLEAN_FILES) $(OTHER_CLEAN)) )
- $(info prof: DEPFILES_INCLUDED=$(words $(_DEPFILES_INCLUDED)) DEPFILES=$(words $(_DEPFILES)) MAKEFILES=$(words $(MAKEFILE_LIST)) )
- _KBUILD_TS_PREV := $(_KBUILD_TS_FOOTER_END)
+ $(evalcall def_profile_self, end of footer.kmk)
+ _KBUILD_TS_FOOTER_END := $(_KBUILD_TS_PREV)
+
+ ifneq ($(KBUILD_PROFILE_SELF),0)
+  $(info prof: ALL=$(words $(_ALL_TARGETS)) BLDPROGS=$(words $(_ALL_BLDPROGS)) LIBRARIES=$(words $(_ALL_LIBRARIES)) IMPORT_LIBS=$(words $(IMPORT_LIBS)) DLLS=$(words $(DLLS)) PROGRAMS=$(words $(_ALL_PROGRAMS)) )
+  $(info prof: SYSMODS=$(words $(_ALL_SYSMODS)) OTHERS=$(words $(_ALL_OTHERS)) INSTALLS=$(words $(_ALL_INSTALLS)) FETCHES=$(words $(_ALL_FETCHES)) PACKING=$(words $(_PACKING)) TESTING=$(words $(TESTING)) )
+  $(info prof: DIRS=$(words $(_DIR_ALL)) TOOLS=$(words $(_TOOLS)) SDKS=$(words $(_SDKS)) USES=$(words $(_USES)) OUT_FILES=$(words $(_OUT_FILES)) OBJS=$(words $(_OBJS)) CLEAN_FILES=$(words $(CLEAN_FILES) $(OTHER_CLEAN)) )
+  $(info prof: DEPFILES_INCLUDED=$(words $(_DEPFILES_INCLUDED)) DEPFILES=$(words $(_DEPFILES)) MAKEFILES=$(words $(MAKEFILE_LIST)) )
+ endif
 endif
 
Index: /trunk/kBuild/header.kmk
===================================================================
--- /trunk/kBuild/header.kmk	(revision 2007)
+++ /trunk/kBuild/header.kmk	(revision 2008)
@@ -36,8 +36,23 @@
 ifdef KBUILD_PROFILE_SELF
  _KBUILD_TS_HEADER_START := $(nanots ) # just a dummy warm up query
- $(info prof: since start - since previous - event description)
- $(info stat: $(make-stats ))
+ $(info prof: since start - since previous -- event description)
+ ifeq ($(KBUILD_PROFILE_SELF),2)
+  $(info stat: $(make-stats ))
+ endif
  _KBUILD_TS_HEADER_START := $(nanots )
  _KBUILD_TS_PREV := $(_KBUILD_TS_HEADER_START)
+
+ _KBUILD_FMT_ELAPSED_EX = $(int-div $(int-add $(int-sub $1, $2),500000),1000000)ms
+ _KBUILD_FMT_ELAPSED = $(call _KBUILD_FMT_ELAPSED_EX,$(_KBUILD_TS_NOW),$1)
+
+define def_profile_self
+ _KBUILD_TS_NOW := $(nanots )
+ $(info prof: $(call _KBUILD_FMT_ELAPSED,$(_KBUILD_TS_HEADER_START)) - $(call _KBUILD_FMT_ELAPSED, $(_KBUILD_TS_PREV)) -- $(strip $1))
+ ifeq ($(KBUILD_PROFILE_SELF),2)
+  $(info stat: $(make-stats ))
+ endif
+ _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+endef
+
 endif
 
@@ -1006,15 +1021,7 @@
 # Include the config.kmk we found file (or the default one).
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - including $(_CFGFILE))
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
-
+ $(evalcall def_profile_self, including $(_CFGFILE))
  include $(_CFGFILE)
-
- _KBUILD_TS_NOW := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_NOW), $(_KBUILD_TS_PREV)) - included $(_CFGFILE))
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_NOW)
+ $(evalcall def_profile_self, included $(_CFGFILE))
 else
  include $(_CFGFILE)
@@ -1204,8 +1211,6 @@
 
 ifdef KBUILD_PROFILE_SELF
- _KBUILD_TS_HEADER_END := $(nanots )
- $(info prof: $(int-sub $(_KBUILD_TS_HEADER_END), $(_KBUILD_TS_HEADER_START)) - $(int-sub $(_KBUILD_TS_HEADER_END), $(_KBUILD_TS_PREV)) - end of header.kmk)
- $(info stat: $(make-stats ))
- _KBUILD_TS_PREV := $(_KBUILD_TS_HEADER_END)
+ $(evalcall def_profile_self, end of header.kmk)
+ _KBUILD_TS_HEADER_END := $(_KBUILD_TS_PREV)
 endif