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

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

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

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

# trace的几个基本部分

首先我们随便烧录一个程序，就只包含下面一个main.lua和自带的LuaTask库文件好了：
main.lua
```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开发板）：

[![](http://oldask.openluat.com/image/show/attachments-2018-08-zqejrkLg5b80ccf881f86.png)](http://oldask.openluat.com/image/show/attachments-2018-08-zqejrkLg5b80ccf881f86.png)
[![](http://oldask.openluat.com/image/show/attachments-2018-08-MRIMreS55b80cd1353c4c.png)](http://oldask.openluat.com/image/show/attachments-2018-08-MRIMreS55b80cd1353c4c.png)
↑显示烧录成功后，最好立即关闭烧录界面，以免错过一些开头的trace信息。实际开发中一般错过了也没事，反正开头的一些东西也没什么用

我们可以看到trace中输出了一些信息：
[![](http://oldask.openluat.com/image/show/attachments-2018-08-bwJsOQOb5b80cd25ac9f6.png)](http://oldask.openluat.com/image/show/attachments-2018-08-bwJsOQOb5b80cd25ac9f6.png)
>由于trace中大多数的信息是由lib库文件打印出来的，随时可能会有更改，所以下面也就讲个大概，具体要以实际为准

为了更好地观察，我们可以点击`停止打印`按钮，以免刷新新的log信息导致滚动条回到最低端：
[![](http://oldask.openluat.com/image/show/attachments-2018-08-5Qp0X2s15b80cd3f7b0fe.png)](http://oldask.openluat.com/image/show/attachments-2018-08-5Qp0X2s15b80cd3f7b0fe.png)

```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/`路径下

---

```log
[时间]: [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固件的版本号`

---

```log
[时间]: 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卡（可能是吧，我猜的）

---

```log
[时间]: [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库来完成，一般情况下不用接触

---

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

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

---

```log
[时间]: [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中稍作修改，在`--启动系统框架`的上方添加如下代码：

```lua
require"logtest"
```

并且新建一个lua文件，名为`logtest.lua`，文件内容如下：

```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编码格式![](http://oldask.openluat.com/image/show/attachments-2018-08-KLoZibqN5b80cd9de7be9.png)，
所以我们在代码中输出的中文字符也都为utf8编码格式。但是luatools使用的却是GB2312格式，所以为了输出正确不乱码的中文，我们需要对中文进行转码，使用`common.utf8ToGb2312()`函数就可以解决这个编码问题
输出英文没有类似问题，无需转码

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

[![](http://oldask.openluat.com/image/show/attachments-2018-08-SetlMIpl5b80cdc199d09.png)](http://oldask.openluat.com/image/show/attachments-2018-08-SetlMIpl5b80cdc199d09.png)

同时，log输出也可以改成如下语句：

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

test()
```

输出如下：
```log
[时间]: [I]-[logtest.test]	mixed output	1	true	test
```

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

# 语法错误输出

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

testlog.lua
```lua
local function test()
	local a
	local b = 10
	b = a + b
end

test()
```

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

```log
[时间]: [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
```lua
require"utils"

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

test()
```

报错信息如下：
```log
[时间]: 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信息还需要各位自己来摸索，用的多了也就熟悉了这些信息了

发表于 2018-08-25 11:33
阅读 ( 8752 )
分类：默认分类

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

你可能感兴趣的文章

相关问题

1 条评论

作家榜 »