perf: track some additional cputimes

Author: folke

lua/lazy/init.lua

@@ -36,10 +36,11 @@ function M.setup(spec, opts)
   -- load module cache before anything else
   require("lazy.core.cache").setup(opts)
 
+  require("lazy.stats").track("LazyStart")
+
   local Util = require("lazy.core.util")
   local Config = require("lazy.core.config")
   local Loader = require("lazy.core.loader")
-  local Plugin = require("lazy.core.plugin")
 
   Util.track({ plugin = "lazy.nvim" }) -- setup start
   Util.track("module", vim.loop.hrtime() - start)
@@ -64,6 +65,7 @@ function M.setup(spec, opts)
 
   -- all done!
   vim.cmd("do User LazyDone")
+  require("lazy.stats").track("LazyDone")
 end
 
 function M.stats()

lua/lazy/stats.lua

@@ -1,3 +1,5 @@
+local ffi = require("ffi")
+
 local M = {}
 
 ---@class LazyStats
@@ -10,35 +12,48 @@ M._stats = {
   startuptime_cputime = false,
   count = 0, -- total number of plugins
   loaded = 0, -- number of loaded plugins
+  ---@type table<string, number>
+  times = {},
 }
 
+---@type ffi.namespace*|boolean
+M.C = nil
+
 function M.on_ui_enter()
-  if not M.C then
-    pcall(function() end)
-  end
+  M._stats.startuptime = M.track("UIEnter")
+  M._stats.startuptime_cputime = M.C ~= false
+  vim.cmd([[do User LazyVimStarted]])
+end
 
-  local ok = pcall(function()
-    local ffi = require("ffi")
-    ffi.cdef([[
+function M.track(event)
+  local time = M.cputime()
+  M._stats.times[event] = time
+  return time
+end
+
+function M.cputime()
+  if M.C == nil then
+    local ok = pcall(function()
+      ffi.cdef([[
         typedef long time_t;
         typedef int clockid_t;
-
         typedef struct timespec {
           time_t   tv_sec;        /* seconds */
           long     tv_nsec;       /* nanoseconds */
         } nanotime;
         int clock_gettime(clockid_t clk_id, struct timespec *tp);
       ]])
+    end)
+    M.C = ok and ffi.C or false
+  end
+  if M.C then
     local pnano = assert(ffi.new("nanotime[?]", 1))
     local CLOCK_PROCESS_CPUTIME_ID = jit.os == "OSX" and 12 or 2
     ffi.C.clock_gettime(CLOCK_PROCESS_CPUTIME_ID, pnano)
-    M._stats.startuptime = tonumber(pnano[0].tv_sec) / 1e6 + tonumber(pnano[0].tv_nsec) / 1e6
-    M._stats.startuptime_cputime = true
-  end)
-  if not ok then
-    M._stats.startuptime = (vim.loop.hrtime() - require("lazy")._start) / 1e6
+    return tonumber(pnano[0].tv_sec) / 1e6 + tonumber(pnano[0].tv_nsec) / 1e6
+  else
+    return (vim.loop.hrtime() - require("lazy")._start) / 1e6
   end
-  vim.cmd([[do User LazyVimStarted]])
 end
 
 function M.stats()

lua/lazy/view/render.lua

@@ -556,7 +556,23 @@ function M:profile()
       :append("UIEnter", "LazySpecial")
     self:append(".")
   end
-  self:nl():nl()
+  self:nl()
+
+  local times = {}
+  for event, time in pairs(require("lazy.stats").stats().times) do
+    times[#times + 1] = { event, self:ms(time * 1e6), "Bold", time = time }
+  end
+  table.sort(times, function(a, b)
+    return a.time < b.time
+  end)
+  for p, prop in ipairs(times) do
+    if p > 1 then
+      prop[2] = prop[2] .. " (+" .. self:ms((prop.time - times[p - 1].time) * 1e6) .. ")"
+    end
+  end
+  self:props(times, { indent = 2 })
+
+  self:nl()
 
   self:append("Profile", "LazyH2"):nl():nl()
   self