dofile(minetest.get_modpath("profnsched").."/queue.lua") dofile(minetest.get_modpath("profnsched").."/after.lua") local durations = {} local active = minetest.setting_get("profnsched_activate") local dump_delay = minetest.setting_get("profnsched_dump_delay") if not active then active = false end if not dump_delay then dump_delay = 60*5 end local mathfloor = math.floor -- Usefull funcs local function dump_durations(current) --param: current durations or nil (to dump global durations) if current then local avg = 0 local dt = 0 for i,v in pairs(current) do dt = mathfloor(v[3])/1000 avg = mathfloor(durations[v[1]][v[2]].us/durations[v[1]][v[2]].n)/1000 minetest.log("[Profnsched] "..dt.."ms (avg: "..avg.." ; "..durations[v[1]][v[2]].n.." calls) "..v[1].." "..v[2]) end else for i,md in pairs(durations) do for j,fn in pairs(md) do avg = mathfloor(fn.us/fn.n)/1000 minetest.log("[Profnsched] avg: "..avg.." ; "..fn.n.." calls ; "..i.." "..j) end end end end local function activate() if active then if dump_delay ~= 0 then minetest.log("[Profnsched] Will dump global stats in "..dump_delay.."s") minetest.after(dump_delay, dump_durations) else minetest.log("[Profnsched] Now will dump RT stats") end end end activate() minetest.register_chatcommand("profnsched", { params = "", description = "Activate mods profiling", func = function(name, param) active = true if param == "" then dump_delay = minetest.setting_get("profnsched_dump_delay") if not dump_delay then dump_delay = 60*5 end else dump_delay = tonumber(param) end activate() end }) local function update_durations(mod_name, func_id, dtime) if not durations[mod_name] then durations[mod_name] = {} end if not durations[mod_name][func_id] then durations[mod_name][func_id] = { us = 0, n = 0, cur = 0 } end durations[mod_name][func_id].us = durations[mod_name][func_id].us + dtime durations[mod_name][func_id].n = durations[mod_name][func_id].n + 1 durations[mod_name][func_id].cur = dtime end -------------------------------------------------------------- -- Move olds globalsteps and redefine minetest internal caller local gs = {} -- global_steps (moved here) for i,f in ipairs(minetest.registered_globalsteps) do gs[#gs+1] = { mod_name = "unknown"..i, func_id = "unknown(globalstep)", func_code = f } minetest.registered_globalsteps[i] = nil end local old_globalstep = minetest.register_globalstep function minetest.register_globalstep(func) gs[#gs+1] = { mod_name = core.get_last_run_mod(), func_id = "unknown(globalstep)", func_code = func } end -- Main code local last_elapsed_local_dtime = 0 local last_internal_server_dtime = 0 local tick_dtime = minetest.setting_get("dedicated_server_step")*1000000 old_globalstep(function(dtime) local begin_time = core.get_us_time() last_internal_server_dtime = dtime*1000000 - last_elapsed_local_dtime local launch_dtime = begin_time - last_internal_server_dtime local current_durations = {} current_durations[1] = {"Internal SERVER", "& unprofiled", last_internal_server_dtime} local tbegin = 0 -- Globalsteps for i,v in pairs(gs) do tbegin = core.get_us_time() v.func_code(dtime+(core.get_us_time()-tbegin)/1000000) if active then current_durations[#current_durations+1] = {v.mod_name, v.func_id, core.get_us_time()-tbegin} end end -- Others jobs local njb = scheduler.waitingjobs() local jbdone = 0 for class,q in ipairs(scheduler.queue) do --local grp = q.cur for i,job in pairs(q.cur) do tbegin = core.get_us_time() core.set_last_run_mod(job.mod_name) job.func_code(unpack(job.arg)) jbdone = jbdone+1 current_durations[#current_durations+1] = {job.mod_name, job.func_id, core.get_us_time()-tbegin} q.cur[i] = nil if class > 1 and ((core.get_us_time()-launch_dtime) > tick_dtime) then --class 1 fully processed even on overload break end end if ((core.get_us_time()-launch_dtime) > tick_dtime) then break end end --minetest.debug("[Profnsched] "..scheduler.waitingjobs()+getnjobs()) scheduler.shift() --minetest.debug("[Profnsched] "..scheduler.waitingjobs()+getnjobs()) local elapsed = (core.get_us_time()-launch_dtime) -- update all durations for i,v in pairs(current_durations) do update_durations(v[1], v[2], v[3]) end if (elapsed > tick_dtime) then --overload ? if last_internal_server_dtime < tick_dtime then -- caused by profiled mods ? if active and dump_delay == 0 then minetest.log("[Profnsched] Overload ! "..mathfloor(elapsed)/1000 .."ms") dump_durations(current_durations) --scheduler.fulldebug() end else if active and dump_delay == 0 then minetest.log("[Profnsched] Overload ! Caused by server or not profiled mods : "..mathfloor(last_internal_server_dtime)/1000 .."ms") end end end for i,v in pairs(current_durations) do current_durations[i] = nil end last_elapsed_local_dtime = core.get_us_time() - begin_time end)