instrumentation.lua 7.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253
  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 format, pairs, type = string.format, pairs, type
  18. local core, get_current_modname = core, core.get_current_modname
  19. local profiler, sampler, get_bool_default = ...
  20. local instrument_builtin = get_bool_default("instrument.builtin", false)
  21. local register_functions = {
  22. register_globalstep = 0,
  23. register_playerevent = 0,
  24. register_on_placenode = 0,
  25. register_on_dignode = 0,
  26. register_on_punchnode = 0,
  27. register_on_generated = 0,
  28. register_on_newplayer = 0,
  29. register_on_dieplayer = 0,
  30. register_on_respawnplayer = 0,
  31. register_on_prejoinplayer = 0,
  32. register_on_joinplayer = 0,
  33. register_on_leaveplayer = 0,
  34. register_on_cheat = 0,
  35. register_on_chat_message = 0,
  36. register_on_player_receive_fields = 0,
  37. register_on_craft = 0,
  38. register_craft_predict = 0,
  39. register_on_protection_violation = 0,
  40. register_on_item_eat = 0,
  41. register_on_punchplayer = 0,
  42. register_on_player_hpchange = 0,
  43. register_on_mapblocks_changed = 0,
  44. }
  45. local function regex_escape(s)
  46. return s:gsub("(%W)", "%%%1")
  47. end
  48. ---
  49. -- Create an unique instrument name.
  50. -- Generate a missing label with a running index number.
  51. --
  52. local counts = {}
  53. local worldmods_path = regex_escape(core.get_worldpath())
  54. local user_path = regex_escape(core.get_user_path())
  55. local builtin_path = regex_escape(core.get_builtin_path())
  56. local function generate_name(def)
  57. local class, label, func_name = def.class, def.label, def.func_name
  58. if label then
  59. if class or func_name then
  60. return format("%s '%s' %s", class or "", label, func_name or ""):trim()
  61. end
  62. return format("%s", label):trim()
  63. elseif label == false then
  64. return format("%s", class or func_name):trim()
  65. end
  66. local index_id = def.mod .. (class or func_name)
  67. local index = counts[index_id] or 1
  68. counts[index_id] = index + 1
  69. local info = debug.getinfo(def.func)
  70. local modpath = regex_escape(core.get_modpath(def.mod) or "")
  71. local source = info.source
  72. if modpath ~= "" then
  73. source = source:gsub(modpath, def.mod)
  74. end
  75. source = source:gsub(worldmods_path, "")
  76. source = source:gsub(builtin_path, "builtin" .. DIR_DELIM)
  77. source = source:gsub(user_path, "")
  78. return format("%s[%d] %s#%s", class or func_name, index, source, info.linedefined)
  79. end
  80. ---
  81. -- Keep `measure` and the closure in `instrument` lean, as these, and their
  82. -- directly called functions are the overhead that is caused by instrumentation.
  83. --
  84. local time, log = core.get_us_time, sampler.log
  85. local function measure(modname, instrument_name, start, ...)
  86. log(modname, instrument_name, time() - start)
  87. return ...
  88. end
  89. --- Automatically instrument a function to measure and log to the sampler.
  90. -- def = {
  91. -- mod = "",
  92. -- class = "",
  93. -- func_name = "",
  94. -- -- if nil, will create a label based on registration order
  95. -- label = "" | false,
  96. -- }
  97. local function instrument(def)
  98. if not def or not def.func then
  99. return
  100. end
  101. def.mod = def.mod or get_current_modname() or "??"
  102. local modname = def.mod
  103. local instrument_name = generate_name(def)
  104. local func = def.func
  105. if not instrument_builtin and modname == "*builtin*" then
  106. return func
  107. end
  108. return function(...)
  109. -- This tail-call allows passing all return values of `func`
  110. -- also called https://en.wikipedia.org/wiki/Continuation_passing_style
  111. -- Compared to table creation and unpacking it won't lose `nil` returns
  112. -- and is expected to be faster
  113. -- `measure` will be executed after func(...)
  114. local start = time()
  115. return measure(modname, instrument_name, start, func(...))
  116. end
  117. end
  118. local function can_be_called(func)
  119. -- It has to be a function or callable table
  120. return type(func) == "function" or
  121. ((type(func) == "table" or type(func) == "userdata") and
  122. getmetatable(func) and getmetatable(func).__call)
  123. end
  124. local function assert_can_be_called(func, func_name, level)
  125. if not can_be_called(func) then
  126. -- Then throw an *helpful* error, by pointing on our caller instead of us.
  127. error(format("Invalid argument to %s. Expected function-like type instead of '%s'.",
  128. func_name, type(func)), level + 1)
  129. end
  130. end
  131. ---
  132. -- Wraps a registration function `func` in such a way,
  133. -- that it will automatically instrument any callback function passed as first argument.
  134. --
  135. local function instrument_register(func, func_name)
  136. local register_name = func_name:gsub("^register_", "", 1)
  137. return function(callback, ...)
  138. assert_can_be_called(callback, func_name, 2)
  139. register_functions[func_name] = register_functions[func_name] + 1
  140. return func(instrument {
  141. func = callback,
  142. func_name = register_name
  143. }, ...)
  144. end
  145. end
  146. local function init_chatcommand()
  147. if get_bool_default("instrument.chatcommand", true) then
  148. local orig_register_chatcommand = core.register_chatcommand
  149. core.register_chatcommand = function(cmd, def)
  150. def.func = instrument {
  151. func = def.func,
  152. label = "/" .. cmd,
  153. }
  154. orig_register_chatcommand(cmd, def)
  155. end
  156. end
  157. end
  158. ---
  159. -- Start instrumenting selected functions
  160. --
  161. local function init()
  162. if get_bool_default("instrument.entity", true) then
  163. -- Explicitly declare entity api-methods.
  164. -- Simple iteration would ignore lookup via __index.
  165. local entity_instrumentation = {
  166. "on_activate",
  167. "on_deactivate",
  168. "on_step",
  169. "on_punch",
  170. "on_rightclick",
  171. "get_staticdata",
  172. }
  173. -- Wrap register_entity() to instrument them on registration.
  174. local orig_register_entity = core.register_entity
  175. core.register_entity = function(name, prototype)
  176. local modname = get_current_modname()
  177. for _, func_name in pairs(entity_instrumentation) do
  178. prototype[func_name] = instrument {
  179. func = prototype[func_name],
  180. mod = modname,
  181. func_name = func_name,
  182. label = prototype.label,
  183. }
  184. end
  185. orig_register_entity(name,prototype)
  186. end
  187. end
  188. if get_bool_default("instrument.abm", true) then
  189. -- Wrap register_abm() to automatically instrument abms.
  190. local orig_register_abm = core.register_abm
  191. core.register_abm = function(spec)
  192. spec.action = instrument {
  193. func = spec.action,
  194. class = "ABM",
  195. label = spec.label,
  196. }
  197. orig_register_abm(spec)
  198. end
  199. end
  200. if get_bool_default("instrument.lbm", true) then
  201. -- Wrap register_lbm() to automatically instrument lbms.
  202. local orig_register_lbm = core.register_lbm
  203. core.register_lbm = function(spec)
  204. local k = spec.bulk_action ~= nil and "bulk_action" or "action"
  205. spec[k] = instrument {
  206. func = spec[k],
  207. class = "LBM",
  208. label = spec.label or spec.name,
  209. }
  210. orig_register_lbm(spec)
  211. end
  212. end
  213. if get_bool_default("instrument.global_callback", true) then
  214. for func_name, _ in pairs(register_functions) do
  215. core[func_name] = instrument_register(core[func_name], func_name)
  216. end
  217. end
  218. if get_bool_default("instrument.profiler", false) then
  219. -- Measure overhead of instrumentation, but keep it down for functions
  220. -- So keep the `return` for better optimization.
  221. profiler.empty_instrument = instrument {
  222. func = function() return end,
  223. mod = "*profiler*",
  224. class = "Instrumentation overhead",
  225. label = false,
  226. }
  227. end
  228. end
  229. return {
  230. register_functions = register_functions,
  231. instrument = instrument,
  232. init = init,
  233. init_chatcommand = init_chatcommand,
  234. }