From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mga11.intel.com (mga11.intel.com [192.55.52.93]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by ml01.01.org (Postfix) with ESMTPS id 67D2F2095BB65 for ; Wed, 20 Sep 2017 22:48:47 -0700 (PDT) Received: from fmsmga005.fm.intel.com ([10.253.24.32]) by fmsmga102.fm.intel.com with ESMTP/TLS/DHE-RSA-AES256-GCM-SHA384; 20 Sep 2017 22:51:51 -0700 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.42,423,1500966000"; d="scan'208";a="153808801" Received: from shwdeopenpsi168.ccr.corp.intel.com ([10.239.158.121]) by fmsmga005.fm.intel.com with ESMTP; 20 Sep 2017 22:51:50 -0700 From: Yonghong Zhu To: edk2-devel@lists.01.org Cc: Liming Gao Date: Thu, 21 Sep 2017 13:51:46 +0800 Message-Id: <1505973106-19164-1-git-send-email-yonghong.zhu@intel.com> X-Mailer: git-send-email 2.6.1.windows.1 Subject: [Patch] BaseTools: report build time measured by module of EDKII Build X-BeenThere: edk2-devel@lists.01.org X-Mailman-Version: 2.1.22 Precedence: list List-Id: EDK II Development List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 21 Sep 2017 05:48:47 -0000 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 Contributed-under: TianoCore Contribution Agreement 1.1 Signed-off-by: Yonghong Zhu --- BaseTools/Source/Python/AutoGen/AutoGen.py | 1 + BaseTools/Source/Python/build/BuildReport.py | 29 +++++++++-- BaseTools/Source/Python/build/build.py | 73 +++++++++++++++++++++++++--- 3 files changed, 92 insertions(+), 11 deletions(-) diff --git a/BaseTools/Source/Python/AutoGen/AutoGen.py b/BaseTools/Source/Python/AutoGen/AutoGen.py index 1a8c0d9..6bbfc87 100644 --- a/BaseTools/Source/Python/AutoGen/AutoGen.py +++ b/BaseTools/Source/Python/AutoGen/AutoGen.py @@ -2693,10 +2693,11 @@ class ModuleAutoGen(AutoGen): self.IsAsBuiltInfCreated = False self.DepexGenerated = False self.BuildDatabase = self.Workspace.BuildDatabase self.BuildRuleOrder = None + self.BuildTime = 0 self._Module = None self._Name = None self._Guid = None self._Version = None diff --git a/BaseTools/Source/Python/build/BuildReport.py b/BaseTools/Source/Python/build/BuildReport.py index 38ee26d..f0e9093 100644 --- a/BaseTools/Source/Python/build/BuildReport.py +++ b/BaseTools/Source/Python/build/BuildReport.py @@ -305,11 +305,15 @@ class LibraryReport(object): LibInfPath = str(Lib) LibClassList = Lib.LibraryClass[0].LibraryClass LibConstructorList = Lib.ConstructorList LibDesstructorList = Lib.DestructorList LibDepexList = Lib.DepexExpression[M.Arch, M.ModuleType] - self.LibraryList.append((LibInfPath, LibClassList, LibConstructorList, LibDesstructorList, LibDepexList)) + for LibAutoGen in M.LibraryAutoGenList: + if LibInfPath == LibAutoGen.MetaFile.Path: + LibTime = LibAutoGen.BuildTime + break + self.LibraryList.append((LibInfPath, LibClassList, LibConstructorList, LibDesstructorList, LibDepexList, LibTime)) ## # Generate report for module library information # # This function generates report for the module library. @@ -342,10 +346,12 @@ class LibraryReport(object): if LibDestructor: EdkIILibInfo += " D = " + LibDestructor LibDepex = " ".join(LibraryItem[4]) if LibDepex: EdkIILibInfo += " Depex = " + LibDepex + if LibraryItem[5]: + EdkIILibInfo += " Time = " + LibraryItem[5] if EdkIILibInfo: FileWrite(File, "{%s: %s}" % (LibClass, EdkIILibInfo)) else: FileWrite(File, "{%s}" % LibClass) @@ -551,10 +557,11 @@ class ModuleReport(object): self.UefiSpecVersion = M.Module.Specification.get("UEFI_SPECIFICATION_VERSION", "") self.PiSpecVersion = M.Module.Specification.get("PI_SPECIFICATION_VERSION", "") self.PciDeviceId = M.Module.Defines.get("PCI_DEVICE_ID", "") self.PciVendorId = M.Module.Defines.get("PCI_VENDOR_ID", "") self.PciClassCode = M.Module.Defines.get("PCI_CLASS_CODE", "") + self.BuildTime = M.BuildTime self._BuildDir = M.BuildDir self.ModulePcdSet = {} if "PCD" in ReportType: # @@ -646,10 +653,12 @@ class ModuleReport(object): FileWrite(File, "Size: 0x%X (%.2fK)" % (self.Size, self.Size / 1024.0)) if self.Hash: FileWrite(File, "SHA1 HASH: %s *%s" % (self.Hash, self.ModuleName + ".efi")) if self.BuildTimeStamp: FileWrite(File, "Build Time Stamp: %s" % self.BuildTimeStamp) + if self.BuildTime: + FileWrite(File, "Module Build Time: %s" % self.BuildTime) if self.DriverType: FileWrite(File, "Driver Type: %s" % self.DriverType) if self.UefiSpecVersion: FileWrite(File, "UEFI Spec Version: %s" % self.UefiSpecVersion) if self.PiSpecVersion: @@ -1694,22 +1703,31 @@ class PlatformReport(object): # module list sections. # # @param self The object pointer # @param File The file object for report # @param BuildDuration The total time to build the modules + # @param AutoGenTime The total time of AutoGen Phase + # @param MakeTime The total time of Make Phase + # @param GenFdsTime The total time of GenFds Phase # @param ReportType The kind of report items in the final report file # - def GenerateReport(self, File, BuildDuration, ReportType): + def GenerateReport(self, File, BuildDuration, AutoGenTime, MakeTime, GenFdsTime, ReportType): FileWrite(File, "Platform Summary") FileWrite(File, "Platform Name: %s" % self.PlatformName) FileWrite(File, "Platform DSC Path: %s" % self.PlatformDscPath) FileWrite(File, "Architectures: %s" % self.Architectures) FileWrite(File, "Tool Chain: %s" % self.ToolChain) FileWrite(File, "Target: %s" % self.Target) FileWrite(File, "Output Path: %s" % self.OutputPath) FileWrite(File, "Build Environment: %s" % self.BuildEnvironment) FileWrite(File, "Build Duration: %s" % BuildDuration) + if AutoGenTime: + FileWrite(File, "AutoGen Duration: %s" % AutoGenTime) + if MakeTime: + FileWrite(File, "Make Duration: %s" % MakeTime) + if GenFdsTime: + FileWrite(File, "GenFds Duration: %s" % GenFdsTime) FileWrite(File, "Report Content: %s" % ", ".join(ReportType)) if GlobalData.MixedPcd: FileWrite(File, gSectionStart) FileWrite(File, "The following PCDs use different access methods:") @@ -1780,17 +1798,20 @@ class BuildReport(object): # This function generates platform build report. It invokes GenerateReport() # method for every platform report in the list. # # @param self The object pointer # @param BuildDuration The total time to build the modules + # @param AutoGenTime The total time of AutoGen phase + # @param MakeTime The total time of Make phase + # @param GenFdsTime The total time of GenFds phase # - def GenerateReport(self, BuildDuration): + def GenerateReport(self, BuildDuration, AutoGenTime, MakeTime, GenFdsTime): if self.ReportFile: try: File = StringIO('') for (Wa, MaList) in self.ReportList: - PlatformReport(Wa, MaList, self.ReportType).GenerateReport(File, BuildDuration, self.ReportType) + PlatformReport(Wa, MaList, self.ReportType).GenerateReport(File, BuildDuration, AutoGenTime, MakeTime, GenFdsTime, self.ReportType) Content = FileLinesSplit(File.getvalue(), gLineMaxLength) SaveFileOnChange(self.ReportFile, Content, True) EdkLogger.quiet("Build report can be found at %s" % os.path.abspath(self.ReportFile)) except IOError: EdkLogger.error(None, FILE_WRITE_FAILURE, ExtraData=self.ReportFile) diff --git a/BaseTools/Source/Python/build/build.py b/BaseTools/Source/Python/build/build.py index bb70a58..8275f1b 100644 --- a/BaseTools/Source/Python/build/build.py +++ b/BaseTools/Source/Python/build/build.py @@ -255,10 +255,11 @@ def ReadMessage(From, To, ExitFlag): # # @param Command A list or string containing the call of the program # @param WorkingDir The directory in which the program will be running # def LaunchCommand(Command, WorkingDir): + BeginTime = time.time() # if working directory doesn't exist, Popen() will raise an exception if not os.path.isdir(WorkingDir): EdkLogger.error("build", FILE_NOT_FOUND, ExtraData=WorkingDir) # Command is used as the first Argument in following Popen(). @@ -319,10 +320,11 @@ def LaunchCommand(Command, WorkingDir): RespContent = f.read() f.close() EdkLogger.info(RespContent) EdkLogger.error("build", COMMAND_FAILURE, ExtraData="%s [%s]" % (Command, WorkingDir)) + return "%dms" % (int(round((time.time() - BeginTime) * 1000))) ## The smallest unit that can be built in multi-thread build mode # # This is the base class of build unit. The "Obj" parameter must provide # __str__(), __eq__() and __hash__() methods. Otherwise there could be build units @@ -663,11 +665,11 @@ class BuildTask: # @param Command A list or string contains the call of the command # @param WorkingDir The directory in which the program will be running # def _CommandThread(self, Command, WorkingDir): try: - LaunchCommand(Command, WorkingDir) + self.BuildItem.BuildObject.BuildTime = LaunchCommand(Command, WorkingDir) self.CompleteFlag = True except: # # TRICK: hide the output of threads left runing, so that the user can # catch the error message easily @@ -761,10 +763,13 @@ class Build(): self.ConfDirectory = BuildOptions.ConfDirectory self.SpawnMode = True self.BuildReport = BuildReport(BuildOptions.ReportFile, BuildOptions.ReportType) self.TargetTxt = TargetTxtClassObject() self.ToolDef = ToolDefClassObject() + self.AutoGenTime = 0 + self.MakeTime = 0 + self.GenFdsTime = 0 GlobalData.BuildOptionPcd = BuildOptions.OptionPcd #Set global flag for build mode GlobalData.gIgnoreSource = BuildOptions.IgnoreSources if self.ConfDirectory: @@ -1337,11 +1342,11 @@ class Build(): # build modules if BuildModule: if Target != 'fds': BuildCommand = BuildCommand + [Target] - LaunchCommand(BuildCommand, AutoGenObject.MakeFileDir) + AutoGenObject.BuildTime = LaunchCommand(BuildCommand, AutoGenObject.MakeFileDir) self.CreateAsBuiltInf() return True # genfds if Target == 'fds': @@ -1758,10 +1763,11 @@ class Build(): def _BuildModule(self): for BuildTarget in self.BuildTargetList: GlobalData.gGlobalDefines['TARGET'] = BuildTarget index = 0 for ToolChain in self.ToolChainList: + WorkspaceAutoGenTime = time.time() GlobalData.gGlobalDefines['TOOLCHAIN'] = ToolChain GlobalData.gGlobalDefines['TOOL_CHAIN_TAG'] = ToolChain GlobalData.gGlobalDefines['FAMILY'] = self.ToolChainFamily[index] index += 1 # @@ -1789,21 +1795,52 @@ class Build(): self.Fdf = Wa.FdfFile self.LoadFixAddress = Wa.Platform.LoadFixAddress Wa.CreateMakeFile(False) self.Progress.Stop("done!") MaList = [] + ExitFlag = threading.Event() + ExitFlag.clear() + self.AutoGenTime += int(round((time.time() - WorkspaceAutoGenTime))) for Arch in Wa.ArchList: + AutoGenStart = time.time() GlobalData.gGlobalDefines['ARCH'] = Arch Pa = PlatformAutoGen(Wa, self.PlatformFile, BuildTarget, ToolChain, Arch) for Module in Pa.Platform.Modules: if self.ModuleFile.Dir == Module.Dir and self.ModuleFile.File == Module.File: Ma = ModuleAutoGen(Wa, Module, BuildTarget, ToolChain, Arch, self.PlatformFile) if Ma == None: continue MaList.append(Ma) self.BuildModules.append(Ma) - if not Ma.IsBinaryModule: - self._Build(self.Target, Ma, BuildModule=True) + self.AutoGenTime += int(round((time.time() - AutoGenStart))) + MakeStart = time.time() + for Ma in self.BuildModules: + if not Ma.IsBinaryModule: + Bt = BuildTask.New(ModuleMakeUnit(Ma, self.Target)) + # Break build if any build thread has error + if BuildTask.HasError(): + # we need a full version of makefile for platform + ExitFlag.set() + BuildTask.WaitForComplete() + Pa.CreateMakeFile(False) + EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule) + # Start task scheduler + if not BuildTask.IsOnGoing(): + BuildTask.StartScheduler(self.ThreadNumber, ExitFlag) + + # in case there's an interruption. we need a full version of makefile for platform + Pa.CreateMakeFile(False) + if BuildTask.HasError(): + EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule) + self.MakeTime += int(round((time.time() - MakeStart))) + + MakeContiue = time.time() + ExitFlag.set() + BuildTask.WaitForComplete() + self.CreateAsBuiltInf() + self.MakeTime += int(round((time.time() - MakeContiue))) + if BuildTask.HasError(): + EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule) self.BuildReport.AddPlatformReport(Wa, MaList) if MaList == []: EdkLogger.error( 'build', @@ -1840,11 +1877,13 @@ class Build(): # self._CollectModuleMapBuffer(MapBuffer, ModuleList) # # create FDS again for the updated EFI image # + GenFdsStart = time.time() self._Build("fds", Wa) + self.GenFdsTime += int(round((time.time() - GenFdsStart))) # # Create MAP file for all platform FVs after GenFds. # self._CollectFvMapBuffer(MapBuffer, Wa, ModuleList) # @@ -1858,10 +1897,11 @@ class Build(): SaveFileOnChange(self.PlatformBuildPath, '# DO NOT EDIT \n# FILE auto-generated\n', False) for BuildTarget in self.BuildTargetList: GlobalData.gGlobalDefines['TARGET'] = BuildTarget index = 0 for ToolChain in self.ToolChainList: + WorkspaceAutoGenTime = time.time() GlobalData.gGlobalDefines['TOOLCHAIN'] = ToolChain GlobalData.gGlobalDefines['TOOL_CHAIN_TAG'] = ToolChain GlobalData.gGlobalDefines['FAMILY'] = self.ToolChainFamily[index] index += 1 Wa = WorkspaceAutoGen( @@ -1887,11 +1927,13 @@ class Build(): Wa.CreateMakeFile(False) # multi-thread exit flag ExitFlag = threading.Event() ExitFlag.clear() + self.AutoGenTime += int(round((time.time() - WorkspaceAutoGenTime))) for Arch in Wa.ArchList: + AutoGenStart = time.time() GlobalData.gGlobalDefines['ARCH'] = Arch Pa = PlatformAutoGen(Wa, self.PlatformFile, BuildTarget, ToolChain, Arch) if Pa == None: continue ModuleList = [] @@ -1922,11 +1964,12 @@ class Build(): Ma.CreateMakeFile(True) if self.Target == "genmake": continue self.BuildModules.append(Ma) self.Progress.Stop("done!") - + self.AutoGenTime += int(round((time.time() - AutoGenStart))) + MakeStart = time.time() for Ma in self.BuildModules: # Generate build task for the module if not Ma.IsBinaryModule: Bt = BuildTask.New(ModuleMakeUnit(Ma, self.Target)) # Break build if any build thread has error @@ -1942,11 +1985,13 @@ class Build(): # in case there's an interruption. we need a full version of makefile for platform Pa.CreateMakeFile(False) if BuildTask.HasError(): EdkLogger.error("build", BUILD_ERROR, "Failed to build module", ExtraData=GlobalData.gBuildingModule) + self.MakeTime += int(round((time.time() - MakeStart))) + MakeContiue = time.time() # # Save temp tables to a TmpTableDict. # for Key in Wa.BuildDatabase._CACHE_: if Wa.BuildDatabase._CACHE_[Key]._RawData and Wa.BuildDatabase._CACHE_[Key]._RawData._Table and Wa.BuildDatabase._CACHE_[Key]._RawData._Table.Table: @@ -1958,11 +2003,11 @@ class Build(): # to exit if all tasks are completed # ExitFlag.set() BuildTask.WaitForComplete() self.CreateAsBuiltInf() - + self.MakeTime += int(round((time.time() - MakeContiue))) # # Check for build error, and raise exception if one # has been signaled. # if BuildTask.HasError(): @@ -1995,16 +2040,18 @@ class Build(): if self.Fdf: # # Generate FD image if there's a FDF file found # + GenFdsStart = time.time() LaunchCommand(Wa.GenFdsCommand, os.getcwd()) # # Create MAP file for all platform FVs after GenFds. # self._CollectFvMapBuffer(MapBuffer, Wa, ModuleList) + self.GenFdsTime += int(round((time.time() - GenFdsStart))) # # Save MAP buffer into MAP file. # self._SaveMapFile(MapBuffer, Wa) @@ -2149,10 +2196,22 @@ def SingleCheckCallback(option, opt_str, value, parser): setattr(parser.values, option.dest, value) gParamCheck.append(option) else: parser.error("Option %s only allows one instance in command line!" % option) +def LogBuildTime(Time): + if Time: + TimeDurStr = '' + TimeDur = time.gmtime(Time) + if TimeDur.tm_yday > 1: + TimeDurStr = time.strftime("%H:%M:%S", TimeDur) + ", %d day(s)" % (TimeDur.tm_yday - 1) + else: + TimeDurStr = time.strftime("%H:%M:%S", TimeDur) + return TimeDurStr + else: + return None + ## Parse command line options # # Using standard Python module optparse to parse command line option of this tool. # # @retval Opt A optparse.Values object containing the parsed options @@ -2405,11 +2464,11 @@ def Main(): BuildDurationStr = time.strftime("%H:%M:%S", BuildDuration) + ", %d day(s)" % (BuildDuration.tm_yday - 1) else: BuildDurationStr = time.strftime("%H:%M:%S", BuildDuration) if MyBuild != None: if not BuildError: - MyBuild.BuildReport.GenerateReport(BuildDurationStr) + MyBuild.BuildReport.GenerateReport(BuildDurationStr, LogBuildTime(MyBuild.AutoGenTime), LogBuildTime(MyBuild.MakeTime), LogBuildTime(MyBuild.GenFdsTime)) MyBuild.Db.Close() EdkLogger.SetLevel(EdkLogger.QUIET) EdkLogger.quiet("\n- %s -" % Conclusion) EdkLogger.quiet(time.strftime("Build end time: %H:%M:%S, %b.%d %Y", time.localtime())) EdkLogger.quiet("Build total time: %s\n" % BuildDurationStr) -- 2.6.1.windows.1