Merge pull request #6437 from Arthapz/profile-module-support

(C++ modules support) profile module support

3 files changed, 74 insertions, 8 deletions

diff --git a/xmake/core/base/profiler.lua b/xmake/core/base/profiler.lua
index ae0ced4fc..1cd1a1d2d 100644
--- a/xmake/core/base/profiler.lua
+++ b/xmake/core/base/profiler.lua
@@ -182,14 +182,20 @@ function profiler:stop()
             return a.totaltime > b.totaltime
         end)
 
-        -- show reports
+        -- show and save reports
+        local report_lines = ""
+        local outfile = path.join(os.tmpdir(), "perf-call-" .. os.date("%d-%m-%y-%S-%M-%H") .. ".log")
         for _, report in ipairs(reports) do
             local percent = (report.totaltime / totaltime) * 100
             if percent < 1 then
                 break
             end
-            utils.print("%6.3f, %6.2f%%, %7d, %s", report.totaltime, percent, report.callcount, self:_func_title(report.funcinfo))
+            local report_line = string.format("%6.3f, %6.2f%%, %7d, %s", report.totaltime, percent, report.callcount, self:_func_title(report.funcinfo))
+            report_lines = report_lines .. report_line .. "\n"
+            utils.print(report_line)
         end
+        utils.print("full log written to %s", outfile)
+        io.writefile(outfile, report_lines)
     elseif self:is_perf("tag") then
 
         -- sort reports, topN
@@ -201,16 +207,27 @@ function profiler:stop()
             h:push(report)
         end
 
-        -- show reports
+        -- show and save reports
         local count = 0
-        while count < 64 and h:length() > 0 do
+        local max_count = 64
+        local outfile = path.join(os.tmpdir(), "perf-tag-" .. os.date("%d-%m-%y-%S-%M-%H") .. ".log")
+        local report_lines = ""
+        while h:length() > 0 do
             local report = h:pop()
-            utils.print("%6.3f, %7d, %s", report.totaltime, report.callcount, self:_tag_title(report.name, report.argv))
+            local report_line = string.format("%6.3f, %7d, %s", report.totaltime, report.callcount, self:_tag_title(report.name, report.argv))
+            report_lines = report_lines .. report_line .. "\n"
             count = count + 1
         end
-        if h:length() > 0 then
+        if count <= max_count then
+            utils.print(report_lines)
+        elseif count > max_count then
+            local max_count_lines = {table.unpack(report_lines:split("\n"), 1, max_count)}
+            utils.print(table.concat(max_count_lines, "\n"))
             utils.print("...")
+            count = count + 1
         end
+        utils.print("full log written to %s", outfile)
+        io.writefile(outfile, report_lines)
    end
 end
 
diff --git a/xmake/rules/c++/modules/builder.lua b/xmake/rules/c++/modules/builder.lua
index 44da4d622..4b50b8ae3 100644
--- a/xmake/rules/c++/modules/builder.lua
+++ b/xmake/rules/c++/modules/builder.lua
@@ -22,6 +22,7 @@
 import("core.base.json")
 import("core.base.option")
 import("core.base.hashset")
+import("core.base.profiler")
 import("async.runjobs")
 import("private.action.clean.remove_files")
 import("private.async.buildjobs")
@@ -134,6 +135,7 @@ end
 -- should we build this module or headerunit ?
 function should_build(target, module)
 
+    profiler.enter(target:fullname(), "c++ modules", "builder", "check if " .. (module.name or module.sourcefile) .. " should be rebuilt")
     local memcache = support.memcache()
     local _should_build = memcache:get2(target:fullname(), "should_build_" .. module.sourcefile)
     if _should_build == nil then
@@ -142,6 +144,7 @@ function should_build(target, module)
         if reused then
             local build = should_build(from, module)
             memcache:set2(target:fullname(), "should_build_" .. module.sourcefile, build)
+            profiler.leave(target:fullname(), "c++ modules", "builder", "check if " .. (module.name or module.sourcefile) .. " should be rebuilt")
             return build
         end
         local compinst = compiler.load("cxx", {target = target})
@@ -164,6 +167,7 @@ function should_build(target, module)
             if should_build(target, mapped_dep) then
                 depend.save(dependinfo, dependfile)
                 memcache:set2(target:fullname(), "should_build_" .. module.sourcefile, true)
+                profiler.leave(target:fullname(), "c++ modules", "builder", "check if " .. (module.name or module.sourcefile) .. " should be rebuilt")
                 return true
             end
         end
@@ -173,11 +177,14 @@ function should_build(target, module)
         if dryrun or depend.is_changed(old_dependinfo, dependinfo) then
             depend.save(dependinfo, dependfile)
             memcache:set2(target:fullname(), "should_build_" .. module.sourcefile, true)
+            profiler.leave(target:fullname(), "c++ modules", "builder", "check if " .. (module.name or module.sourcefile) .. " should be rebuilt")
             return true
         end
         memcache:set2(target:fullname(), "should_build_" .. module.sourcefile, false)
+        profiler.leave(target:fullname(), "c++ modules", "builder", "check if " .. (module.name or module.sourcefile) .. " should be rebuilt")
         return false
     end
+    profiler.leave(target:fullname(), "c++ modules", "builder", "check if " .. (module.name or module.sourcefile) .. " should be rebuilt")
     return _should_build
 end
 
@@ -186,6 +193,7 @@ end
 -- it not build also objectfiles
 function build_modules_for_jobgraph(target, jobgraph, built_modules)
 
+    profiler.enter(target:fullname(), "c++ modules", "builder", "schedule module bmi build jobs")
     local builder = _builder(target)
     local has_two_phase_compilation_support = support.has_two_phase_compilation_support(target)
     local jobdeps = {}
@@ -247,11 +255,13 @@ function build_modules_for_jobgraph(target, jobgraph, built_modules)
             jobgraph:add_orders(depname, jobname)
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "builder", "schedule module bmi build jobs")
 end
 
 -- build modules objectfiles for jobgraph if two phase compilation is supported
 function build_objectfiles_for_jobgraph(target, jobgraph, built_modules)
 
+    profiler.enter(target:fullname(), "c++ modules", "builder", "schedule module objectfiles build jobs")
     local builder = _builder(target)
     local has_two_phase_compilation_support = support.has_two_phase_compilation_support(target)
     local buildgroup = _get_module_buildgroup_for(target, "objectfile")
@@ -279,6 +289,7 @@ function build_objectfiles_for_jobgraph(target, jobgraph, built_modules)
             end
         end
     end)
+    profiler.leave(target:fullname(), "c++ modules", "builder", "schedule module objectfiles build jobs")
 end
 
 -- build batchjobs for modules
@@ -451,6 +462,7 @@ end
 -- build headerunits for jobgraph
 function build_headerunits_for_jobgraph(target, jobgraph, built_stlheaderunits, built_headerunits)
 
+    profiler.enter(target:fullname(), "c++ modules", "builder", "schedule headerunits build jobs")
     local builder = _builder(target)
     function make_headerunit_job(headerfile, opt)
         local reused, from = support.is_reused(target, headerfile)
@@ -483,6 +495,7 @@ function build_headerunits_for_jobgraph(target, jobgraph, built_stlheaderunits,
             end
         end)
     end
+    profiler.leave(target:fullname(), "c++ modules", "builder", "schedule headerunits build jobs")
 end
 
 -- build headerunits for batchjobs
@@ -549,6 +562,7 @@ function build_headerunits_for_batchcmds(target, batchcmds, built_stlheaderunits
 end
 
 function generate_metadata(target, modules)
+    profiler.enter(target:fullname(), "c++ modules", "builder", "generate module metadata")
     local public_modules
     for sourcefile, module in table.orderpairs(modules) do
         local fileconfig = target:fileconfig(sourcefile)
@@ -560,6 +574,7 @@ function generate_metadata(target, modules)
     end
 
     if not public_modules then
+        profiler.leave(target:fullname(), "c++ modules", "builder", "generate module metadata")
         return
     end
 
@@ -571,10 +586,12 @@ function generate_metadata(target, modules)
         local metadata = _generate_meta_module_info(target, module)
         json.savefile(metafilepath, metadata)
     end, {comax = jobs, total = #public_modules})
+    profiler.leave(target:fullname(), "c++ modules", "builder", "generate module metadata")
 end
 
 -- check if dependencies changed
 function is_dependencies_changed(target, module)
+    profiler.enter(target:fullname(), "c++ modules", "builder", "check if dependency chain changed")
     local cachekey = target:fullname() .. (module.name or module.sourcefile)
     local requires = hashset.from(table.keys(module.deps or {}))
     local oldrequires = support.memcache():get2(cachekey, "oldrequires")
@@ -591,6 +608,7 @@ function is_dependencies_changed(target, module)
            end
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "builder", "check if dependency chain changed")
     return requires, changed
 end
 
@@ -644,6 +662,7 @@ function build_bmis(target, jobgraph, _, opt)
         if target:is_moduleonly() and not target:data("cxx.modules.reused") then
             return
         end
+        profiler.enter(target:fullname(), "c++ modules", "builder", "bmis")
         local modules = scanner.get_modules(target)
         -- avoid building non referenced modules
         local built_modules, built_headerunits, _ = scanner.sort_modules_by_dependencies(target, modules, {jobgraph = target:policy("build.jobgraph")})
@@ -680,6 +699,7 @@ function build_bmis(target, jobgraph, _, opt)
         else
             assert(false, "shouldn't be here :D")
         end
+        profiler.leave(target:fullname(), "c++ modules", "builder", "bmis")
     end
 end
 
@@ -689,6 +709,7 @@ function build_objectfiles(target, jobgraph, _, opt)
         if target:is_moduleonly() and not target:data("cxx.modules.reused") then
             return
         end
+        profiler.enter(target:fullname(), "c++ modules", "builder", "objectfiles")
         local modules = scanner.get_modules(target)
         -- avoid building non referenced modules
         local built_modules, _, _ = scanner.sort_modules_by_dependencies(target, modules, {jobgraph = target:policy("build.jobgraph")})
@@ -712,6 +733,7 @@ function build_objectfiles(target, jobgraph, _, opt)
         else
             assert(false, "shouldn't be here :D")
         end
+        profiler.leave(target:fullname(), "c++ modules", "builder", "objectfiles")
     end
 end
 
diff --git a/xmake/rules/c++/modules/scanner.lua b/xmake/rules/c++/modules/scanner.lua
index fe9b9c63d..cef06cdbc 100644
--- a/xmake/rules/c++/modules/scanner.lua
+++ b/xmake/rules/c++/modules/scanner.lua
@@ -23,6 +23,7 @@ import("core.base.json")
 import("core.base.hashset")
 import("core.base.graph")
 import("core.base.option")
+import("core.base.profiler")
 import("async.runjobs")
 import("support")
 import("mapper")
@@ -32,8 +33,9 @@ function _scanner(target)
     return support.import_implementation_of(target, "scanner")
 end
 
-function _parse_meta_info(metafile)
+function _parse_meta_info(target, metafile)
 
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "parse metainfo", metafile)
     local metadata = json.loadfile(metafile)
     if metadata.file and metadata.name then
         return metadata.file, metadata.name, metadata
@@ -59,6 +61,7 @@ function _parse_meta_info(metafile)
             break
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "parse metainfo", metafile)
     return filename, name, metadata
 end
 
@@ -102,6 +105,7 @@ end
 }]]
 function _parse_dependencies_data(target, moduleinfos)
 
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "parse modulescans")
     -- insert headerunit as moduleinfos
     local headerunitinfos = {}
     for _, moduleinfo in ipairs(moduleinfos) do
@@ -188,12 +192,14 @@ function _parse_dependencies_data(target, moduleinfos)
             end
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "parse modulescans")
     return modules, modules_names
 end
 
 -- generate edges for DAG
 function _get_edges(target, nodes, modules)
 
+  profiler.enter(target:fullname(), "c++ modules", "scanner", "get module dependency graph edges")
   local edges = {}
   local name_filemap = {}
   local deps_names = hashset.new()
@@ -219,18 +225,20 @@ function _get_edges(target, nodes, modules)
           end
       end
   end
+  profiler.leave(target:fullname(), "c++ modules", "scanner", "get module dependency graph edges")
   return edges
 end
 
 -- get package modules
 function _get_package_modules(target, package, opt)
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "get modules from package", package:name())
     opt = opt or {}
     local package_modules
     local modulesdir = path.join(package:installdir(), "modules")
     local metafiles = os.files(path.join(modulesdir, "*", "*.meta-info"))
     for _, metafile in ipairs(metafiles) do
         package_modules = package_modules or {}
-        local modulefile, _, metadata = _parse_meta_info(metafile)
+        local modulefile, _, metadata = _parse_meta_info(target, metafile)
 
         local bmionly = package:libraryfiles() and true or false
         package_modules[path.join(modulesdir, modulefile)] = {defines = metadata.defines,
@@ -238,6 +246,7 @@ function _get_package_modules(target, package, opt)
                                                               bmionly = bmionly,
                                                               external = opt.external and target:fullname()}
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "get modules from package", package:name())
     return package_modules
 end
 
@@ -257,6 +266,7 @@ end
 
 -- get packages modules
 function _get_packages_modules(target)
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "get modules from package dependencies")
     -- parse all meta-info and append their informations to the package store
     local packages_modules = support.memcache():get2(target:fullname(), "cxx_packages_modules")
     if not packages_modules then
@@ -271,12 +281,14 @@ function _get_packages_modules(target)
         end
         support.memcache():set2(target:fullname(), "cxx_packages_modules", packages_modules)
     end
+    profiler.leave(target:fullname(), "c++ modules", "get modules from package dependencies")
     return packages_modules
 end
 
 -- get target deps modules
 function _get_targetdeps_modules(target)
 
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "get modules from target dependencies")
     local _, stdmodules_set = support.get_stdmodules(target)
     local modules
     for _, dep in ipairs(target:orderdeps()) do
@@ -310,6 +322,7 @@ function _get_targetdeps_modules(target)
             end
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "get modules from target dependencies")
     return modules
 end
 
@@ -390,6 +403,7 @@ end
 
 function _do_parse(target, sourcebatch)
 
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "parse module dependencies and compute dependency graph")
     local changed = support.memcache():get2(target:fullname(), "modules.changed")
     local modules
     if changed then
@@ -436,18 +450,22 @@ function _do_parse(target, sourcebatch)
 
     -- sort modules
     sort_modules_by_dependencies(target, modules, {jobgraph = target:policy("build.jobgraph")})
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "parse module dependencies and compute dependency graph")
 end
 
 function _do_scan(target, sourcefile, opt)
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "scan dependencies for", sourcefile)
     local changed = _scanner(target).scan_dependency_for(target, sourcefile, opt)
     if changed or not support.localcache():get2(target:fullname(), "module_mapper") then
         support.memcache():set2(target:fullname(), "modules.changed", true)
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "scan dependencies for", sourcefile)
 end
 
 -- scan module dependencies
 function _schedule_module_dependencies_scan(target, jobgraph, sourcebatch)
 
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "schedule module dependencies scans")
     function get_basegroup_for(target)
         return target:fullname() .. "/modules"
     end
@@ -513,10 +531,12 @@ function _schedule_module_dependencies_scan(target, jobgraph, sourcebatch)
             end
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "schedule module dependencies scans")
 end
 
 -- get headerunits info
 function sort_headerunits(target, headerunits)
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "sort headerunits")
     local _headerunits
     local stl_headerunits
     for _, headerunit in ipairs(headerunits) do
@@ -529,6 +549,7 @@ function sort_headerunits(target, headerunits)
             table.insert(_headerunits, headerunit)
         end
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "sort headerunits")
     return _headerunits, stl_headerunits
 end
 
@@ -563,6 +584,7 @@ end
 }]]
 function fallback_generate_dependencies(target, jsonfile, sourcefile, preprocess_file)
 
+    profiler.enter(target:fullname(), "c++ modules", "fallback scanner", "scan module dependencies for", sourcefile)
     local output = {version = 1, revision = 0, rules = {}}
     local rule = {outputs = {jsonfile}}
     rule["primary-output"] = target:objectfile(sourcefile)
@@ -637,11 +659,13 @@ function fallback_generate_dependencies(target, jsonfile, sourcefile, preprocess
     table.insert(output.rules, rule)
     local jsondata = json.encode(output)
     io.writefile(jsonfile, jsondata)
+    profiler.leave(target:fullname(), "c++ modules", "fallback scanner", "scan module dependencies for", sourcefile)
 end
 
 -- topological sort
 function sort_modules_by_dependencies(target, modules)
 
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "compute module dependency dag")
     local memcache = support.memcache()
     local localcache = support.localcache()
     local changed = memcache:get2(target:fullname(), "modules.changed")
@@ -765,6 +789,7 @@ function sort_modules_by_dependencies(target, modules)
         memcache:set2(target:fullname(), "modules.changed", false)
     end
     assert(built_artifacts, "shouldn't assert here, please open an issue")
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "compute module dependency dag")
     return built_artifacts.modules, built_artifacts.headerunits, built_artifacts.objectfiles
 end
 
@@ -793,9 +818,11 @@ function after_scan(target)
 end
 
 function main(target, jobgraph, sourcebatch)
+    profiler.enter(target:fullname(), "c++ modules", "scanner", "scan")
     local compile_commands = os.getenv("XMAKE_IN_PROJECT_GENERATOR") and os.getenv("XMAKE_IN_COMPILE_COMMANDS_PROJECT_GENERATOR")
     if target:data("cxx.has_modules") and (not os.getenv("XMAKE_IN_PROJECT_GENERATOR") or compile_commands) then
         _patch_sourcebatch(target, sourcebatch)
         _schedule_module_dependencies_scan(target, jobgraph, sourcebatch)
     end
+    profiler.leave(target:fullname(), "c++ modules", "scanner", "scan")
 end