Perl profiling笔记
项目背景 ? 在一个庞大的代码自动生成项目中,需要通过对C/C++头文件的扫描分析并记录所有public类型的函数原型及参数类型。 在XML script中,显式使用C函数和参数。用户可以自行编写xml测试脚本来运行C/C++代码。 上述过程都通过perl script自动生成并编译。 ? 问题 ? 自动生成代码量巨大,很大部分的时间瓶颈在于perl脚本的执行时间。需要进行优化。 ? 方法 ? 利用了perl的profiling机制进行运行时profiling分析并分perl函数统计所有时间开销。 最后重点改善耗费时间最多的20-30个瓶颈函数。 ? 结果 ? 不包括makefile等方面的脚本编译优化,不考虑perl脚本的功能实现大变动,perl执行时间有大约10~15%的提升。 ? ------------------------------------------------------------------------------------------------------------------------------------------------------------- ? 了解速度瓶颈
? 典型的,tmon.out示例如下 #fOrTyTwO $hz=1000; $XS_VERSION='DProf 20050310.00'; # All values are given in HZ $over_utime=32; $over_stime=0; $over_rtime=32; $over_tests=10000; $rrun_utime=15; $rrun_stime=0; $rrun_rtime=15; $total_marks=2 PART2 @ 15 0 15 & 2 main BEGIN + 2 - 2 ? 对于perl脚本执行后产生的profiling概要数据示例如下 Total Elapsed Time = 0.139411 Seconds User+System Time = 0.061411 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 26.0 0.016 0.016 1 0.0160 0.0160 warnings::BEGIN 26.0 0.016 0.016 1 0.0160 0.0160 fileutils::RemoveFilesWithContent 24.4 0.015 0.015 6 0.0025 0.0025 FindBin::BEGIN 24.4 0.015 0.045 7 0.0021 0.0065 main::BEGIN 0.00 - -0.000 1 - - File::Basename::fileparse_set_fsty 0.0000 pe 0.00 - -0.000 1 - - lib::_nativize 0.00 - -0.000 1 - - Getopt::Long::ConfigDefaults 0.00 - -0.000 1 - - Getopt::Long::Configure 0.00 - -0.000 1 - - DynaLoader::dl_load_file 0.00 - -0.000 1 - - DynaLoader::dl_undef_symbols 0.00 - -0.000 1 - - DynaLoader::dl_find_symbol 0.00 - -0.000 1 - - DynaLoader::dl_install_xsub 0.00 - -0.000 1 - - Cwd::bootstrap 0.00 - -0.000 1 - - Config::TIEHASH 0.00 - -0.000 1 - - re::bits perl执行时间统计结果示例 ====== Final Data Result in Values order ( Time Unit: second) ====== 134.68317 <= all_total_elapsed_time 83.519373 <= all_user_system_time 42.560276 <= genentityfile.pl::total_elapsed_time 24.133051 <= genapiids.pl::total_elapsed_time 18.171 <= main::BEGIN 16.265623 <= genapinamesfromtemplate.pl::total_elapsed_time 15.991419 <= genapinamesfromtemplate.pl::user_system_time 10.250529 <= genentityfile.pl::user_system_time 10.030177 <= genmoduleapifiles.pl::total_elapsed_time 9.902177 <= genmoduleapifiles.pl::user_system_time 8.354992 <= genscriptschema.pl::total_elapsed_time 8.294992 <= genscriptschema.pl::user_system_time 7.45852 <= genmoduleversionfile.pl::total_elapsed_time 7.417362 <= genapiids.pl::user_system_time 7.36752 <= genmoduleversionfile.pl::user_system_time 7.227387 <= convertxscriptapis.pl::total_elapsed_time 7.136385 <= convertxscriptapis.pl::user_system_time 6.909191 <= genatsfile.pl::total_elapsed_time 6.868048 <= genatsfile.pl::user_system_time 5.80599999999999 <= debugutils::BEGIN 5.69099999999999 <= IO::File 5.67999999999999 <= File::Temp 4.112021 <= compilescript.pl::total_elapsed_time 4.112 <= FindBin::BEGIN 4.09702 <= compilescript.pl::user_system_time 3.639 <= tmpfile::BEGIN 3.589 <= templateparser::BEGIN 3.19 <= datamanager::BEGIN 3.089 <= IO::Seekable 2.902 <= Benchmark::BEGIN 2.451 <= templateparser::ReplaceNameValuePa 2.403 <= vars::BEGIN 2.24 <= Getopt::Long 2.159 <= enumparser::ParseEnumFile 1.867215 <= geneventhandlerfromtemplate.pl::total_elapsed_time 1.867205 <= geneventhandlerfromtemplate.pl::user_system_time 1.609 <= IO::Handle 1.387 <= Exporter::as_heavy 1.35 <= apisparser::ParseAPIs 1.295 <= warnings::BEGIN 1.133 <= DynaLoader::dl_load_file 1.05 <= configparser::BEGIN 0.943427 <= genfilefromtemplate.pl::total_elapsed_time 0.908427 <= genfilefromtemplate.pl::user_system_time 0.846000000000001 <= cpreprocessfile::PreprocessFile 0.827000000000001 <= File::Basename 0.809 <= Exporter::import 0.798000000000001 <= apisparser::BEGIN 0.74 <= calculatecrc::CRC16_CalculateCRC 0.729000000000001 <= scriptapiparser::BEGIN 0.690000000000001 <= DynaLoader::bootstrap 0.681 <= vars::import 0.642 <= eventsparser::ParseEvents 0.598 <= Storable::BEGIN 0.573 <= templateparser::StripSubstringForI 0.560688 <= genglobalrefsfromtemplate.pl::user_system_time 0.559688 <= genglobalrefsfromtemplate.pl::total_elapsed_time 0.532 <= enumparser::BEGIN 0.482 <= XSLoader::load 0.471 <= AutoLoader::AUTOLOAD 0.465705 <= findfiles.pl::total_elapsed_time 0.436 <= Cwd::fast_abs_path 0.41 <= templateparser::PreserveSubstringF 0.392 <= apideffileparser::GetGlobalsForMod 0.389 <= enumparser::GetDigitValue 0.368973 <= genentityversionfile.pl::total_elapsed_time 0.368973 <= genentityversionfile.pl::user_system_time 0.357 <= isiconfigparser::BEGIN 0.353 <= debugutils::DebugPrint 0.343 <= lib::import 0.331 <= Storable::pretrieve 0.303 <= apisparser::GetParentStructureName 0.295134 <= genxmlmultiinput.pl::total_elapsed_time 0.285 <= apisparser::GetNamespaceFromApiIDS 0.279134 <= genxmlmultiinput.pl::user_system_time 0.279 <= File::Copy 0.277984 <= genadaptergroups.pl::total_elapsed_time 0.277984 <= genadaptergroups.pl::user_system_time 0.255 <= apisparser::GetStructsFromLine 0.24919 <= SCRIPTS_LISTS_DIAG::total_elapsed_time 0.231705 <= findfiles.pl::user_system_time 0.231 <= templateparser::ProcessTemplate 0.219 <= cpreprocessfile::StripPreprocessor 0.217 <= constant::import 0.215 <= validateparams::ValidatePos 0.207 <= warnings::register 0.206 <= entityparser::ParseEntityFile 0.204 <= cpreprocessfile::BEGIN 0.188 <= File::stat 0.187 <= moduleidsparser::BEGIN 0.173 <= storabledata::BEGIN 0.171205 <= SCRIPTS_INC_SRCS_DIAG::total_elapsed_time 0.147 <= templateparser::ReplaceIfCondition 0.141 <= main::WriteFileContents_NoXmlVersi 0.138 <= adaptercodegen::WriteForAPI 0.131 <= apisparser::IsParamNotScriptableBy 0.124 <= main::WriteFile_NoXmlVersion 0.124 <= scriptcompiler::BEGIN 0.123 <= FindBin::init 0.11 <= main::WriteData 0.10843 <= getxscriptversion.pl::total_elapsed_time 0.105502 <= geneventhandlerfactoryfromtemplate.pl::user_system_time 0.105502 <= geneventhandlerfactoryfromtemplate.pl::total_elapsed_time 0.104 <= scriptapiparser::GetCppClassNames 0.099 <= templateparser::StripSubstring 0.095 <= tmpfile::DeleteTmpFile 0.093205 <= SCRIPTS_INC_SRCS_DIAG::user_system_time 0.093 <= File::Spec 0.09219 <= SCRIPTS_LISTS_DIAG::user_system_time 0.085 <= enumparser::GetEnumValueFromMaps 0.083 <= main::WriteForEachEntityFile 0.08 <= AutoLoader::import 0.079 <= datamanager::OutputNameValuePair 0.079 <= main::WriteDefs 0.079 <= strict::unimport 0.078 <= scriptapiparser::GetModuleList 0.078 <= main::ProcessXml 0.076 <= pounddefineparser::ParseDefinesFil 0.074 <= templateparser::CreateEnumNameFrom 0.074 <= templateparser::PreserveSubstring 0.073 <= main::WriteVersions 0.07 <= Regexp::DESTROY 0.063 <= main::EnumGroupCallback 0.063 <= Storable::bootstrap 0.063 <= DynaLoader::dl_install_xsub 0.062 <= strict::import 0.062 <= datamanager::WriteSetNameValuePair 0.06143 <= getxscriptversion.pl::user_system_time 0.061 <= Class::Struct 0.06 <= IO::bootstrap 0.047 <= warnings::import 0.047 <= eventhandlerparser::BEGIN 0.047 <= err::BEGIN 0.047 <= main::GetGlobalVariableList 0.046 <= main::WriteScriptSymbolsForAPI 0.046 <= datamanager::WriteField 0.046 <= strict::bits 0.046 <= overload::OVERLOAD 0.046 <= enumparser::ParseEnumFileWithPrepr 0.046 <= apisparser::ReplaceXmlEntitiesInCp 0.046 <= scriptapiparser::ConvertScriptFile 0.046 <= eventhandlerparser::GetEventHandle 0.045 <= Time::HiRes 0.045 <= datamanager::ResolveFieldName 0.032 <= enumpreserver::GetExistingEnumValu 0.031 <= main::WriteSchemaForLoopCB 0.031 <= adaptercodegen::WriteHandleResultF 0.031 <= main::WriteEntityParamIDsForAPI 0.031 <= fileutils::BEGIN 0.031 <= apisparser::GetArgsArray 0.031 <= fileutils::ExecShellFindCmd 0.031 <= templateparser::WriteForEachInclud 0.031 <= apisparser::HasFieldsWithUseType 0.031 <= Fcntl::constant 0.031 <= datamanager::OpenIfs 0.031 <= main::WriteDefsParamsForAPI 0.03 <= apisparser::IsArrayElement 0.016 <= main::WriteFunctionDefsForAPI 0.016 <= main::GetModuleSchemaFileName 0.016 <= apisparser::GetReturnName 0.016 <= Fcntl::AUTOLOAD 0.016 <= re::import 0.016 <= datamanager::ConvertToDataMgrEntit 0.016 <= Symbol::gensym 0.016 <= main::WriteEntitiesForEvent 0.016 <= versionparser::BEGIN 0.016 <= validateparams::BEGIN 0.016 <= SelectSaver::new 0.016 <= datamanager::GenPtrStructCppExpr 0.016 <= storabledata::GetDataForPhase3 0.016 <= enumparser::CallEnumGroupCallback 0.016 <= apisparser::IsDescendant 0.016 <= Config::import 0.016 <= validateparams::Validate 0.016 <= apisparser::GetDataItemFromList 0.016 <= main::WriteOutputEntitiesForAPI 0.016 <= main::CompileScript 0.016 <= main::GetApisForModule 0.016 <= eventsparser::GetPayloadNameAndTyp 0.016 <= main::WriteAtsForLoopCB 0.016 <= Benchmark::init 0.016 <= Storable::_retrieve 0.016 <= enumpreserver::CopyFileUntilEndMar 0.016 <= apisparser::GetParam 0.015 <= fileutils::RemoveFilesWithContent 0.015 <= main::WriteFooterForSchema 0.015 <= AutoLoader::BEGIN 0.015 <= IO::BEGIN 0.015 <= apisparser::IsUnionOrVoidPtrDescen 0.015 <= main::WriteSchemaForAPI 0.015 <= datamanager::GetClosestAncestorStr 0.015 <= datamanager::CloseForLoops 0.015 <= Cwd::cwd 0.015 <= scriptapiparser::GetApiFromScriptL 0.015 <= main::WriteDataParamsForAPI 0.015 <= enumpreserver::WriteEnum 0.015 <= base::has_version 7.9e-05 <= convertmoduleids.pl::total_elapsed_time 7.8e-05 <= convertmoduleids.pl::user_system_time 0 <= Storable::_store 0 <= Exporter::Heavy 0 <= Storable::retrieve 0 <= Storable::store 0 <= Fcntl::__ANON__ (编辑:李大同) 【声明】本站内容均来自网络,其相关言论仅代表作者个人观点,不代表本站立场。若无意侵犯到您的权利,请及时与联系站长删除相关内容! |