e4s-sdk/gamedata/scripts/profiler.script

local function printf				(fmt,...)
	log								(string.format(fmt,...))
end

local								Counters = {}
local								Names = {}
local								timer = profile_timer()
local								old_hook_func, old_hook_mask, old_hook_count
local								started = false

local function getname				(func)
    local							n = Names[func]
    local							loc = string.format("[%s]:%s", n.short_src, n.linedefined)
    if "" ~= n.namewhat then
        return						(string.format("%s (%s)", loc, n.name))
    else
        return						(string.format("%s", loc))
    end
end

local function hook					(context,line_number)
--	if nil ~= old_hook_func then
--		if old_hook_func ~= hook then
--			old_hook_func			(context,line_number)
--		end
--	end
	
	assert							("line" ~= context)

	local							f = debug.getinfo(2, "f").func
	local							caller = debug.getinfo(3, "f")
	local							g = nil
	if caller ~= nil then
		g							= caller.func;
	end

--[[
	local							f_name = nil
	local							g_name = nil
	local							old_g = Names[g]

	if (Names[f] == nil) then
		Names[f]					= debug.getinfo(2,"Sn")
		f_name						= getname(f)
		Names[f]					= nil
	else
		f_name						= getname(f)
	end

	if (g == nil) then
		g_name						= ""
	else
		if (Names[g] == nil) then
			Names[g]				= debug.getinfo(3,"Sn")
			g_name					= "from [" .. getname(g) .. "]"
			Names[g]				= nil
		else
			g_name					= "from [" .. getname(g) .. "]"
		end
	end

	printf							("%6s : [%s]%s",context,f_name,g_name)
]]
	
	if ("return" == context) then
		local						object = Counters[f]
		if (object ~= nil) then
			object.timer:stop		()
			object.child_timer:stop	()
			if (g ~= nil) then
				local				object = Counters[g]
				if (object ~= nil) then
					object.timer:start	()
				end
			end
		end
		
		return
	end

	if ("tail return" == context) then
		if (g ~= nil) then
			local					object = Counters[g]
			if (object ~= nil) then
				object.timer:start	()
			end
		end
		
		return
	end

	assert							("call" == context)

	if g ~= nil then
		local						object = Counters[g]
		if (object ~= nil) then
			object.timer:stop		()
		end
	end
	
	if (Counters[f] == nil) then
		Counters[f]					= {count=1,timer=profile_timer(),child_timer=profile_timer()}
		local						object = Counters[f]
		object.child_timer:start	()
		object.timer:start			()
		Names[f]					= debug.getinfo(2,"Sn")
	else
		local						object = Counters[f]
		object.count				= object.count + 1
		object.child_timer:start	()
		object.timer:start			()
	end
end

function setup_hook					(do_not_print_message)
	if started == true then
		return
	end
	
	timer:start						()

	old_hook_func, 
	old_hook_mask, 
	old_hook_count					= debug.gethook();
	
    debug.sethook					()
	debug.sethook					(hook, "cr")
    
   	started							= true
   	
   	if (do_not_print_message ~= true) then
   		printf						("profiler is activated")
   	end
end

function clear_hook					()	
   	if started == false then		
		printf						("profiler hook wasn't setup!")
   		return;
   	end
--	debug.sethook					(old_hook_func,old_hook_mask,old_hook_count)
	debug.sethook					()
	timer:stop						()
	
	started							= false
end

function stats						()
	if started == false then
		printf						("profiler hook wasn't setup!")
		return
	end

	clear_hook						()
	
	printf							("profiler statistics")
	
	local							sort_stats = {}
    for func, count in pairs(Counters) do
		local						n = getname(func)
		if (nil == sort_stats[n]) then
			sort_stats[n]			= count
		else 
			sort_stats[n].count		= sort_stats[n].count		+ count.count
			sort_stats[n].timer		= sort_stats[n].timer		+ count.timer
			sort_stats[n].child_timer	= sort_stats[n].child_timer + count.child_timer
		end
    end

    local								script = profile_timer()
    local								count = 0
    
	local								out_stats = {}
    for i,j in pairs(sort_stats) do
		local							k = i
		if k == "[[C]]:-1" then
			k							= "#uncrecognized C/C++ stuff"
		end
		
		table.insert					(out_stats,{name=k,count=j})
		
		script							= script + j.timer
		count							= count + j.count
    end

	table.sort							(
		out_stats,
		function (a,b)
			return						(a.count.timer < b.count.timer)
		end
	)
	
	printf								("total_time (pecent)  child_time [total_call_count][average_call_time]")
    for n,c in pairs(out_stats) do
		printf							("%9.2fms (%5.2f%%) %9.2fms [%8d][%9.2fmks] : %s",c.count.timer:time()/1000,c.count.timer:time()*100/script:time(),c.count.child_timer:time()/1000,c.count.count, c.count.timer:time()/(c.count.count),c.name)
    end
    
	printf								("")
	printf								(" pure time :   %%%%   :  children  :   count  : function name")
	printf								("")
	printf								("profile time : %8.2fms",timer:time()/1000)
	printf								("script time  : %8.2fms (%5.2f%%)",script:time()/1000,script:time()*100/timer:time())
	printf								("call count   : %8d",count)

	setup_hook							(true)
end

function clear							()
	if started == true then
		clear_hook						()
	end

	Counters							= {}
	Names								= {}
	timer								= profile_timer()
	
	setup_hook							(true)
end