Module:Sandbox/Aidan9382/Benchmarker

Module documentation[view] [edit] [history] [purge]

A module benchmarker aimed at benchmarking at a wider scope and reliably. This differs from the standard MediaWiki Lua Profile in that it profiles specifically exported module functions instead of every function (e.g. standard string library functions). This lets you figure out what module is making expensive calls rather than what expensive calls are being made.

Usage

To benchmark a module and all submodules it calls, put local __prepare = require("Module:Sandbox/Aidan9382/Benchmarker") on the first line and __prepare(p, "<Module name>") (or the equivilant to p) at the very bottom just before the return in the highest level module you want to benchmark from. You do not need to include the benchmarker in any other modules; any module fetched using require will automatically have its returned value hooked.

Example output

An excerpt from a benchmark of Module:WikiProject banner/sandbox previewed on Special:Permalink/1214895585

-- Benchmarker Finished --
Total time taken: 91.1ms

Top 5 modules by time taken:
Module:Pagetype/sandbox: 55.7ms (61.1%)
Module:Wikitext Parsing: 25.5ms (28%)
Module:WikiProject banner/sandbox: 7.8ms (8.6%)
Module:Template parameter value: 1.9ms (2.1%)
Module:Arguments: 0.2ms (0.2%)

Top 5 functions by time taken:
Module:Pagetype/sandbox._main: 55.7ms (61.1%)
Module:Wikitext Parsing.PrepareText: 25.5ms (28%)
Module:WikiProject banner/sandbox._main: 7.4ms (8.1%)
Module:Template parameter value.getValue: 1ms (1.1%)
Module:Template parameter value.getTemplate: 1ms (1.1%)

The above documentation is transcluded from Module:Sandbox/Aidan9382/Benchmarker/doc. (edit | history)
Editors can experiment in this module's sandbox (create | mirror) and testcases (create) pages.
Subpages of this module.

-- In-depth execution speed benchmarker - read the /doc for more info

-- =================================================================== --
-- This is a meta-module that hooks globals, which could be disruptive --
--        Be careful including this module outside of sandboxes        --
-- =================================================================== --

-- Always use rawget/rawset on _G to bypass strict
local ActiveHooker = rawget(_G, "_BenchmarkerHooker")
if ActiveHooker ~= nil then
	return ActiveHooker
end

--== Personal stuff ==--
local function dp(x, n)
	n = n or 4
	return math.floor(x*10^n+0.5) / 10^n
end

local function GetVarargInfo(...)
	return {...}, select("#", ...)
end

local function DetermineCaller(stacktrace)
	for line in stacktrace:gmatch("[^\n]+") do
		if not line:find("^stack traceback:") and not line:find("Aidan9382/Benchmarker") then
			local f, l = line:match("^%s*([^:]+):([^:]+)")
			return {Function=f, Line=tonumber(l)}
		end
	end
end

local CompleteCalls = {}
local FunctionCallStack = {}
local NoHookZone = {}

local function FinishUp()
	-- Note: Don't currently use caller stats. Eh, whatever
	local TotalTimeTaken = 0
	local ModuleTotalTimes = {}
	local ModuleCallCount = {}
	local FunctionTotalTimes = {}
	local FunctionCallCount = {}
	local SeenModules = {}
	local SeenFunctions = {}
	for _, Call in next, CompleteCalls do
		local CallTime = Call.TimeTaken - Call.Offset
		TotalTimeTaken = TotalTimeTaken + CallTime
		if not ModuleTotalTimes[Call.Origin] then
			ModuleTotalTimes[Call.Origin] = 0
			ModuleCallCount[Call.Origin] = 0
			SeenModules[#SeenModules+1] = Call.Origin
		end
		ModuleTotalTimes[Call.Origin] = ModuleTotalTimes[Call.Origin] + CallTime
		ModuleCallCount[Call.Origin] = ModuleCallCount[Call.Origin] + 1
		local UniqueName = Call.Origin .. "." .. Call.Name
		if not FunctionTotalTimes[UniqueName] then
			FunctionTotalTimes[UniqueName] = 0
			FunctionCallCount[UniqueName] = 0
			SeenFunctions[#SeenFunctions+1] = UniqueName
		end
		FunctionTotalTimes[UniqueName] = FunctionTotalTimes[UniqueName] + CallTime
		FunctionCallCount[UniqueName] = FunctionCallCount[UniqueName] + 1
	end
	local MinTimeTaken = rawget(_G, "_MinTimeTaken") or 0.01
	if TotalTimeTaken > MinTimeTaken then
		table.sort(SeenModules, function(a, b)
			return ModuleTotalTimes[a] > ModuleTotalTimes[b]
		end)
		table.sort(SeenFunctions, function(a, b)
			return FunctionTotalTimes[a] > FunctionTotalTimes[b]
		end)
		mw.log("\n-- Benchmarker Finished --")
		mw.log("Total time taken: " .. dp(TotalTimeTaken)*1000 .. "ms")
		mw.log("\nTop 5 modules by time taken:")
		for i = 1, math.min(5, #SeenModules) do
			local name = SeenModules[i]
			local t = dp(ModuleTotalTimes[name])
			mw.log(name .. ": " .. t*1000 .. "ms (" .. dp(t/TotalTimeTaken, 3)*100 .. "%) in " .. ModuleCallCount[name] .. " calls")
		end
		mw.log("\nTop 5 functions by time taken:")
		for i = 1, math.min(5, #SeenFunctions) do
			local name = SeenFunctions[i]
			local t = dp(FunctionTotalTimes[name])
			mw.log(name .. ": " .. t*1000 .. "ms (" .. dp(t/TotalTimeTaken, 3)*100 .. "%) in " .. FunctionCallCount[name] .. " calls")
		end
		mw.log("") -- extra newline
	end
	CompleteCalls = {}
end

local function HookFunction(f, fname, origin)
	if not NoHookZone[f] then
		local out = function(...)
			-- Caller stats aren't used right now, so keep performance up
			-- local callerinfo = DetermineCaller(debug.traceback())
			local StackObject = {
				Name=fname, Origin=origin, Offset=0,
				-- Caller=callerinfo.Function, CallLine=callerinfo.Line
			}
			FunctionCallStack[#FunctionCallStack+1] = StackObject
			local s = os.clock()
			local response, length = GetVarargInfo(f(...))
			local timetaken = os.clock() - s
			StackObject.TimeTaken = timetaken
			CompleteCalls[#CompleteCalls+1] = StackObject
			local maxi = #FunctionCallStack
			FunctionCallStack[maxi] = nil
			if maxi == 1 then
				FinishUp()
			else
				FunctionCallStack[maxi-1].Offset = FunctionCallStack[maxi-1].Offset + timetaken
			end
			return unpack(response, 1, length)
		end
		NoHookZone[out] = true
		return out
	else
		return f
	end
end
local function HookGeneric(obj, origin)
	assert(type(origin) == "string", "Attempted to init benchmarking with a non-string origin")
	-- safety catch since we export this function
	if type(obj) == "function" then
		return HookFunction(obj, "<main>", origin)
	elseif type(obj) == "table" then
		for a, b in next, obj do
			if type(b) == "function" then
				obj[a] = HookFunction(b, a, origin)
			end
		end
		return obj
	else
		error("Attempted to init benchmarking on an invalid object type")
	end
end
rawset(_G, "_BenchmarkerHooker", HookGeneric)

--== Global hooking ==--
local require = require
local function hookedrequire(source)
	local out = require(source)
	if source ~= "strict" and source ~= "Module:Sandbox/Aidan9382/Benchmarker" then
		if type(out) == "table" then
			HookGeneric(out, source)
		elseif type(out) == "function" then
			out = HookFunction(out, "<main>", source)
		end
	end
	return out
end
rawset(_G, "require", hookedrequire)

return HookGeneric