1 files changed, 206 insertions, 0 deletions
diff --git a/builtin/profiler/sampling.lua b/builtin/profiler/sampling.lua
new file mode 100644
index 000000000..1d1ef256d
--- /dev/null
+++ b/builtin/profiler/sampling.lua
@@ -0,0 +1,206 @@
+--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 setmetatable = setmetatable
+local pairs, format = pairs, string.format
+local min, max, huge = math.min, math.max, math.huge
+local core = core
+
+local profiler = ...
+-- Split sampler and profile up, to possibly allow for rotation later.
+local sampler = {}
+local profile
+local stats_total
+local logged_time, logged_data
+
+local _stat_mt = {
+	get_time_avg = function(self)
+		return self.time_all/self.samples
+	end,
+	get_part_avg = function(self)
+		if not self.part_all then
+			return 100 -- Extra handling for "total"
+		end
+		return self.part_all/self.samples
+	end,
+}
+_stat_mt.__index = _stat_mt
+
+function sampler.reset()
+	-- Accumulated logged time since last sample.
+	-- This helps determining, the relative time a mod used up.
+	logged_time = 0
+	-- The measurements taken through instrumentation since last sample.
+	logged_data = {}
+
+	profile = {
+		-- Current mod statistics (max/min over the entire mod lifespan)
+		-- Mod specific instrumentation statistics are nested within.
+		stats = {},
+		-- Current stats over all mods.
+		stats_total = setmetatable({
+			samples = 0,
+			time_min = huge,
+			time_max = 0,
+			time_all = 0,
+			part_min = 100,
+			part_max = 100
+		}, _stat_mt)
+	}
+	stats_total = profile.stats_total
+
+	-- Provide access to the most recent profile.
+	sampler.profile = profile
+end
+
+---
+-- Log a measurement for the sampler to pick up later.
+-- Keep `log` and its often called functions lean.
+-- It will directly add to the instrumentation overhead.
+--
+function sampler.log(modname, instrument_name, time_diff)
+	if time_diff <= 0 then
+		if time_diff < 0 then
+			-- This **might** have happened on a semi-regular basis with huge mods,
+			-- resulting in negative statistics (perhaps midnight time jumps or ntp corrections?).
+			core.log("warning", format(
+					"Time travel of %s::%s by %dµs.",
+					modname, instrument_name, time_diff
+			))
+		end
+		-- Throwing these away is better, than having them mess with the overall result.
+		return
+	end
+
+	local mod_data = logged_data[modname]
+	if mod_data == nil then
+		mod_data = {}
+		logged_data[modname] = mod_data
+	end
+
+	mod_data[instrument_name] = (mod_data[instrument_name] or 0) + time_diff
+	-- Update logged time since last sample.
+	logged_time = logged_time + time_diff
+end
+
+---
+-- Return a requested statistic.
+-- Initialize if necessary.
+--
+local function get_statistic(stats_table, name)
+	local statistic = stats_table[name]
+	if statistic == nil then
+		statistic = setmetatable({
+			samples = 0,
+			time_min = huge,
+			time_max = 0,
+			time_all = 0,
+			part_min = 100,
+			part_max = 0,
+			part_all = 0,
+		}, _stat_mt)
+		stats_table[name] = statistic
+	end
+	return statistic
+end
+
+---
+-- Update a statistic table
+--
+local function update_statistic(stats_table, time)
+	stats_table.samples = stats_table.samples + 1
+
+	-- Update absolute time (µs) spend by the subject
+	stats_table.time_min = min(stats_table.time_min, time)
+	stats_table.time_max = max(stats_table.time_max, time)
+	stats_table.time_all = stats_table.time_all + time
+
+	-- Update relative time (%) of this sample spend by the subject
+	local current_part = (time/logged_time) * 100
+	stats_table.part_min = min(stats_table.part_min, current_part)
+	stats_table.part_max = max(stats_table.part_max, current_part)
+	stats_table.part_all = stats_table.part_all + current_part
+end
+
+---
+-- Sample all logged measurements each server step.
+-- Like any globalstep function, this should not be too heavy,
+-- but does not add to the instrumentation overhead.
+--
+local function sample(dtime)
+	-- Rare, but happens and is currently of no informational value.
+	if logged_time == 0 then
+		return
+	end
+
+	for modname, instruments in pairs(logged_data) do
+		local mod_stats = get_statistic(profile.stats, modname)
+		if mod_stats.instruments == nil then
+			-- Current statistics for each instrumentation component
+			mod_stats.instruments = {}
+		end
+
+		local mod_time = 0
+		for instrument_name, time in pairs(instruments) do
+			if time > 0 then
+				mod_time = mod_time + time
+				local instrument_stats = get_statistic(mod_stats.instruments, instrument_name)
+
+				-- Update time of this sample spend by the instrumented function.
+				update_statistic(instrument_stats, time)
+				-- Reset logged data for the next sample.
+				instruments[instrument_name] = 0
+			end
+		end
+
+		-- Update time of this sample spend by this mod.
+		update_statistic(mod_stats, mod_time)
+	end
+
+	-- Update the total time spend over all mods.
+	stats_total.time_min = min(stats_total.time_min, logged_time)
+	stats_total.time_max = max(stats_total.time_max, logged_time)
+	stats_total.time_all = stats_total.time_all + logged_time
+
+	stats_total.samples = stats_total.samples + 1
+	logged_time = 0
+end
+
+---
+-- Setup empty profile and register the sampling function
+--
+function sampler.init()
+	sampler.reset()
+
+	if core.setting_getbool("instrument.profiler") then
+		core.register_globalstep(function()
+			if logged_time == 0 then
+				return
+			end
+			return profiler.empty_instrument()
+		end)
+		core.register_globalstep(profiler.instrument {
+			func = sample,
+			mod = "*profiler*",
+			class = "Sampler (update stats)",
+			label = false,
+		})
+	else
+		core.register_globalstep(sample)
+	end
+end
+
+return sampler