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)
|