From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mga09.intel.com (mga09.intel.com [134.134.136.24]) (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 D3ACB21E1B763 for ; Thu, 21 Sep 2017 01:02:47 -0700 (PDT) Received: from orsmga002.jf.intel.com ([10.7.209.21]) by orsmga102.jf.intel.com with ESMTP/TLS/DHE-RSA-AES256-GCM-SHA384; 21 Sep 2017 01:05:54 -0700 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.42,424,1500966000"; d="scan'208";a="137819729" Received: from fmsmsx104.amr.corp.intel.com ([10.18.124.202]) by orsmga002.jf.intel.com with ESMTP; 21 Sep 2017 01:05:53 -0700 Received: from shsmsx151.ccr.corp.intel.com (10.239.6.50) by fmsmsx104.amr.corp.intel.com (10.18.124.202) with Microsoft SMTP Server (TLS) id 14.3.319.2; Thu, 21 Sep 2017 01:05:51 -0700 Received: from shsmsx152.ccr.corp.intel.com ([169.254.6.93]) by SHSMSX151.ccr.corp.intel.com ([169.254.3.98]) with mapi id 14.03.0319.002; Thu, 21 Sep 2017 16:05:49 +0800 From: "Gao, Liming" To: "Zhu, Yonghong" , "edk2-devel@lists.01.org" Thread-Topic: [Patch] BaseTools: report build time measured by module of EDKII Build Thread-Index: AQHTMp3JSAY+crbFZUSI3IckqVBEKaK++5aw Date: Thu, 21 Sep 2017 08:05:49 +0000 Message-ID: <4A89E2EF3DFEDB4C8BFDE51014F606A14E15BAA0@SHSMSX152.ccr.corp.intel.com> References: <1505973106-19164-1-git-send-email-yonghong.zhu@intel.com> In-Reply-To: <1505973106-19164-1-git-send-email-yonghong.zhu@intel.com> Accept-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-originating-ip: [10.239.127.40] MIME-Version: 1.0 Subject: Re: [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 08:02:48 -0000 Content-Language: en-US Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable Reviewed-by: Liming Gao >-----Original Message----- >From: Zhu, Yonghong >Sent: Thursday, September 21, 2017 1:52 PM >To: edk2-devel@lists.01.org >Cc: Gao, Liming >Subject: [Patch] 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 >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 =3D False > self.DepexGenerated =3D False > > self.BuildDatabase =3D self.Workspace.BuildDatabase > self.BuildRuleOrder =3D None >+ self.BuildTime =3D 0 > > self._Module =3D None > self._Name =3D None > self._Guid =3D None > self._Version =3D 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 =3D str(Lib) > LibClassList =3D Lib.LibraryClass[0].LibraryClass > LibConstructorList =3D Lib.ConstructorList > LibDesstructorList =3D Lib.DestructorList > LibDepexList =3D Lib.DepexExpression[M.Arch, M.ModuleType] >- self.LibraryList.append((LibInfPath, LibClassList, LibConstru= ctorList, >LibDesstructorList, LibDepexList)) >+ for LibAutoGen in M.LibraryAutoGenList: >+ if LibInfPath =3D=3D LibAutoGen.MetaFile.Path: >+ LibTime =3D LibAutoGen.BuildTime >+ break >+ self.LibraryList.append((LibInfPath, LibClassList, LibConstru= ctorList, >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 +=3D " D =3D " + LibDestructor > LibDepex =3D " ".join(LibraryItem[4]) > if LibDepex: > EdkIILibInfo +=3D " Depex =3D " + LibDepex >+ if LibraryItem[5]: >+ EdkIILibInfo +=3D " Time =3D " + LibraryItem[5] > if EdkIILibInfo: > FileWrite(File, "{%s: %s}" % (LibClass, EdkIILibI= nfo)) > else: > FileWrite(File, "{%s}" % LibClass) > >@@ -551,10 +557,11 @@ class ModuleReport(object): > self.UefiSpecVersion =3D >M.Module.Specification.get("UEFI_SPECIFICATION_VERSION", "") > self.PiSpecVersion =3D >M.Module.Specification.get("PI_SPECIFICATION_VERSION", "") > self.PciDeviceId =3D M.Module.Defines.get("PCI_DEVICE_ID", "") > self.PciVendorId =3D M.Module.Defines.get("PCI_VENDOR_ID", "") > self.PciClassCode =3D M.Module.Defines.get("PCI_CLASS_CODE", "") >+ self.BuildTime =3D M.BuildTime > > self._BuildDir =3D M.BuildDir > self.ModulePcdSet =3D {} > 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.BuildTimeSt= amp) >+ 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.UefiSpecVer= sion) > 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.BuildEnvironmen= t) > 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 meth= ods:") >@@ -1780,17 +1798,20 @@ class BuildReport(object): > # This function generates platform build report. It invokes GenerateR= eport() > # 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 =3D StringIO('') > for (Wa, MaList) in self.ReportList: >- PlatformReport(Wa, MaList, self.ReportType).GenerateR= eport(File, >BuildDuration, self.ReportType) >+ PlatformReport(Wa, MaList, self.ReportType).GenerateR= eport(File, >BuildDuration, AutoGenTime, MakeTime, GenFdsTime, self.ReportType) > Content =3D FileLinesSplit(File.getvalue(), gLineMaxLengt= h) > 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=3Dself.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 t= he program > # @param WorkingDir The directory in which the program will b= e >running > # > def LaunchCommand(Command, WorkingDir): >+ BeginTime =3D 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=3DWorkingDir) > > # Command is used as the first Argument in following Popen(). >@@ -319,10 +320,11 @@ def LaunchCommand(Command, WorkingDir): > RespContent =3D f.read() > f.close() > EdkLogger.info(RespContent) > > EdkLogger.error("build", COMMAND_FAILURE, ExtraData=3D"%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 wi= ll be >running > # > def _CommandThread(self, Command, WorkingDir): > try: >- LaunchCommand(Command, WorkingDir) >+ self.BuildItem.BuildObject.BuildTime =3D LaunchCommand(Comman= d, >WorkingDir) > self.CompleteFlag =3D 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 =3D BuildOptions.ConfDirectory > self.SpawnMode =3D True > self.BuildReport =3D BuildReport(BuildOptions.ReportFile, >BuildOptions.ReportType) > self.TargetTxt =3D TargetTxtClassObject() > self.ToolDef =3D ToolDefClassObject() >+ self.AutoGenTime =3D 0 >+ self.MakeTime =3D 0 >+ self.GenFdsTime =3D 0 > GlobalData.BuildOptionPcd =3D BuildOptions.OptionPcd > #Set global flag for build mode > GlobalData.gIgnoreSource =3D BuildOptions.IgnoreSources > > if self.ConfDirectory: >@@ -1337,11 +1342,11 @@ class Build(): > > # build modules > if BuildModule: > if Target !=3D 'fds': > BuildCommand =3D BuildCommand + [Target] >- LaunchCommand(BuildCommand, AutoGenObject.MakeFileDir) >+ AutoGenObject.BuildTime =3D LaunchCommand(BuildCommand, >AutoGenObject.MakeFileDir) > self.CreateAsBuiltInf() > return True > > # genfds > if Target =3D=3D 'fds': >@@ -1758,10 +1763,11 @@ class Build(): > def _BuildModule(self): > for BuildTarget in self.BuildTargetList: > GlobalData.gGlobalDefines['TARGET'] =3D BuildTarget > index =3D 0 > for ToolChain in self.ToolChainList: >+ WorkspaceAutoGenTime =3D time.time() > GlobalData.gGlobalDefines['TOOLCHAIN'] =3D ToolChain > GlobalData.gGlobalDefines['TOOL_CHAIN_TAG'] =3D ToolChain > GlobalData.gGlobalDefines['FAMILY'] =3D self.ToolChainFam= ily[index] > index +=3D 1 > # >@@ -1789,21 +1795,52 @@ class Build(): > self.Fdf =3D Wa.FdfFile > self.LoadFixAddress =3D Wa.Platform.LoadFixAddress > Wa.CreateMakeFile(False) > self.Progress.Stop("done!") > MaList =3D [] >+ ExitFlag =3D threading.Event() >+ ExitFlag.clear() >+ self.AutoGenTime +=3D int(round((time.time() - >WorkspaceAutoGenTime))) > for Arch in Wa.ArchList: >+ AutoGenStart =3D time.time() > GlobalData.gGlobalDefines['ARCH'] =3D Arch > Pa =3D PlatformAutoGen(Wa, self.PlatformFile, BuildTa= rget, ToolChain, >Arch) > for Module in Pa.Platform.Modules: > if self.ModuleFile.Dir =3D=3D Module.Dir and self= .ModuleFile.File =3D=3D >Module.File: > Ma =3D ModuleAutoGen(Wa, Module, BuildTarget,= ToolChain, >Arch, self.PlatformFile) > if Ma =3D=3D None: continue > MaList.append(Ma) > self.BuildModules.append(Ma) >- if not Ma.IsBinaryModule: >- self._Build(self.Target, Ma, BuildModule= =3DTrue) >+ self.AutoGenTime +=3D int(round((time.time() - AutoGe= nStart))) >+ MakeStart =3D time.time() >+ for Ma in self.BuildModules: >+ if not Ma.IsBinaryModule: >+ Bt =3D 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 plat= form >+ ExitFlag.set() >+ BuildTask.WaitForComplete() >+ Pa.CreateMakeFile(False) >+ EdkLogger.error("build", BUILD_ERROR, "Failed= to build >module", ExtraData=3DGlobalData.gBuildingModule) >+ # Start task scheduler >+ if not BuildTask.IsOnGoing(): >+ BuildTask.StartScheduler(self.ThreadNumber, E= xitFlag) >+ >+ # in case there's an interruption. we need a full ver= sion of makefile >for platform >+ Pa.CreateMakeFile(False) >+ if BuildTask.HasError(): >+ EdkLogger.error("build", BUILD_ERROR, "Failed to = build module", >ExtraData=3DGlobalData.gBuildingModule) >+ self.MakeTime +=3D int(round((time.time() - MakeStart= ))) >+ >+ MakeContiue =3D time.time() >+ ExitFlag.set() >+ BuildTask.WaitForComplete() >+ self.CreateAsBuiltInf() >+ self.MakeTime +=3D int(round((time.time() - MakeContiue))= ) >+ if BuildTask.HasError(): >+ EdkLogger.error("build", BUILD_ERROR, "Failed to buil= d module", >ExtraData=3DGlobalData.gBuildingModule) > > self.BuildReport.AddPlatformReport(Wa, MaList) > if MaList =3D=3D []: > EdkLogger.error( > 'build', >@@ -1840,11 +1877,13 @@ class Build(): > # > self._CollectModuleMapBuffer(MapBuffer, ModuleLis= t) > # > # create FDS again for the updated EFI image > # >+ GenFdsStart =3D time.time() > self._Build("fds", Wa) >+ self.GenFdsTime +=3D int(round((time.time() - GenFdsS= tart))) > # > # 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'] =3D BuildTarget > index =3D 0 > for ToolChain in self.ToolChainList: >+ WorkspaceAutoGenTime =3D time.time() > GlobalData.gGlobalDefines['TOOLCHAIN'] =3D ToolChain > GlobalData.gGlobalDefines['TOOL_CHAIN_TAG'] =3D ToolChain > GlobalData.gGlobalDefines['FAMILY'] =3D self.ToolChainFam= ily[index] > index +=3D 1 > Wa =3D WorkspaceAutoGen( >@@ -1887,11 +1927,13 @@ class Build(): > Wa.CreateMakeFile(False) > > # multi-thread exit flag > ExitFlag =3D threading.Event() > ExitFlag.clear() >+ self.AutoGenTime +=3D int(round((time.time() - >WorkspaceAutoGenTime))) > for Arch in Wa.ArchList: >+ AutoGenStart =3D time.time() > GlobalData.gGlobalDefines['ARCH'] =3D Arch > Pa =3D PlatformAutoGen(Wa, self.PlatformFile, BuildTa= rget, ToolChain, >Arch) > if Pa =3D=3D None: > continue > ModuleList =3D [] >@@ -1922,11 +1964,12 @@ class Build(): > Ma.CreateMakeFile(True) > if self.Target =3D=3D "genmake": > continue > self.BuildModules.append(Ma) > self.Progress.Stop("done!") >- >+ self.AutoGenTime +=3D int(round((time.time() - AutoGe= nStart))) >+ MakeStart =3D time.time() > for Ma in self.BuildModules: > # Generate build task for the module > if not Ma.IsBinaryModule: > Bt =3D 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 ver= sion of makefile >for platform > Pa.CreateMakeFile(False) > if BuildTask.HasError(): > EdkLogger.error("build", BUILD_ERROR, "Failed to = build module", >ExtraData=3DGlobalData.gBuildingModule) >+ self.MakeTime +=3D int(round((time.time() - MakeStart= ))) > >+ MakeContiue =3D 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 +=3D 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 =3D time.time() > LaunchCommand(Wa.GenFdsCommand, os.getcwd()) > > # > # Create MAP file for all platform FVs after GenF= ds. > # > self._CollectFvMapBuffer(MapBuffer, Wa, ModuleLis= t) >+ self.GenFdsTime +=3D int(round((time.time() - Gen= FdsStart))) > # > # 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 =3D '' >+ TimeDur =3D time.gmtime(Time) >+ if TimeDur.tm_yday > 1: >+ TimeDurStr =3D time.strftime("%H:%M:%S", TimeDur) + ", %d day= (s)" % >(TimeDur.tm_yday - 1) >+ else: >+ TimeDurStr =3D 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 =3D time.strftime("%H:%M:%S", BuildDuration) + "= , %d >day(s)" % (BuildDuration.tm_yday - 1) > else: > BuildDurationStr =3D time.strftime("%H:%M:%S", BuildDuration) > if MyBuild !=3D 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