几种lua性能分析工具的使用及对比

参考: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

QQ图片.png

总结:不需要嵌入代码,定位精确,可视化,但是需要额外安装软件

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

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 220,884评论 6 513
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 94,212评论 3 395
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 167,351评论 0 360
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 59,412评论 1 294
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 68,438评论 6 397
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 52,127评论 1 308
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,714评论 3 420
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,636评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 46,173评论 1 319
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 38,264评论 3 339
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 40,402评论 1 352
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 36,073评论 5 347
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,763评论 3 332
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 32,253评论 0 23
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,382评论 1 271
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,749评论 3 375
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 45,403评论 2 358