Luat系列教程:4、学会使用并看懂luatools的trace信息

LUAT系列全部教程可以点击下面链接查看(建议保存书签):

https://www.chenxublog.com/tag/luat系列教程

看到标题,可能会有些读者(假装文章有很多人看的样子.jpg)会问:我要的mqtt代码解释呢!
别着急,下一篇投稿就会去讲(咕咕咕咕咕咕咕咕


适合阅读本文的人需要:
理解或已经学习了前几章的内容
熟悉lua语法
有实际模块,可以自己实践验证
能耐心阅读完本文
有问题会在文章下方进行留言

由于luat这个架构并不能直接连接仿真器进行调试,所以也无法在程序中设置断点来检查自己代码是否有问题,所以在开发过程中,一般我们都是靠各种print来输出trace获取程序运行的各种状态的。
并且由于lua是脚本文件,烧录时并没有进行编译,所以就算是报错,报错信息也可以准确地把错误所在行的具体位置详细指出来,方便我们进行排查问题

trace的几个基本部分

首先我们随便烧录一个程序,就只包含下面一个main.lua和自带的LuaTask库文件好了:
main.lua

PROJECT = "LOG-TEST"
VERSION = "1.0.0"

--加载日志功能模块,并且设置日志输出等级
--如果关闭调用log模块接口输出的日志,等级设置为log.LOG_SILENT即可
require "log"
LOG_LEVEL = log.LOGLEVEL_TRACE

require "sys"

require "net"
--每1分钟查询一次GSM信号强度
--每1分钟查询一次基站信息
net.startQueryAll(60000, 60000)

--加载硬件看门狗功能模块
--根据自己的硬件配置决定:1、是否加载此功能模块;2、配置Luat模块复位单片机引脚和互相喂狗引脚
--合宙官方出售的Air201开发板上有硬件看门狗,所以使用官方Air201开发板时,必须加载此功能模块
require "wdt"
wdt.setup(pio.P0_30, pio.P0_31)


--加载网络指示灯功能模块
--根据自己的项目需求和硬件配置决定:1、是否加载此功能模块;2、配置指示灯引脚
--合宙官方出售的Air800和Air801开发板上的指示灯引脚为pio.P0_28,其他开发板上的指示灯引脚为pio.P1_1
require "netLed"
netLed.setup(true,pio.P1_1)

--加载错误日志管理功能模块【强烈建议打开此功能】
--如下2行代码,只是简单的演示如何使用errDump功能,详情参考errDump的api
require "errDump"
errDump.request("udp://ota.airm2m.com:9072")

--启动系统框架
sys.init(0, 0)
sys.run()

程序中除了必要的声明软件版本和名称初始化看门狗初始化网络灯加载错误日志管理功能模块启动系统框架之外,没有进行其他任何操作(lib库文件和lod底层里进行的各种操作除外)
我们可以将这个文件烧录到开发板中,查看trace的各种信息(这里用的是S9开发板):



↑显示烧录成功后,最好立即关闭烧录界面,以免错过一些开头的trace信息。实际开发中一般错过了也没事,反正开头的一些东西也没什么用

我们可以看到trace中输出了一些信息:

由于trace中大多数的信息是由lib库文件打印出来的,随时可能会有更改,所以下面也就讲个大概,具体要以实际为准

为了更好地观察,我们可以点击停止打印按钮,以免刷新新的log信息导致滚动条回到最低端:

[时间]: CDFU_LoadSection: %d-%d

[时间]: CDFU_LoadSection: %d-%d

[时间]: ====================================
[时间]: INTR VER :Luat_V0027_8955_SSL_UI
[时间]: BASE VER :B5431
[时间]: SCRIPT ADDR :0x002b0000
[时间]: SCRIPT SIZE :0x000b0000
[时间]: BASE   ADDR :0x00220000
[时间]: BASE   SIZE :0x00090000
[时间]: ====================================
[时间]: [cust_task_main]: Enter message loop
[时间]: INTEGRITY file not exist!
[时间]: FH:file=/lua/wdt.lua,len=589,offset=29006
[时间]: FH:file=/lua/utils.lua,len=2526,offset=26455
[时间]: FH:file=/lua/sys.lua,len=5472,offset=20956
[时间]: FH:file=/lua/sim.lua,len=1084,offset=19847
[时间]: FH:file=/lua/ril.lua,len=7790,offset=12032
[时间]: FH:file=/lua/pins.lua,len=946,offset=11061
[时间]: FH:file=/lua/patch.lua,len=1186,offset=9849
[时间]: FH:file=/lua/netLed.lua,len=2601,offset=7221
[时间]: FH:file=/lua/net.lua,len=5141,offset=2052
[时间]: FH:file=/lua/main.lua,len=280,offset=1747
[时间]: FH:file=/lua/log.lua,len=1174,offset=547
[时间]: FH:file=/lua/clib.lua,len=472,offset=50
[时间]: parse_luadb_data:delupdpack=0,err=0,section=1,wrFile=0
[时间]: INTEGRITY file write begin!
[时间]: lualibc_fopen /integrity.bin wb 601 1 2
[时间]: INTEGRITY file write success!
[时间]: [fopen_ext]: /lua/main.lua 2!
[时间]: RUN main.lua
[时间]: [fopen_ext]: /lua/main.lua 2!
[时间]: [fopen_ext]: /lua/log.lua 2!
[时间]: [fopen_ext]: /lua/log.lua 2!
[时间]: [fopen_ext]: /lua/sys.lua 2!
[时间]: [fopen_ext]: /lua/sys.lua 2!
[时间]: [fopen_ext]: /lua/utils.lua 2!
[时间]: [fopen_ext]: /lua/utils.lua 2!
[时间]: [fopen_ext]: /lua/patch.lua 2!
[时间]: [fopen_ext]: /lua/patch.lua 2!
[时间]: [fopen_ext]: /lua/clib.lua 2!
[时间]: [fopen_ext]: /lua/clib.lua 2!
[时间]: [fopen_ext]: /lua/net.lua 2!
[时间]: [fopen_ext]: /lua/net.lua 2!
[时间]: [fopen_ext]: /lua/ril.lua 2!
[时间]: [fopen_ext]: /lua/ril.lua 2!
[时间]: [fopen_ext]: /lua/sim.lua 2!
[时间]: [fopen_ext]: /lua/sim.lua 2!
[时间]: [fopen_ext]: /lua/wdt.lua 2!
[时间]: [fopen_ext]: /lua/wdt.lua 2!
[时间]: [fopen_ext]: /lua/pins.lua 2!
[时间]: [fopen_ext]: /lua/pins.lua 2!
[时间]: [I]-[wdt.taskWdt] AirM2M --> WATCHDOG : OK
[时间]: [fopen_ext]: /lua/netLed.lua 2!
[时间]: [fopen_ext]: /lua/netLed.lua 2!
/******************************温馨提示**************************************/
软件开机,如果是意外重启,请去http://wiki.openluat.com/doc/luatApi/#rtospoweron,查看
/******************************提示结束**************************************/

开头的这一些代码表示读取到了上述的这些文件,可以用于后续的运行

注意:
我们烧录进模块的lua文件一般都在/lua/路径下
而烧录的其他文件如png图片、mp3音乐,则会在/ldata/路径下


[时间]: [I]-[poweron reason:] 3   LOG-TEST    1.0.0   2.0.8   Luat_V0027_8955_SSL_UI

这一行代表了上次关机的原因脚本工程里定义的名称(main.lua第1行写的)脚本工程里定义的版本号(main.lua第2行写的)LuaTask库文件的版本号(1.x.x是旧版的lua script,2.x.x是LuaTask)lod固件的版本号


[时间]: LJD VSIM sim_SetNextVoltage:1048,sim_present=0,IsVsim=0
[时间]: LJD VSIM sim_ProcessInstruction:2784,sim_present=1,IsVsim=1

这两行的IsVsim=1代表了当前模块拥有虚拟sim卡,sim_present=1代表没检测到外置sim卡,所以就使用内置的虚拟sim卡(可能是吧,我猜的)


[时间]: [I]-[ril.defrsp]  AT+CMEE=0   true    OK  nil
[时间]: [I]-[ril.sendat]  AT+CREG=2
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.defrsp]  AT+CREG=2   true    OK  nil
[时间]: [I]-[ril.sendat]  AT+CREG?
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CREG: 2,0
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.defrsp]  AT+CREG?    true    OK  nil
[时间]: [I]-[ril.sendat]  AT+CENG=1,1
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.sendat]  AT+CSQ
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CSQ: 0,0
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.sendat]  AT+CENG?
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CENG:1,1
[时间]: [I]-[ril.proatc]  +CENG:0,"0000, 0, 0,000,00,00,0000,00,00,0000,00"
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.sendat]  AT+CSQ
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CSQ: 0,0
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.sendat]  AT+CENG?
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CENG:1,1
[时间]: [I]-[ril.proatc]  +CENG:0,"0000, 0, 0,000,00,00,0000,00,00,0000,00"
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CSIMTYPE: 0,0
[时间]: [I]-[ril.defurc]  +CSIMTYPE: 0,0
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +ENCRET: 0
[时间]: [I]-[ril.defurc]  +ENCRET: 0
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  +CPIN: READY

上面这些就是lua脚本底层里,调用AT接口来对模块进行的操作了。熟悉AT指令的人会一下子就明白这些,不熟悉的人可以无视,只要知道这些是调用的AT指令就可以,操作基本都由底层和lib库来完成,一般情况下不用接触


[时间]: [I]-[wdt.taskWdt] AirM2M --> WATCHDOG : OK
[时间]: [I]-[wdt.taskWdt] AirM2M <-- WatchDog : OK

这是看门狗的喂狗操作。。。我觉得我不用解释了吧。。。


[时间]: [I]-[ril.defrsp]  AT+CIPSTATUS    true    OK  nil
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  STATE: IP INITIAL
[时间]: [I]-[link.STATE]  IP STATUS   IP INITIAL
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  C: 0,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 0,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 1,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 1,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 2,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 2,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 3,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 3,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 4,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 4,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 5,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 5,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 6,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 6,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 7,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 7,,"","","","INITIAL"
[时间]: [I]-[ril.sendat]  AT+CSTT="CMIOT","",""
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.defrsp]  AT+CSTT="CMIOT","",""   true    OK  nil
[时间]: [I]-[ril.sendat]  AT+CIICR
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.defrsp]  AT+CIICR    true    OK  nil
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  STATE: IP GPRSACT
[时间]: [I]-[link.STATE]  IP STATUS   IP GPRSACT
[时间]: [I]-[ril.sendat]  AT+CIFSR
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  010.007.081.239
[时间]: [I]-[ril.defrsp]  AT+CIFSR    true    nil 010.007.081.239
[时间]: [I]-[ril.sendat]  AT+CIPSTATUS
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  OK
[时间]: [I]-[ril.defrsp]  AT+CIPSTATUS    true    OK  nil
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  STATE: IP STATUS
[时间]: [I]-[link.STATE]  IP STATUS   IP STATUS
[时间]: [I]-[ril.proatc]  
[时间]: [I]-[ril.proatc]  C: 0,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 0,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 1,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 1,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 2,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 2,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 3,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 3,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 4,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 4,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 5,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 5,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 6,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 6,,"","","","INITIAL"
[时间]: [I]-[ril.proatc]  C: 7,,"","","","INITIAL"
[时间]: [I]-[ril.defurc]  C: 7,,"","","","INITIAL"

熟悉AT的各位如果看到这两大串,一定又明白了,这模块连上GPRS网络了。不明白的大概了解一下就好,可以在测试时作为参考


基本的trace就讲到这里,具体的自己去研究吧

自定义输出trace(LuaTask格式)

在第一版lua script时代,输出的trace基本都是直接使用print(xxxxx)这种格式,这个输出习惯的效果不怎么样,也不利于排查问题
于是在稀饭放姜大佬写的LuaTask版本中,使用了log语句,输出整齐具有区分度较高格式的trace

老套路,我们在上面的main.lua中稍作修改,在--启动系统框架的上方添加如下代码:

require"logtest"

并且新建一个lua文件,名为logtest.lua,文件内容如下:

require"common"

local function test()
    log.info("logtest.test",common.utf8ToGb2312("输出info级别的日志"))
    log.debug("logtest.test",common.utf8ToGb2312("输出debug级别的日志"))
    log.trace("logtest.test",common.utf8ToGb2312("输出trace级别的日志"))
    log.warn("logtest.test",common.utf8ToGb2312("输出warn级别的日志"))
    log.error("logtest.test",common.utf8ToGb2312("输出error级别的日志"))
    log.fatal("logtest.test",common.utf8ToGb2312("输出fatal级别的日志"))
end

test()

注意:
由于vscode新建文件默认都为utf8编码格式
所以我们在代码中输出的中文字符也都为utf8编码格式。但是luatools使用的却是GB2312格式,所以为了输出正确不乱码的中文,我们需要对中文进行转码,使用common.utf8ToGb2312()函数就可以解决这个编码问题
输出英文没有类似问题,无需转码

我们把logtest.lua文件添加到烧录工程中,将程序烧录进去,可以得到如下的输出结果(需要自己在luatools往上翻地找):

同时,log输出也可以改成如下语句:

testlog.lua

local function test()
    local a = 1
    local b = true
    local c = "test"
    log.info("logtest.test","mixed output",a,b,c)
end

test()

输出如下:

[时间]: [I]-[logtest.test]    mixed output    1   true    test

这些输出日志方便了我们调试的过程,我们可以在程序必要处添加这些log输出,以便通过trace掌握程序运行的状态

语法错误输出

为了演示,我们可以再次更改testlog.lua文件的内容如下:

testlog.lua

local function test()
    local a
    local b = 10
    b = a + b
end

test()

显而易见,这是会产生语法错误的,没看懂的也不要紧,烧录到模块中,可以看一下trace输出了什么:

[时间]: [E]-[errDump.luaErr]  /lua/logtest.lua:4: attempt to perform arithmetic on local 'a' (a nil value)

程序运行错误,请根据上方提示,找到对应lua文件修改程序
[时间]: stack traceback:
[时间]:   /lua/logtest.lua:4: in function 'test'
[时间]:   /lua/logtest.lua:7: in main chunk
[时间]:   [C]: in function 'require'
[时间]:   /lua/main.lua:34: in main chunk
[时间]:   [C]: ?
[时间]: [fopen_ext]: /lua/logtest.lua 2!
[时间]: [fopen_ext]: /lua/logtest.lua 2!
[时间]: lualibc_fopen /luaerrinfo.txt w 601 1 2
[时间]: lua: /lua/logtest.lua:4: attempt to perform arithmetic on local 'a' (a nil value)
程序运行错误,请根据上方提示,找到对应lua文件修改程序
[时间]: stack traceback:
[时间]:   /lua/logtest.lua:4: in function 'test'
[时间]:   /lua/logtest.lua:7: in main chunk
[时间]:   [C]: in function 'require'
[时间]:   /lua/main.lua:34: in main chunk
[时间]:   [C]: ?
[时间]: [lua_shell_main]: lua exit status 1

第一行的/lua/logtest.lua:4: attempt to perform arithmetic on local 'a' (a nil value)代表了这个错误的具体原因,我们可以直接到错误的行数寻找,同时错误信息也写得十分明确:a是个nil值,无法进行算术计算

如果你觉得这个报错十分准确的话,那你就错了,如果真是这样我就不会在下面再加一段解释了

再次修改testlog.lua文件的内容如下:

testlog.lua

require"utils"

local function test()
    local a = ""
    log.info("logtest.test",string.toHex(a))
end

test()

报错信息如下:

[时间]: lua: /lua/utils.lua:19: attempt to index local 'str' (a nil value)
程序运行错误,请根据上方提示,找到对应lua文件修改程序
[时间]: stack traceback:
[时间]:   /lua/utils.lua:19: in function 'toHex'
[时间]:   /lua/logtest.lua:5: in function 'test'
[时间]:   /lua/logtest.lua:8: in main chunk
[时间]:   [C]: in function 'require'
[时间]:   /lua/main.lua:34: in main chunk
[时间]:   [C]: ?
[时间]: [lua_shell_main]: lua exit status 1

可能有人看到这个报错就凌乱了:utils.lua?这文件不是我写的啊?

确实,utils.lua这个文件是lib文件夹中的库文件,库文件中的函数报错也会导致trace中显示这个文件的错误位置
我们可以在错误报告中找到/lua/logtest.lua:5: in function 'test'这一段,在检查后发现,确实是logtest.lua文件的第五行导致了错误:对nil进行转成16进制字符串的处理是非法的


以上就是luatools中trace解析的基本解释,很多trace信息还需要各位自己来摸索,用的多了也就熟悉了这些信息了

2 Comments

发表评论

您的电子邮箱地址不会被公开。