2
0

sampling.lua 5.8 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206
  1. --Minetest
  2. --Copyright (C) 2016 T4im
  3. --
  4. --This program is free software; you can redistribute it and/or modify
  5. --it under the terms of the GNU Lesser General Public License as published by
  6. --the Free Software Foundation; either version 2.1 of the License, or
  7. --(at your option) any later version.
  8. --
  9. --This program is distributed in the hope that it will be useful,
  10. --but WITHOUT ANY WARRANTY; without even the implied warranty of
  11. --MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  12. --GNU Lesser General Public License for more details.
  13. --
  14. --You should have received a copy of the GNU Lesser General Public License along
  15. --with this program; if not, write to the Free Software Foundation, Inc.,
  16. --51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
  17. local setmetatable = setmetatable
  18. local pairs, format = pairs, string.format
  19. local min, max, huge = math.min, math.max, math.huge
  20. local core = core
  21. local profiler = ...
  22. -- Split sampler and profile up, to possibly allow for rotation later.
  23. local sampler = {}
  24. local profile
  25. local stats_total
  26. local logged_time, logged_data
  27. local _stat_mt = {
  28. get_time_avg = function(self)
  29. return self.time_all/self.samples
  30. end,
  31. get_part_avg = function(self)
  32. if not self.part_all then
  33. return 100 -- Extra handling for "total"
  34. end
  35. return self.part_all/self.samples
  36. end,
  37. }
  38. _stat_mt.__index = _stat_mt
  39. function sampler.reset()
  40. -- Accumulated logged time since last sample.
  41. -- This helps determining, the relative time a mod used up.
  42. logged_time = 0
  43. -- The measurements taken through instrumentation since last sample.
  44. logged_data = {}
  45. profile = {
  46. -- Current mod statistics (max/min over the entire mod lifespan)
  47. -- Mod specific instrumentation statistics are nested within.
  48. stats = {},
  49. -- Current stats over all mods.
  50. stats_total = setmetatable({
  51. samples = 0,
  52. time_min = huge,
  53. time_max = 0,
  54. time_all = 0,
  55. part_min = 100,
  56. part_max = 100
  57. }, _stat_mt)
  58. }
  59. stats_total = profile.stats_total
  60. -- Provide access to the most recent profile.
  61. sampler.profile = profile
  62. end
  63. ---
  64. -- Log a measurement for the sampler to pick up later.
  65. -- Keep `log` and its often called functions lean.
  66. -- It will directly add to the instrumentation overhead.
  67. --
  68. function sampler.log(modname, instrument_name, time_diff)
  69. if time_diff <= 0 then
  70. if time_diff < 0 then
  71. -- This **might** have happened on a semi-regular basis with huge mods,
  72. -- resulting in negative statistics (perhaps midnight time jumps or ntp corrections?).
  73. core.log("warning", format(
  74. "Time travel of %s::%s by %dµs.",
  75. modname, instrument_name, time_diff
  76. ))
  77. end
  78. -- Throwing these away is better, than having them mess with the overall result.
  79. return
  80. end
  81. local mod_data = logged_data[modname]
  82. if mod_data == nil then
  83. mod_data = {}
  84. logged_data[modname] = mod_data
  85. end
  86. mod_data[instrument_name] = (mod_data[instrument_name] or 0) + time_diff
  87. -- Update logged time since last sample.
  88. logged_time = logged_time + time_diff
  89. end
  90. ---
  91. -- Return a requested statistic.
  92. -- Initialize if necessary.
  93. --
  94. local function get_statistic(stats_table, name)
  95. local statistic = stats_table[name]
  96. if statistic == nil then
  97. statistic = setmetatable({
  98. samples = 0,
  99. time_min = huge,
  100. time_max = 0,
  101. time_all = 0,
  102. part_min = 100,
  103. part_max = 0,
  104. part_all = 0,
  105. }, _stat_mt)
  106. stats_table[name] = statistic
  107. end
  108. return statistic
  109. end
  110. ---
  111. -- Update a statistic table
  112. --
  113. local function update_statistic(stats_table, time)
  114. stats_table.samples = stats_table.samples + 1
  115. -- Update absolute time (µs) spend by the subject
  116. stats_table.time_min = min(stats_table.time_min, time)
  117. stats_table.time_max = max(stats_table.time_max, time)
  118. stats_table.time_all = stats_table.time_all + time
  119. -- Update relative time (%) of this sample spend by the subject
  120. local current_part = (time/logged_time) * 100
  121. stats_table.part_min = min(stats_table.part_min, current_part)
  122. stats_table.part_max = max(stats_table.part_max, current_part)
  123. stats_table.part_all = stats_table.part_all + current_part
  124. end
  125. ---
  126. -- Sample all logged measurements each server step.
  127. -- Like any globalstep function, this should not be too heavy,
  128. -- but does not add to the instrumentation overhead.
  129. --
  130. local function sample(dtime)
  131. -- Rare, but happens and is currently of no informational value.
  132. if logged_time == 0 then
  133. return
  134. end
  135. for modname, instruments in pairs(logged_data) do
  136. local mod_stats = get_statistic(profile.stats, modname)
  137. if mod_stats.instruments == nil then
  138. -- Current statistics for each instrumentation component
  139. mod_stats.instruments = {}
  140. end
  141. local mod_time = 0
  142. for instrument_name, time in pairs(instruments) do
  143. if time > 0 then
  144. mod_time = mod_time + time
  145. local instrument_stats = get_statistic(mod_stats.instruments, instrument_name)
  146. -- Update time of this sample spend by the instrumented function.
  147. update_statistic(instrument_stats, time)
  148. -- Reset logged data for the next sample.
  149. instruments[instrument_name] = 0
  150. end
  151. end
  152. -- Update time of this sample spend by this mod.
  153. update_statistic(mod_stats, mod_time)
  154. end
  155. -- Update the total time spend over all mods.
  156. stats_total.time_min = min(stats_total.time_min, logged_time)
  157. stats_total.time_max = max(stats_total.time_max, logged_time)
  158. stats_total.time_all = stats_total.time_all + logged_time
  159. stats_total.samples = stats_total.samples + 1
  160. logged_time = 0
  161. end
  162. ---
  163. -- Setup empty profile and register the sampling function
  164. --
  165. function sampler.init()
  166. sampler.reset()
  167. if core.settings:get_bool("instrument.profiler") then
  168. core.register_globalstep(function()
  169. if logged_time == 0 then
  170. return
  171. end
  172. return profiler.empty_instrument()
  173. end)
  174. core.register_globalstep(profiler.instrument {
  175. func = sample,
  176. mod = "*profiler*",
  177. class = "Sampler (update stats)",
  178. label = false,
  179. })
  180. else
  181. core.register_globalstep(sample)
  182. end
  183. end
  184. return sampler