参考:http://lua-users.org/wiki/ProfilingLuaCode
先上结论:luatrace和Profiling Lua with KCacheGrind不用嵌入代码,而且生成的报告内容齐全,内容清晰,是不错的选择
1、LuaProfiler
网站:http://luaprofiler.luaforge.net/index.html
安装:luarocks install luaprofiler
内嵌代码使用:
--test.lua
require("profiler")
profiler.start("test.log")
function add(x)
return x + 1
end
function test()
for i=1,500000 do
local j = add(i)
end
end
test()
使用方式:
lua test.lua (会生成一个test.log的分析文件)
lua /usr/lib64/luarocks/rocks/luaprofiler/2.0.2-2/bin/summary.lua test.log (分析报告)
Node name Total time
test 0.600000
add 0.51
profiler_init 0.000000
stop 0.000000
总结:内嵌代码,提示每个函数用时
2、PepperfishProfiler
网站:http://lua-users.org/wiki/PepperfishProfiler
内嵌代码使用
require "profiler"
profiler = newProfiler("call", 1)
profiler:start()
function add(x)
return x + 1
end
function test()
for i=1,500000 do
local j = add(i)
end
end
test()
profiler:stop()
local outfile = io.open( "profile.txt", "w+" )
profiler:report( outfile )
outfile:close()
会生成profile.txt,内容如下
Lua Profile output created by profiler.lua. Copyright Pepperfish 2002+
------------------------------ L:test@@test.lua:9 ------------------------------
Call count: 1
Time spend total: 4.980s
Time spent in children: 1.820s
Time spent in self: 3.160s
Time spent per call: 4.98000s/call
Time spent in self per call: 3.16000s/call
Child L:add@@test.lua:5 called 500000 times. Took 1.82s
------------------------------ L:add@@test.lua:5 -------------------------------
Call count: 500000
Time spend total: 1.820s
Time spent in children: 0.000s
Time spent in self: 1.820s
Time spent per call: 0.00000s/call
Time spent in self per call: 0.00000s/call
Total time spent in profiled functions: 4.98s
END
总结:内嵌代码,只能看到函数耗时
3、ProfilterInLua
网站:http://lua-users.org/wiki/ProfilerInLua
整个profiler.lua如下
修改:将原文的os.time()改为os.clock(),统计时间的精度由1s改为到0.01s
--| Profiler module.
--b "Pedro Miller Rabinovitch" <miller@inf.puc-rio.br>
--$Id: prof.lua,v 1.4 2003/10/17 00:17:21 miller Exp $
--TODO add function call profiling. Some of the skeleton is already in
--- place, but call profiling behaves different, so a couple of new
--- functionalities must be added.
--TODO add methods for proper result retrieval
--TODO use optional clock() function for millisecond precision, if it's
--- available
local E, I = {}, {}
--& Profiler module.
Profiler = E
--. Keeps track of the hit counts of each item
E.counts = {
line = {}
}
--. These should be inside the _line_ table above.
E.last_line = nil
E.last_time = os.clock()
E.started, E.ended = nil, nil
--% Activates the profiling system.
--@ [kind] (string) Optional hook kind. For now, only 'line' works,
-- so just avoid it. >: )
function E:activate( kind )
kind = kind or 'line'
local function hook_counter( hk_name, param,... )
local t = self.counts[hk_name][param]
if t == nil then
t = { count=0, time = 0 }
self.counts[hk_name][param] = t
end
self.counts[hk_name][param].count =
self.counts[hk_name][param].count + 1
if self.last_line then
local delta = os.clock() - self.last_time
if delta > 0 then
self.counts[hk_name][self.last_line].time =
self.counts[hk_name][self.last_line].time + delta
self.last_time = os.clock()
end
end
self.last_line = param
end
self.started = os.clock()
debug.sethook( hook_counter, kind )
end
--% Deactivates the profiling system.
--@ [kind] (string) Optional hook kind. For now, only 'line' works,
--- so just avoid it.
function E:deactivate( kind )
kind = kind or 'line'
self.ended = os.clock()
debug.sethook( nil, kind )
end
--% Prints the results.
--@ [kind] (string) Optional hook... Aah, you got it by now.
--TODO add print output formatting and sorting
function E:print_results( kind )
kind = kind or 'line'
print( kind, 'count', 'approx. time (s)' )
print( '----', '-----', '----------------' )
for i,v in pairs( self.counts[kind] ) do
print( i, v.count, v.time )
end
print( self.ended - self.started,
' second(s) total (approximately).' )
end
内嵌代码
--test.lua
require "Profiler"
Profiler:activate()
---检测的代码begin
function add(x)
return x + 1
end
function test()
for i=1,5000000 do
local j = add(i)
end
end
test()
--检测的代码end
Profiler:deactivate()
Profiler:print_results()
执行:lua test.lua
输出到屏幕
line count approx. time (s)
---- ----- ----------------
61 1 0
14 1 0
4 1 0
8 1 0
16 1 0
9 5000001 4.89
5 5000000 4.98
10 5000000 4.89
53 1 0
60 1 0
6 1 0
12 2 0
59 1 0
14.76 second(s) total (approximately).
总结:嵌入使用,定位到代码行,没有统计函数
4、Profiling Lua with KCacheGrind
网站:https://jan.kneschke.de/projects/misc/profiling-lua-with-kcachegrind/
lua-callgrind.lua (修改gsub函数的参数,转义符由\改为%,否则高版本的lua会报错,invalid escape sequence near '"^package\.loaded\.')
--[[
Copyright 2007 Jan Kneschke (jan@kneschke.de)
Licensed under the same license as Lua 5.1
$ lua lua-callgrind.lua <lua-script> [outputfile]
--]]
callstack = { }
instr_count = 0
last_line_instr_count = 0
current_file = nil
tracefile = io.open(arg[2] or "lua-callgrind.txt", "w+")
tracefile:write("events: Instructions\n")
mainfunc = nil
function getfuncname(f)
return ("%s"):format(tostring(f.func))
end
functions = { }
methods = { }
method_id = 1
call_indent = 0
function trace(class)
-- print("calling tracer: "..class)
if class == "count" then
instr_count = instr_count + 1
elseif class == "line" then
-- check if we know this function already
local f = debug.getinfo(2, "lSf")
if not functions[f.func] then
functions[f.func] = {
meta = f,
lines = { }
}
end
local lines = functions[f.func].lines
lines[#lines + 1] =("%d %d"):format(f.currentline, instr_count - last_line_instr_count)
functions[f.func].last_line = f.currentline
if not mainfunc then mainfunc = f.func end
last_line_instr_count = instr_count
elseif class == "call" then
-- add the function info to the stack
--
local f = debug.getinfo(2, "lSfn")
callstack[#callstack + 1] = {
short_src = f.short_src,
func = f.func,
linedefined = f.linedefined,
name = f.name,
instr_count = instr_count
}
if not functions[f.func] then
functions[f.func] = {
meta = f,
lines = { }
}
end
if not functions[f.func].meta.name then
functions[f.func].meta.name = f.name
end
-- is this method already known ?
if f.name then
methods[tostring(f.func)] = { name = f.name }
end
-- print((" "):rep(call_indent)..">>"..tostring(f.func).." (".. tostring(f.name)..")")
call_indent = call_indent + 1
elseif class == "return" then
if #callstack > 0 then
-- pop the function from the stack and
-- add the instr-count to the its caller
local ret = table.remove(callstack)
local f = debug.getinfo(2, "lSfn")
-- if lua wants to return from a pcall() after a assert(),
-- error() or runtime-error we have to cleanup our stack
if ret.func ~= f.func then
-- print("handling error()")
-- the error() is already removed
-- removed every thing up to pcall()
while callstack[#callstack].func ~= f.func do
table.remove(callstack)
call_indent = call_indent - 1
end
-- remove the pcall() too
ret = table.remove(callstack)
call_indent = call_indent - 1
end
local prev
if #callstack > 0 then
prev = callstack[#callstack].func
else
prev = mainfunc
end
local lines = functions[prev].lines
local last_line = functions[prev].last_line
call_indent = call_indent - 1
-- in case the assert below fails, enable this print and the one in the "call" handling
-- print((" "):rep(call_indent).."<<"..tostring(ret.func).." "..tostring(f.func).. " =? " .. tostring(f.func == ret.func))
assert(ret.func == f.func)
lines[#lines + 1] = ("cfl=%s"):format(ret.short_src)
lines[#lines + 1] = ("cfn=%s"):format(tostring(ret.func))
lines[#lines + 1] = ("calls=1 %d"):format(ret.linedefined)
lines[#lines + 1] = ("%d %d"):format(last_line and last_line or -1, instr_count - ret.instr_count)
end
-- tracefile:write("# --callstack: " .. #callstack .. "\n")
else
-- print("class = " .. class)
end
end
local main = assert(loadfile(arg[1]))
debug.sethook(trace, "crl", 1)
main()
debug.sethook()
-- try to build a reverse mapping of all functions pointers
-- string.sub() should not just be sub(), but the full name
--
-- scan all tables in _G for functions
function func2name(m, tbl, prefix)
prefix = prefix and prefix .. "." or ""
-- print(prefix)
for name, func in pairs(tbl) do
if func == _G then
-- ignore
elseif m[tostring(func)] and type(m[tostring(func)]) == "table" and m[tostring(func)].id then
-- already mapped
elseif type(func) == "function" then
-- remove the package.loaded. prefix from the loaded methods
--m[tostring(func)] = { name = (prefix..name):gsub("^package\.loaded\.", ""), id = method_id }
--转义符由\改为%,否则高版本的lua会报错
m[tostring(func)] = { name = (prefix..name):gsub("^package%.loaded%.", ""), id = method_id }
method_id = method_id + 1
elseif type(func) == "table" and type(name) == "string" then
-- a package, class, ...
--
-- make sure we don't look endlessly
if m[tostring(func)] ~= "*stop*" then
m[tostring(func)] = "*stop*"
func2name(m, func, prefix..name)
end
end
end
end
-- resolve the function pointers
func2name(methods, _G)
for key, func in pairs(functions) do
local f = func.meta
if (not f.name) and f.linedefined == 0 then
f.name = "(test-wrapper)"
end
local func_name = getfuncname(f)
if methods[tostring(f.func)] then
func_name = methods[tostring(f.func)].name
end
tracefile:write("fl="..f.short_src.."\n")
tracefile:write("fn="..func_name.."\n")
for i, line in ipairs(func.lines) do
if line:sub(1, 4) == "cfn=" and methods[line:sub(5)] then
tracefile:write("cfn="..(methods[line:sub(5)].name).."\n")
else
tracefile:write(line.."\n")
end
end
tracefile:write("\n")
end
test.lua
function add(x)
return x + 1
end
function test()
for i=1,50000 do
local j = add(i)
end
end
test()
使用方式: lua lua-callgrind.lua test.lua
生成文件:lua-callgrind.txt
需要用kcachegrind(https://nchc.dl.sourceforge.net/project/qcachegrindwin/0.7.4/qcachegrind074-32bit-x86.zip)查看,具体使用请查看cachegrind
总结:不需要嵌入代码,定位精确,可视化,但是需要额外安装软件
5、luatrace
网站:https://github.com/geoffleyland/luatrace.git
使用:先安装,安装完成后
lua -luatrace test.lua (生成trace-out.txt)
luatrace.profile trace-out.txt (分析trace-out.txt)
function add(x)
return x + 1
end
function test()
for i=1,50000 do
local j = add(i)
end
end
test()
Total time 119.09 milliseconds
Times in milliseconds
Top 20 lines by total time
File:line Hits Total Self Child | Line
test2.lua:11 1 119.09 0.00 119.09 | test()
test2.lua:7 50000 95.86 48.43 47.43 | local j = add(i)
test2.lua:2 50000 47.43 47.43 0.00 | return x + 1
test2.lua:6 50001 23.22 23.22 0.00 | for i=1,50000 do
test2.lua:3 1 0.00 0.00 0.00 | end
test2.lua:9 2 0.00 0.00 0.00 | end
test2.lua:1 1 0.00 0.00 0.00 | function add(x)
test2.lua:5 1 0.00 0.00 0.00 | function test()
Top 20 functions by self time
File:lines Hits Total Self Child | Line
test2.lua:5-9 1 119.09 71.65 47.43 | function test()
test2.lua:1-3 50000 47.43 47.43 0.00 | function add(x)
test2.lua:0-0 1 0.00 0.00 0.00 | -
总结:安装工具,代码可以内嵌也可以不内嵌,列出了耗时最高的20个函数和总时最高的20行代码,并且列出了代码,很清晰,支持luajit