1
0
mirror of https://github.com/moparisthebest/minetest synced 2024-12-22 15:48:48 -05:00
minetest/builtin/profiler/instrumentation.lua
Tim d7060c212f Builtin/profiler: Replace game profiler (#4245)
Use the setting "profiler.load" to enable profiling.
Other settings can be found in settingtypes.txt.

* /profiler print [filter] - report statistics to in-game console
* /profiler dump [filter] - report statistics to STDOUT and debug.txt
* /profiler save [format [filter]] - saves statistics to a file in your worldpath
	* txt (default) - same treetable format as used by the dump and print commands
	* csv - ready for spreadsheet import
	* json - useful for adhoc D3 visualizations
	* json_pretty - line wrapped and intended json for humans
	* lua - serialized lua table of the profile-data, for adhoc scripts
* /profiler reset - reset all gathered profile data.
	This can be helpful to discard of any startup measurements that often spike during loading or to get more useful min-values.

[filter] allows limiting the output of the data via substring/pattern matching against the modname.

Note: Serialized data structures might be subject to change with changed or added measurements.
	csv might be the most stable, due to flat structure.

Changes to the previous version include:

* Updated and extended API monitoring
* Correct calculation of average (mean) values (undistorted by idleness)
* Reduce instrumentation overhead.
* Fix crashes related to missing parameters for the future and occasional DIV/0's.
* Prevent issues caused by timetravel (overflow, timejump, NTP corrections)
* Prevent modname clashes with internal names.
* Measure each instrumentation individually and label based on registration order.
* Labeling of ABM's and LBM's for easier classification.
  Giving several ABM's or LBM's the same label will treat them as one.
  Missing labels will be autogenerated based on name or registration order.
* Configurable instrumentation and reporting. Skip e.g. builtin if you don't need it.
* Profile the profiler to measure instrumentation overhead.
2016-07-12 21:51:10 +02:00

233 lines
7.0 KiB
Lua

--Minetest
--Copyright (C) 2016 T4im
--
--This program is free software; you can redistribute it and/or modify
--it under the terms of the GNU Lesser General Public License as published by
--the Free Software Foundation; either version 2.1 of the License, or
--(at your option) any later version.
--
--This program is distributed in the hope that it will be useful,
--but WITHOUT ANY WARRANTY; without even the implied warranty of
--MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
--GNU Lesser General Public License for more details.
--
--You should have received a copy of the GNU Lesser General Public License along
--with this program; if not, write to the Free Software Foundation, Inc.,
--51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
local format, pairs, type = string.format, pairs, type
local core, get_current_modname = core, core.get_current_modname
local profiler, sampler = ...
local instrument_builtin = core.setting_getbool("instrument.builtin") or false
local register_functions = {
register_globalstep = 0,
register_playerevent = 0,
register_on_placenode = 0,
register_on_dignode = 0,
register_on_punchnode = 0,
register_on_generated = 0,
register_on_newplayer = 0,
register_on_dieplayer = 0,
register_on_respawnplayer = 0,
register_on_prejoinplayer = 0,
register_on_joinplayer = 0,
register_on_leaveplayer = 0,
register_on_cheat = 0,
register_on_chat_message = 0,
register_on_player_receive_fields = 0,
register_on_craft = 0,
register_craft_predict = 0,
register_on_protection_violation = 0,
register_on_item_eat = 0,
register_on_punchplayer = 0,
register_on_player_hpchange = 0,
}
---
-- Create an unique instrument name.
-- Generate a missing label with a running index number.
--
local counts = {}
local function generate_name(def)
local class, label, func_name = def.class, def.label, def.func_name
if label then
if class or func_name then
return format("%s '%s' %s", class or "", label, func_name or ""):trim()
end
return format("%s", label):trim()
elseif label == false then
return format("%s", class or func_name):trim()
end
local index_id = def.mod .. (class or func_name)
local index = counts[index_id] or 1
counts[index_id] = index + 1
return format("%s[%d] %s", class or func_name, index, class and func_name or ""):trim()
end
---
-- Keep `measure` and the closure in `instrument` lean, as these, and their
-- directly called functions are the overhead that is caused by instrumentation.
--
local time, log = core.get_us_time, sampler.log
local function measure(modname, instrument_name, start, ...)
log(modname, instrument_name, time() - start)
return ...
end
--- Automatically instrument a function to measure and log to the sampler.
-- def = {
-- mod = "",
-- class = "",
-- func_name = "",
-- -- if nil, will create a label based on registration order
-- label = "" | false,
-- }
local function instrument(def)
if not def or not def.func then
return
end
def.mod = def.mod or get_current_modname()
local modname = def.mod
local instrument_name = generate_name(def)
local func = def.func
if not instrument_builtin and modname == "*builtin*" then
return func
end
return function(...)
-- This tail-call allows passing all return values of `func`
-- also called https://en.wikipedia.org/wiki/Continuation_passing_style
-- Compared to table creation and unpacking it won't lose `nil` returns
-- and is expected to be faster
-- `measure` will be executed after time() and func(...)
return measure(modname, instrument_name, time(), func(...))
end
end
local function can_be_called(func)
-- It has to be a function or callable table
return type(func) == "function" or
((type(func) == "table" or type(func) == "userdata") and
getmetatable(func) and getmetatable(func).__call)
end
local function assert_can_be_called(func, func_name, level)
if not can_be_called(func) then
-- Then throw an *helpful* error, by pointing on our caller instead of us.
error(format("Invalid argument to %s. Expected function-like type instead of '%s'.", func_name, type(func)), level + 1)
end
end
---
-- Wraps a registration function `func` in such a way,
-- that it will automatically instrument any callback function passed as first argument.
--
local function instrument_register(func, func_name)
local register_name = func_name:gsub("^register_", "", 1)
return function(callback, ...)
assert_can_be_called(callback, func_name, 2)
register_functions[func_name] = register_functions[func_name] + 1
return func(instrument {
func = callback,
func_name = register_name
}), ...
end
end
local function init_chatcommand()
if core.setting_getbool("instrument.chatcommand") or true then
local orig_register_chatcommand = core.register_chatcommand
core.register_chatcommand = function(cmd, def)
def.func = instrument {
func = def.func,
label = "/" .. cmd,
}
orig_register_chatcommand(cmd, def)
end
end
end
---
-- Start instrumenting selected functions
--
local function init()
local is_set = core.setting_getbool
if is_set("instrument.entity") or true then
-- Explicitly declare entity api-methods.
-- Simple iteration would ignore lookup via __index.
local entity_instrumentation = {
"on_activate",
"on_step",
"on_punch",
"rightclick",
"get_staticdata",
}
-- Wrap register_entity() to instrument them on registration.
local orig_register_entity = core.register_entity
core.register_entity = function(name, prototype)
local modname = get_current_modname()
for _, func_name in pairs(entity_instrumentation) do
prototype[func_name] = instrument {
func = prototype[func_name],
mod = modname,
func_name = func_name,
label = prototype.label,
}
end
orig_register_entity(name,prototype)
end
end
if is_set("instrument.abm") or true then
-- Wrap register_abm() to automatically instrument abms.
local orig_register_abm = core.register_abm
core.register_abm = function(spec)
spec.action = instrument {
func = spec.action,
class = "ABM",
label = spec.label,
}
orig_register_abm(spec)
end
end
if is_set("instrument.lbm") or true then
-- Wrap register_lbm() to automatically instrument lbms.
local orig_register_lbm = core.register_lbm
core.register_lbm = function(spec)
spec.action = instrument {
func = spec.action,
class = "LBM",
label = spec.label or spec.name,
}
orig_register_lbm(spec)
end
end
if is_set("instrument.global_callback") or true then
for func_name, _ in pairs(register_functions) do
core[func_name] = instrument_register(core[func_name], func_name)
end
end
if is_set("instrument.profiler") or false then
-- Measure overhead of instrumentation, but keep it down for functions
-- So keep the `return` for better optimization.
profiler.empty_instrument = instrument {
func = function() return end,
mod = "*profiler*",
class = "Instrumentation overhead",
label = false,
}
end
end
return {
register_functions = register_functions,
instrument = instrument,
init = init,
init_chatcommand = init_chatcommand,
}