aboutsummaryrefslogtreecommitdiff
path: root/init.lua
blob: ca5eb206d25c1b183c0857f4a823f92cf75f7fa3 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
-- Advprofiler
-- A mod profiler written in need for a profiler for advtrains

-- (c)2019 orwell96 <orwell@bleipb.de>

advprofiler = {}

local WINDOW_SIZE = 2048

--[[

Unit table:
["unit"] = {
	-- st=step, run = one enter..leave
	st_counts = {...}		-- total count values (indexed by step)
	st_times_tot = {...}	-- total time spent in unit per step
	st_times_max = {...}	-- max time spent in single run
	st_times_avg = {...}	-- avg time spent in single run
	st_stepcount = 3		-- count of actual steps in st table*

	rn_times = {...}		-- times of individual runs in current step
	rn_runcount	= 3			-- count of actual runs in current step*
	
	rn_count = 4			-- 'count' value in current step
	
	[enter_ts = ...]		-- Timestamp when unit was last entered
}

* to prevent expensive reallocations in tables, track the current table length
	in external variables and only overwrite values.

]]

local _profs = {}

advprofiler._profilers = _profs

local function logs(t)
	minetest.log("action", "[advprofiler] "..t)
end

local function warning(prof, unit, text)
	minetest.log("warning", "[advprofiler] ("..prof.name..":"..unit..") "..text
end

local clock = os.clock

local function accumulate(list, count)
	local tot, max = 0, nil
	local li
	for i=1,count do
		li = list[i]
		tot = tot + li
		max = math.max((max or li), li)
	end
	local avg = tot/count
	return tot, avg, max
end

-- prototype for profiler instances (index metatable)
local profiler = {}

function profiler:unit_get(unit)
	if self.units[unit] then return self.units[unit] end
	-- create unit new
	self.units[unit] = {
		st_counts = {},
		st_times_tot = {...}
		st_times_max = {...}
		st_times_avg = {...}
		st_stepcount = 0,
		
		rn_times = {},
		rn_runcount = 0,
		
		rn_count = 0,
	}
end

function profiler:count(unitn, count_inc)
	local unit = self:unit_get(unitn)
	unit.rn_count = unit.rn_count + (count_inc or 1)
end

function profiler:enter(unitn, count_inc)
	local unit = self:unit_get(unitn)
	if unit.enter_ts then
		warning(self,unitn,"Unit is already entered!")
		return
	end
	unit.rn_count = unit.rn_count + (count_inc or 1)
	unit.enter_ts = clock()
end

function profiler:leave(unitn)
	local t1 = clock()
	local unit = self:unit_get(unitn)
	if not unit.enter_ts then
		warning(self,unitn,"Unit was never entered!")
		return
	end
	local td = t1 - unit.enter_ts
	if td<0 then
		warning(self,unitn,"Time difference smaller than 0 ?! td="..td)
		return
	end
	unit.rn_runcount = unit.rn_runcount + 1
	unit.rn_times[unit.rn_runcount] = td
	
	unit.enter_ts = nil
end

function profiler:end_step()
	for unitn, unit in pairs(self.units) do
		local sc = unit.st_stepcount + 1
		unit.st_counts[sc] = unit.rn_count
		local rt_tot, rt_avg, rt_max = accumulate(unit.rn_times, unit.rn_runcount)
		unit.st_times_tot = rt_tot
		unit.st_times_max = rt_max
		unit.st_times_avg = rt_avg
		unit.st_stepcount = sc
		
		unit.rn_runcount = 0
		unit.rn_count = 0
	end
end

function profiler:end_window(print_table)
	table.insert(print_table, "=== "..profiler.name.." ===")
	for unitn, unit in pairs(self.units) do
		if unit.enter_ts then
			warning(self,unitn,"Unit still entered at end of step! (discarding)")
			unit.enter_ts = nil
		end
		local sc = unit.st_stepcount
		local rep = {
			profiler = self,
			unit = unitn,
		}
		rep.count_tot, rep.count_avg, rep.count_max = accumulate(unit.st_count, sc)
		rep.time_tot, rep.time_avg, rep.time_max = accumulate(unit.st_times_tot, sc)
		
		local report_f = unit.report or advprofiler.report
		
		table.insert(print_table, unitn..": "..report_f(rep))
		
		unit.st_stepcount = 0
	end
end

--===========--

local prof_mt = {__index = profiler}
-- creates a new profiler instance and returns it
function advprofiler.new_profiler(name)
	local new = {
		name = name,
		units = {},
	}
	setmetatable(new, prof_mt)
	table.insert(_profs, new)
	logs("Registered profiler "..name)
	return new
end



function advprofiler.step()
	for _,prof in ipairs(_profs) do
		prof:end_step()
	end
end

function advprofiler.end_window_and_report(cyc)
	local print_table = {
		"--- Profiling report for cycle "..cyc.." ---"
	}
	for _,prof in ipairs(_profs) do
		prof:end_window(print_table)
	end
	
	for _,l in ipairs(print_table) do
		logs(l)
	end
end


--[[
Report table:
(all values are 'per step' ,tot=total over whole window)
rep.count_tot, rep.count_avg, rep.count_max
rep.time_tot, rep.time_avg, rep.time_max
]]


function advprofiler.report(rep)
	return string.format("Count avg=%d max=%d total=%d | Time avg=%3fms max=%3fms total=%3fms"
		rep.count_avg, rep.count_max, rep.count_tot,
		rep.time_avg, rep.time_max, rep.time_tot)
end


--===========--

local stepcnt = 0
local cyccnt = 0

minetest.register_globalstep(function(dtime)
	
	advprofiler.step()
	
	stepcnt = (stepcnt + 1) % WINDOW_SIZE
	
	if stepcnt == 0 then
		cyccnt = cyccnt + 1
		advprofiler.end_window_and_report(cyccnt)
	end
	
end)