BaseTools: report build time measured by module of EDKII Build

In the build report, we add AutoGen Phase, Make Phase and GenFds Phase
time duration in the Platform Summary section, and we also add a item
in Module section to display module and library's build time.

Cc: Liming Gao <liming.gao@intel.com>
Contributed-under: TianoCore Contribution Agreement 1.1
Signed-off-by: Yonghong Zhu <yonghong.zhu@intel.com>
Reviewed-by: Liming Gao <liming.gao@intel.com>

diff --git a/BaseTools/Source/Python/AutoGen/AutoGen.py b/BaseTools/Source/Python/AutoGen/AutoGen.py
index 1a8c0d9d31afa348fca185a52ea7c8302be89e8b..6bbfc8774fedf0c27fd98d434d5d44f7c3b19731 100644 (file)
--- a/BaseTools/Source/Python/AutoGen/AutoGen.py
+++ b/BaseTools/Source/Python/AutoGen/AutoGen.py
@@ -2695,6 +2695,7 @@ class ModuleAutoGen(AutoGen):
 \r
         self.BuildDatabase = self.Workspace.BuildDatabase\r
         self.BuildRuleOrder = None\r
+        self.BuildTime      = 0\r
 \r
         self._Module          = None\r
         self._Name            = None\r

diff --git a/BaseTools/Source/Python/build/BuildReport.py b/BaseTools/Source/Python/build/BuildReport.py
index 38ee26df70321baa85cd0f326fbea873797dc995..f0e9093c7abd9b349029536a2f93632a6355e02f 100644 (file)
--- a/BaseTools/Source/Python/build/BuildReport.py
+++ b/BaseTools/Source/Python/build/BuildReport.py
@@ -307,7 +307,11 @@ class LibraryReport(object):
             LibConstructorList = Lib.ConstructorList\r
             LibDesstructorList = Lib.DestructorList\r
             LibDepexList = Lib.DepexExpression[M.Arch, M.ModuleType]\r
-            self.LibraryList.append((LibInfPath, LibClassList, LibConstructorList, LibDesstructorList, LibDepexList))\r
+            for LibAutoGen in M.LibraryAutoGenList:\r
+                if LibInfPath == LibAutoGen.MetaFile.Path:\r
+                    LibTime = LibAutoGen.BuildTime\r
+                    break\r
+            self.LibraryList.append((LibInfPath, LibClassList, LibConstructorList, LibDesstructorList, LibDepexList, LibTime))\r
 \r
     ##\r
     # Generate report for module library information\r
@@ -344,6 +348,8 @@ class LibraryReport(object):
                     LibDepex = " ".join(LibraryItem[4])\r
                     if LibDepex:\r
                         EdkIILibInfo += " Depex = " + LibDepex\r
+                    if LibraryItem[5]:\r
+                        EdkIILibInfo += " Time = " + LibraryItem[5]\r
                     if EdkIILibInfo:\r
                         FileWrite(File, "{%s: %s}" % (LibClass, EdkIILibInfo))\r
                     else:\r
@@ -553,6 +559,7 @@ class ModuleReport(object):
         self.PciDeviceId = M.Module.Defines.get("PCI_DEVICE_ID", "")\r
         self.PciVendorId = M.Module.Defines.get("PCI_VENDOR_ID", "")\r
         self.PciClassCode = M.Module.Defines.get("PCI_CLASS_CODE", "")\r
+        self.BuildTime = M.BuildTime\r
 \r
         self._BuildDir = M.BuildDir\r
         self.ModulePcdSet = {}\r
@@ -648,6 +655,8 @@ class ModuleReport(object):
             FileWrite(File, "SHA1 HASH:            %s *%s" % (self.Hash, self.ModuleName + ".efi"))\r
         if self.BuildTimeStamp:\r
             FileWrite(File, "Build Time Stamp:     %s" % self.BuildTimeStamp)\r
+        if self.BuildTime:\r
+            FileWrite(File, "Module Build Time:    %s" % self.BuildTime)\r
         if self.DriverType:\r
             FileWrite(File, "Driver Type:          %s" % self.DriverType)\r
         if self.UefiSpecVersion:\r
@@ -1696,9 +1705,12 @@ class PlatformReport(object):
     # @param self            The object pointer\r
     # @param File            The file object for report\r
     # @param BuildDuration   The total time to build the modules\r
+    # @param AutoGenTime     The total time of AutoGen Phase\r
+    # @param MakeTime        The total time of Make Phase\r
+    # @param GenFdsTime      The total time of GenFds Phase\r
     # @param ReportType      The kind of report items in the final report file\r
     #\r
-    def GenerateReport(self, File, BuildDuration, ReportType):\r
+    def GenerateReport(self, File, BuildDuration, AutoGenTime, MakeTime, GenFdsTime, ReportType):\r
         FileWrite(File, "Platform Summary")\r
         FileWrite(File, "Platform Name:        %s" % self.PlatformName)\r
         FileWrite(File, "Platform DSC Path:    %s" % self.PlatformDscPath)\r
@@ -1708,6 +1720,12 @@ class PlatformReport(object):
         FileWrite(File, "Output Path:          %s" % self.OutputPath)\r
         FileWrite(File, "Build Environment:    %s" % self.BuildEnvironment)\r
         FileWrite(File, "Build Duration:       %s" % BuildDuration)\r
+        if AutoGenTime:\r
+            FileWrite(File, "AutoGen Duration:     %s" % AutoGenTime)\r
+        if MakeTime:\r
+            FileWrite(File, "Make Duration:        %s" % MakeTime)\r
+        if GenFdsTime:\r
+            FileWrite(File, "GenFds Duration:      %s" % GenFdsTime)\r
         FileWrite(File, "Report Content:       %s" % ", ".join(ReportType))\r
 \r
         if GlobalData.MixedPcd:\r
@@ -1782,13 +1800,16 @@ class BuildReport(object):
     #\r
     # @param self            The object pointer\r
     # @param BuildDuration   The total time to build the modules\r
+    # @param AutoGenTime     The total time of AutoGen phase\r
+    # @param MakeTime        The total time of Make phase\r
+    # @param GenFdsTime      The total time of GenFds phase\r
     #\r
-    def GenerateReport(self, BuildDuration):\r
+    def GenerateReport(self, BuildDuration, AutoGenTime, MakeTime, GenFdsTime):\r
         if self.ReportFile:\r
             try:\r
                 File = StringIO('')\r
                 for (Wa, MaList) in self.ReportList:\r
-                    PlatformReport(Wa, MaList, self.ReportType).GenerateReport(File, BuildDuration, self.ReportType)\r
+                    PlatformReport(Wa, MaList, self.ReportType).GenerateReport(File, BuildDuration, AutoGenTime, MakeTime, GenFdsTime, self.ReportType)\r
                 Content = FileLinesSplit(File.getvalue(), gLineMaxLength)\r
                 SaveFileOnChange(self.ReportFile, Content, True)\r
                 EdkLogger.quiet("Build report can be found at %s" % os.path.abspath(self.ReportFile))\r

diff --git a/BaseTools/Source/Python/build/build.py b/BaseTools/Source/Python/build/build.py
index bb70a5830c22d601fd470e6e6e482f0090bdef9b..8275f1b5b9d99e1a1af75a7ca0518d9b59592701 100644 (file)
--- a/BaseTools/Source/Python/build/build.py
+++ b/BaseTools/Source/Python/build/build.py
@@ -257,6 +257,7 @@ def ReadMessage(From, To, ExitFlag):
 # @param  WorkingDir            The directory in which the program will be running\r
 #\r
 def LaunchCommand(Command, WorkingDir):\r
+    BeginTime = time.time()\r
     # if working directory doesn't exist, Popen() will raise an exception\r
     if not os.path.isdir(WorkingDir):\r
         EdkLogger.error("build", FILE_NOT_FOUND, ExtraData=WorkingDir)\r
@@ -321,6 +322,7 @@ def LaunchCommand(Command, WorkingDir):
             EdkLogger.info(RespContent)\r
 \r
         EdkLogger.error("build", COMMAND_FAILURE, ExtraData="%s [%s]" % (Command, WorkingDir))\r
+    return "%dms" % (int(round((time.time() - BeginTime) * 1000)))\r
 \r
 ## The smallest unit that can be built in multi-thread build mode\r
 #\r
@@ -665,7 +667,7 @@ class BuildTask:
     #\r
     def _CommandThread(self, Command, WorkingDir):\r
         try:\r
-            LaunchCommand(Command, WorkingDir)\r
+            self.BuildItem.BuildObject.BuildTime = LaunchCommand(Command, WorkingDir)\r
             self.CompleteFlag = True\r
         except:\r
             #\r
@@ -763,6 +765,9 @@ class Build():
         self.BuildReport    = BuildReport(BuildOptions.ReportFile, BuildOptions.ReportType)\r
         self.TargetTxt      = TargetTxtClassObject()\r
         self.ToolDef        = ToolDefClassObject()\r
+        self.AutoGenTime    = 0\r
+        self.MakeTime       = 0\r
+        self.GenFdsTime     = 0\r
         GlobalData.BuildOptionPcd     = BuildOptions.OptionPcd\r
         #Set global flag for build mode\r
         GlobalData.gIgnoreSource = BuildOptions.IgnoreSources\r
@@ -1339,7 +1344,7 @@ class Build():
         if BuildModule:\r
             if Target != 'fds':\r
                 BuildCommand = BuildCommand + [Target]\r
-            LaunchCommand(BuildCommand, AutoGenObject.MakeFileDir)\r
+            AutoGenObject.BuildTime = LaunchCommand(BuildCommand, AutoGenObject.MakeFileDir)\r
             self.CreateAsBuiltInf()\r
             return True\r
 \r
@@ -1760,6 +1765,7 @@ class Build():
             GlobalData.gGlobalDefines['TARGET'] = BuildTarget\r
             index = 0\r
             for ToolChain in self.ToolChainList:\r
+                WorkspaceAutoGenTime = time.time()\r
                 GlobalData.gGlobalDefines['TOOLCHAIN'] = ToolChain\r
                 GlobalData.gGlobalDefines['TOOL_CHAIN_TAG'] = ToolChain\r
                 GlobalData.gGlobalDefines['FAMILY'] = self.ToolChainFamily[index]\r
@@ -1791,7 +1797,11 @@ class Build():
                 Wa.CreateMakeFile(False)\r
                 self.Progress.Stop("done!")\r
                 MaList = []\r
+                ExitFlag = threading.Event()\r
+                ExitFlag.clear()\r
+                self.AutoGenTime += int(round((time.time() - WorkspaceAutoGenTime)))\r
                 for Arch in Wa.ArchList:\r
+                    AutoGenStart = time.time()\r
                     GlobalData.gGlobalDefines['ARCH'] = Arch\r
                     Pa = PlatformAutoGen(Wa, self.PlatformFile, BuildTarget, ToolChain, Arch)\r
                     for Module in Pa.Platform.Modules:\r
@@ -1800,8 +1810,35 @@ class Build():
                             if Ma == None: continue\r
                             MaList.append(Ma)\r
                             self.BuildModules.append(Ma)\r
-                            if not Ma.IsBinaryModule:\r
-                                self._Build(self.Target, Ma, BuildModule=True)\r
+                    self.AutoGenTime += int(round((time.time() - AutoGenStart)))\r
+                    MakeStart = time.time()\r
+                    for Ma in self.BuildModules:\r
+                        if not Ma.IsBinaryModule:\r
+                            Bt = BuildTask.New(ModuleMakeUnit(Ma, self.Target))\r
+                        # Break build if any build thread has error\r
+                        if BuildTask.HasError():\r
+                            # we need a full version of makefile for platform\r
+                            ExitFlag.set()\r
+                            BuildTask.WaitForComplete()\r
+                            Pa.CreateMakeFile(False)\r
+                            EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule)\r
+                        # Start task scheduler\r
+                        if not BuildTask.IsOnGoing():\r
+                            BuildTask.StartScheduler(self.ThreadNumber, ExitFlag)\r
+\r
+                    # in case there's an interruption. we need a full version of makefile for platform\r
+                    Pa.CreateMakeFile(False)\r
+                    if BuildTask.HasError():\r
+                        EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule)\r
+                    self.MakeTime += int(round((time.time() - MakeStart)))\r
+\r
+                MakeContiue = time.time()\r
+                ExitFlag.set()\r
+                BuildTask.WaitForComplete()\r
+                self.CreateAsBuiltInf()\r
+                self.MakeTime += int(round((time.time() - MakeContiue)))\r
+                if BuildTask.HasError():\r
+                    EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule)\r
 \r
                 self.BuildReport.AddPlatformReport(Wa, MaList)\r
                 if MaList == []:\r
@@ -1842,7 +1879,9 @@ class Build():
                     #\r
                     # create FDS again for the updated EFI image\r
                     #\r
+                    GenFdsStart = time.time()\r
                     self._Build("fds", Wa)\r
+                    self.GenFdsTime += int(round((time.time() - GenFdsStart)))\r
                     #\r
                     # Create MAP file for all platform FVs after GenFds.\r
                     #\r
@@ -1860,6 +1899,7 @@ class Build():
             GlobalData.gGlobalDefines['TARGET'] = BuildTarget\r
             index = 0\r
             for ToolChain in self.ToolChainList:\r
+                WorkspaceAutoGenTime = time.time()\r
                 GlobalData.gGlobalDefines['TOOLCHAIN'] = ToolChain\r
                 GlobalData.gGlobalDefines['TOOL_CHAIN_TAG'] = ToolChain\r
                 GlobalData.gGlobalDefines['FAMILY'] = self.ToolChainFamily[index]\r
@@ -1889,7 +1929,9 @@ class Build():
                 # multi-thread exit flag\r
                 ExitFlag = threading.Event()\r
                 ExitFlag.clear()\r
+                self.AutoGenTime += int(round((time.time() - WorkspaceAutoGenTime)))\r
                 for Arch in Wa.ArchList:\r
+                    AutoGenStart = time.time()\r
                     GlobalData.gGlobalDefines['ARCH'] = Arch\r
                     Pa = PlatformAutoGen(Wa, self.PlatformFile, BuildTarget, ToolChain, Arch)\r
                     if Pa == None:\r
@@ -1924,7 +1966,8 @@ class Build():
                                 continue\r
                         self.BuildModules.append(Ma)\r
                     self.Progress.Stop("done!")\r
-\r
+                    self.AutoGenTime += int(round((time.time() - AutoGenStart)))\r
+                    MakeStart = time.time()\r
                     for Ma in self.BuildModules:\r
                         # Generate build task for the module\r
                         if not Ma.IsBinaryModule:\r
@@ -1944,7 +1987,9 @@ class Build():
                     Pa.CreateMakeFile(False)\r
                     if BuildTask.HasError():\r
                         EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule)\r
+                    self.MakeTime += int(round((time.time() - MakeStart)))\r
 \r
+                MakeContiue = time.time()\r
                 #\r
                 # Save temp tables to a TmpTableDict.\r
                 #\r
@@ -1960,7 +2005,7 @@ class Build():
                 ExitFlag.set()\r
                 BuildTask.WaitForComplete()\r
                 self.CreateAsBuiltInf()\r
-\r
+                self.MakeTime += int(round((time.time() - MakeContiue)))\r
                 #\r
                 # Check for build error, and raise exception if one\r
                 # has been signaled.\r
@@ -1997,12 +2042,14 @@ class Build():
                         #\r
                         # Generate FD image if there's a FDF file found\r
                         #\r
+                        GenFdsStart = time.time()\r
                         LaunchCommand(Wa.GenFdsCommand, os.getcwd())\r
 \r
                         #\r
                         # Create MAP file for all platform FVs after GenFds.\r
                         #\r
                         self._CollectFvMapBuffer(MapBuffer, Wa, ModuleList)\r
+                        self.GenFdsTime += int(round((time.time() - GenFdsStart)))\r
                     #\r
                     # Save MAP buffer into MAP file.\r
                     #\r
@@ -2151,6 +2198,18 @@ def SingleCheckCallback(option, opt_str, value, parser):
     else:\r
         parser.error("Option %s only allows one instance in command line!" % option)\r
 \r
+def LogBuildTime(Time):\r
+    if Time:\r
+        TimeDurStr = ''\r
+        TimeDur = time.gmtime(Time)\r
+        if TimeDur.tm_yday > 1:\r
+            TimeDurStr = time.strftime("%H:%M:%S", TimeDur) + ", %d day(s)" % (TimeDur.tm_yday - 1)\r
+        else:\r
+            TimeDurStr = time.strftime("%H:%M:%S", TimeDur)\r
+        return TimeDurStr\r
+    else:\r
+        return None\r
+\r
 ## Parse command line options\r
 #\r
 # Using standard Python module optparse to parse command line option of this tool.\r
@@ -2407,7 +2466,7 @@ def Main():
         BuildDurationStr = time.strftime("%H:%M:%S", BuildDuration)\r
     if MyBuild != None:\r
         if not BuildError:\r
-            MyBuild.BuildReport.GenerateReport(BuildDurationStr)\r
+            MyBuild.BuildReport.GenerateReport(BuildDurationStr, LogBuildTime(MyBuild.AutoGenTime), LogBuildTime(MyBuild.MakeTime), LogBuildTime(MyBuild.GenFdsTime))\r
         MyBuild.Db.Close()\r
     EdkLogger.SetLevel(EdkLogger.QUIET)\r
     EdkLogger.quiet("\n- %s -" % Conclusion)\r