gistfile1.txt

-- requirement helper funcs
if cechowin == nil then
  function cechowin(win,s)
    if s ~= nil then
    	for colour, text in string.gmatch("<white>"..s, "<([a-z_]+)>([^<>]+)") do
        if color_table[colour] ~= nil and color_table[colour][1] ~= nil then
      		setFgColor(win, color_table[colour][1], color_table[colour][2], color_table[colour][3])
      		echo(win,text)
        else
      		echo(win,text)
        end
    	end
    end
  	--echo(win,"\n")
  end
end


-- initial tables
function timing_init(force)
  if force ~= nil and force == true then
    timing_ctx = nil
  end
  
  if timing_ctx == nil then
    timing_ctx = {}
    timing_ctx.hooks = {}
    timing_ctx.originals = {}
    timing_ctx.data = {}
    timing_ctx.info = {}
    timing_ctx.func_id = 1
    timing_ctx.ids = {}
    timing_ctx.paths = {}
    timing_ctx.gvars = {}
    timing_ctx.counts = {}
    timing_ctx.hooked = {}
    --cecho("timing tables initialized")
  end
end

-- feed script to eval to load()
function timing_load_helper()
  if bfunc_data == nil then return nil end
  if table.size(bfunc_data) == 0 then return nil end
  return table.remove(bfunc_data, 1)
end

function timing_can_hook(func_name, path)
  excludes = {"table","getEpoch","tonumber","tostring","pack","unpack","loadstring","echo","decho","type","math","pcall","string",
  "debug","pairs","ipairs","dofile","print","pcall","wait","coroutine","rex","collectgarbage","luasql","display"}

  --cecho("timing can hook: "..tostring(func_name).." path "..tostring(path).."\n")
  
  -- paths are strings...
  if path ~= nil then
    vcmp2 = loadstring("return "..path)()
    for i,n in pairs(excludes) do
      if string.find(path, n, nil, true) ~= nil then
        return false
      end
      -- maybe they localized the cmds, lets verify -- like.. local tbl = table.. lets cross match
      vcmp = _G[n]
      if vcmp ~= nil then
        if vcmp == vcmp2 then
          return false
        end
      end
    end
  else
    for i,n in pairs(excludes) do
      if n == func_name then
        return false
      end
    end
  end
  
  return true
end

-- build the wrapper function which monitors timing of a target and logs to a table
function timing_make_wrapper(func_name_a, path)  
  if path == nil then
    func_name = tostring(func_name_a)
  else
    func_name = path
  end

  if timing_can_hook(func_name_a, path) == false then
    --cecho("cant hook "..func_name.."\n")
    return
  end

    if timing_ctx.hooked[func_name] ~= nil then
      --cecho(func_name.." already hooked\n")
      return
    end
    
  
  func_id = tostring(timing_ctx.func_id)
  
  timing_ctx.func_id = timing_ctx.func_id + 1
  
  if path == nil then

    if string.find(func_path, "timing", nil, true) ~= nil then
      -- dont hook self
      return
    end
    
    -- keep a pointer to the original function so we can call it and proxxy data
    timing_ctx.originals["f"..func_id] = _G[func_name]  
    timing_ctx.info["f"..func_id] = debug.getinfo(_G[func_name])
    timing_ctx.gvars["f"..func_id] = func_name
  else
  
    if string.find(path, "timing", nil, true) ~= nil then
      -- dont hook self
      return
    end
    
    timing_ctx.paths["f"..func_id] = path
    timing_ctx.originals["f"..func_id] =  loadstring("return "..path)()
    timing_ctx.info["f"..func_id] = loadstring("return debug.getinfo("..path..")")()
  end
  
  bfunc_data = {}
  
  -- this is our replaced function..
  table.insert(bfunc_data, "function timing_ctx.hooks.f"..func_id.."(...)\n")
  -- get timestamp before
  table.insert(bfunc_data, "  local tsstart = getEpoch()\n")
  -- call original function
  table.insert(bfunc_data, "  local ret = {timing_ctx.originals[\"f"..func_id.."\"](...)}\n")
  -- get timestamp after...
  table.insert(bfunc_data, "  local tsend = getEpoch()\n")
  -- calculate total time in the function
  table.insert(bfunc_data, "  local ttotal = tonumber(tsend - tsstart)\n")
  -- ignore things which are 0, but all else...
  
  --table.insert(bfunc_data, "  if ttotal > 0 then\n")
  -- ensure this func id has a table in the results, if not then create it
  table.insert(bfunc_data, "    timing_ctx.data[\"f"..func_id.."\"] = timing_ctx.data[\"f"..func_id.."\"] or {}\n")
  -- insert this timing result into that table for later usage
  table.insert(bfunc_data, "    table.insert(timing_ctx.data[\"f"..func_id.."\"], tonumber(tsend-tsstart))\n")
  --table.insert(bfunc_data, "  end\n")
  
  -- increase count for this func
  table.insert(bfunc_data, "  timing_ctx.counts[\"f"..func_id.."\"] = timing_ctx.counts[\"f"..func_id.."\"] or 0\n")  
  table.insert(bfunc_data, "  timing_ctx.counts[\"f"..func_id.."\"] = timing_ctx.counts[\"f"..func_id.."\"] + 1\n")  
  -- return the results from the original functon to the callee
  table.insert(bfunc_data, "  return unpack(ret)\n")
  
  table.insert(bfunc_data, "end\n")
  
  local compiled, errorMessage = load(timing_load_helper)
  if compiled then
    -- execute the eval'd code (to actually declare it as a global usable function..)
    compiled()
  else
  	-- this will most likely happen because of a syntax error
  	cecho("Error load string fail:"..errorMessage)
  end  
  
  if timing_ctx.hooks["f"..func_id] == nil then
    cechowin("building hook func didnt work")
    return
  end
  
  --cecho("hooking "..func_name.. " id "..func_id.."\n")
  -- redirect original functions value to the new hook function
  --timing_ctx.hooks[func_name] = _G[func_name.."_hook"]
  --_G[func_name.."_hook"] = nil
  
  if path == nil then
    _G[func_name] = timing_ctx.hooks["f"..func_id]
  else
    loadstring(path.." = timing_ctx.hooks[\"f"..func_id.."\"]")()
  end
  timing_ctx.hooked[func_name] = 1
  
  return true
end


function timing_unwrap(hfunc)
  if timing_ctx.hooks[hfunc] == nil then
    cecho("cannot unhook "..hfunc.." .. theres on hook there\n")
    return
  end

  if timing_ctx.paths[hfunc] == nil then
    _G[timing_ctx.gvars[hfunc]] = timing_ctx.originals[hfunc]
    timing_ctx.hooked[timing_ctx.gvars[hfunc]] = nil
  else
    loadstring(timing_ctx.paths[hfunc] .. " = timing_ctx.originals[\""..hfunc.."\"]")()
    timing_ctx.hooked[timing_ctx.paths[hfunc]] = nil
  end

    timing_ctx.hooks[hfunc] = nil
    timing_ctx.originals[hfunc] = nil
    
    -- these two needed for results even after unhooking
    --timing_ctx.gvars[hfunc] = nil
    --timing_ctx.paths[hfunc] = nil
  
  --cecho("unhooked "..hfunc)
end

function timing_unhook_all()
  to_unhook = table.keys(timing_ctx.hooks)
  
  for _,n in pairs(to_unhook) do
    pcall(timing_unwrap,n)
  end
  
  cechowin("Timing","all unhooked\n")
end

-- was the first method of hooking, but didnt cover a scripts.. function Battle.Init() for instance.. 
function timing_hook_by_name(namestr)
  for _,n in pairs(table.keys(_G)) do
    if string.find(n, namestr, nil, true) ~= nil and string.find(n, "hook", nil, true) == nil and string.find(n, "original", nil, true) == nil and string.find(n, "temp", nil,true) == nil then
      gtype = type(_G[n])
      if gtype == "function" then
        timing_make_wrapper(n)
      else
        if gtype == "table" then
          -- recurse table and hook...
        end
      end
    end
  end
 end

-- was first method for hooking, but may be useful later for someone...
function timing_hook_em_all()
  timing_hook_by_name("Alias")
  timing_hook_by_name("Trig")
end



-- create window for giving information
function timing_win()
  if ATimingWindow == nil or TimingWin == nil then
    ATimingWindow = nil
    TimingWin = nil
    ATimingWindow = ATimingWindow or Adjustable.Container:new({name = 'Timing', x = '25%', y = '5%', width = '15%', height = '25%', titleTxtColor ='Red'}) 
    ATimingWindow:setTitle("Timing")
    TimingWin = TimingWin or Geyser.MiniConsole:new({name = "Timing",  x=0, y=0,  autoWrap = true,  color = "black", fontSize = 12,  width="100%", height="100%",}, ATimingWindow)
  else
    ATimingWindow:show()
  end  
  

end



function timing_hook_recurse(p_path, depth, var, p_var_name)
  local path = p_path
  local var_name = p_var_name

  -- dont go too deep into _G.. this allows hooking some scripts which use function Blah.Blah() but not too far
  -- it required a complete rewrite of the wrapping, since it has to do 'paths' instead of direct _G[func_name] for this
  if depth > 3 then return end
  
  -- path starts as _G.. the rest s _G[sub_depth][...]
  if string.len(var_name) > 0 then
    path = path.."[\""..var_name.."\"]"
  else
    path = "_G"
  end
  

  -- enumerate all keys in the var, and check if its a func of interest
  for i,n in pairs(table.keys(var)) do
    -- wrapping in pcall() since some metatables/etc were having exceptions..
    pcall(function()
      if n ~= "_G" then
        -- if its a table, then lets go into it and determine if we want to hook anything
        if type(var[n]) == "table" then
          pcall(timing_hook_recurse,path, depth + 1, var[n], n)
        end
        if type(var[n]) == "function" then
          fpath = path.."[\""..n.."\"]"
          --display(fpath)
          -- obtain debugging information relating to this path
          dtest = loadstring("return debug.getinfo("..fpath..")")()
          --cecho(fpath.." "..dtest.source.."\n")
          -- These are the particular sources from debug information that we want to hook... User related things :)
          if 1==1 or (string.find(dtest.source,"Script:", nil, true) ~= nil or
              string.find(dtest.source,"Alias:", nil, true) ~= nil or
                string.find(dtest.source,"Trigger:", nil, true) ~= nil) then
                  -- call the hooking function on this particular path
                  table.insert(timing_ctx_hook_queue, fpath)
--                  timing_make_wrapper(fpath, fpath)
          end
        end
      end
    end)
  end
end

-- for some reason hooking them all in a loop will lock up mudlet...
function timing_ctx_hook_slow()
  fpath = table.remove(timing_ctx_hook_queue,1)
  if fpath ~= nil then
    if timing_make_wrapper(fpath, fpath) == true then
    end
  end
  if table.size(timing_ctx_hook_queue) > 0 then
    tempTimer(0.0001, [[ timing_ctx_hook_slow() ]], false)
  else
    --timing_win_default()
    cechowin("Timing","All hooked\n")
  end
end

function timing_hook_all()
  timing_ctx_hook_queue = {}
  -- start recursing the global variables to find functions to hook
  timing_hook_recurse("", 1, _G, "")
  
  if table.size(timing_ctx_hook_queue) > 0 then
    timing_ctx_hook_slow()
  end
end

function timing_win_default()
  timing_win()
  ATimingWindow:show()
  clearWindow("Timing")
  hcount = table.size(timing_ctx.hooks)
  cechowin("Timing",hcount.." hooked...")
  
  cechoLink("Timing","<red>hook", [[
    timing_hook_all()    
    ]], "hook funcs", true)
    
  cechowin("Timing","   ")
  
  cechoLink("Timing","<orange>unhook", [[
    timing_unhook_all()
    ]], "unhook funcs", true)
    
  cechowin("Timing","   ")
  
  --if hcount > 0 then
  cechoLink("Timing","<green>results", [[
    timing_results()
  ]], "unhook funcs", true)
    
  cechowin("Timing","   ")    

  cechoLink("Timing","<green>Reset stats", [[
    timing_ctx.data = {}
    timing_ctx.counts = {}
    cechowin("Timing","results cleared\n")
    
  ]], "unhook funcs", true)

  --end
  cechowin("Timing","\n")
end

function timing_results()
  -- ensure the window exists      
  timing_win_default()
  
  local totals = {}
  local all = {}
  
  for i,n in pairs(timing_ctx.data) do
    table.insert(all, i)
    totals[i] = 0
    for i2,n2 in pairs(n) do
      totals[i] = totals[i] + n2
    end
  end
  
  cechowin("Timing", table.size(all).." total funcs logged\n")
  
  table.sort(all, function(a,b) return totals[a] > totals[b] end)
  
  for i,n in pairs(all) do  
    if i < 30 then
      fname = n
      if timing_ctx.gvars[n] ~= nil then
        fname = timing_ctx.gvars[n]
      end
      if timing_ctx.paths[n] ~= nil then
        fname = timing_ctx.paths[n]
      end
      cechowin("Timing",fname.." time "..totals[n].." count "..timing_ctx.counts[n].." source: "..string.sub(timing_ctx.info[n].source,1,15).."\n")
    end
  end
end



timing_init()
timing_win_default()