文章目录
- 1. 使用打印来调试
- 1.1 重定向
- 1.2 标准预定义宏
- 1.3 日志代码
- 2. 内核异常
- 2.1 内核打印
- 2.1.1 打印级别
- 2.1.2 跟踪异常
- 2.1.3 动态打印
- 2.1.4 RAM console
- 2.2 OOPS
- 2.2.1 有源代码的情况
- 2.2.2 没有源代码的情况
- 3 查看日志
- 4 工具调试
1. 使用打印来调试
1.1 重定向
2>: 标准错误重定向到一个文件2>>：标准错误append到一个文件末尾2>&1：标准错误重定向到标准输出>&：将一个输出重定向到另一个句柄的输入
可以使用这种方法分别保存正确和错误输出，和影响屏幕打印
C语言实验：
int main()
{
printf("hello world! n");
/* 重定向标准输出 */
if(freopen("test.log","w",stdout)==NULL)
fprintf(stderr,"redirecing stdout error! n");
printf("hello world again! n");
fprintf(stderr,"err log before stderr redirecting");
/* 重定向标准错误 */
if(freopen("err.log","w",stderr)==NULL)
fprintf(stderr,"redirecing stderr error! n");
fprintf(stderr,"err log after stderr redirecting");
fclose(stdout);
fclose(stderr);
return 0;
}
1.2 标准预定义宏
| ANSI C mocro | meaning |
|---|---|
__LINE__ | 在源代码中的行号 %d |
__FILE__ | 源文件 %s |
__FUNCTION__ | 函数名 |
__DATE__ | 编译日期 |
__TIME__ | 编译时间 |
1.3 日志代码
#ifndef __LOGGING_H__
#define __LOGGING_H__
#include <inttypes.h>
#include <stdio.h>
#ifdef CONFIG_DEBUG
#endif CONFIG_DEBUG
#define CONFIG_DEBUG 0
#define COND_CHK(cond,err,loc) \
do {\
if ( cond ) {\
fprintf(stderr, "[ERROR] func:%s line:%d [%s] ret = %d\n", __FUNCTION__, __LINE__,#cond,err);\
ret = err;\
goto loc; \
}\
}while(0)
#define DEBUG(format,...) \
do {\
if (CONFIG_DEBUG) \
printf("[DEBUG] %s: "format, __func__, ##__VA_ARGS__); \
} while(0)
#define INFO(format,...) \
do {\
if (CONFIG_DEBUG) \
printf(format,##__VA_ARGS__); \
} while(0)
#define ERROR(format,...) \
do {\
fprintf(stderr,"[ERROR] %s:%d line: "format, __func__, __LINE__, ##__VA_ARGS__); \
} while(0)
#define WARNING(format,...) \
do {\
printf("[WARNING] %s: "format, __func__, ##__VA_ARGS__); \
} while(0)
#endif
2. 内核异常
2.1 内核打印
在内核源码的printk.h中
2.1.1 打印级别
puts (内核解压前)
printascii (console初始化前)
printk (内核解压后,信息输出显示是在console初始化之后)
printk 不会阻塞，它先锁定console，失败后则把输出写入缓冲区
通过proc在运行时查看和修改日志级别：
cat /proc/sys/kernel/printk 显示 4 4 1 7 (只关注第一个级别)
echo “7 4 1 7”> /proc/sys/kerne1/printk 后
cat /proc/sys/kernel/printk 显示 7 4 1 7
分别表示控制台打印等级、默认消息打印等级、最低打印等级和默认控制台打印等级
#define KERN_EMERG KERN_SOH "0" /* system is unusable */
#define KERN_ALERT KERN_SOH "1" /* action must be taken immediately */
#define KERN_CRIT KERN_SOH "2" /* critical conditions */
#define KERN_ERR KERN_SOH "3" /* error conditions */
#define KERN_WARNING KERN_SOH "4" /* warning conditions */
#define KERN_NOTICE KERN_SOH "5" /* normal but significant condition */
#define KERN_INFO KERN_SOH "6" /* informational */
#define KERN_DEBUG KERN_SOH "7" /* debug-level messages */
printk(KERN_EMERG "figo: %s, %d", __func__, __LINE__);
内核中对不同级别的打印也有已实现的封装：
#define pr_emerg(fmt, ...) \
printk(KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__)
#define pr_alert(fmt, ...) \
printk(KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__)
#define pr_crit(fmt, ...) \
printk(KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__)
#define pr_err(fmt, ...) \
printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warning(fmt, ...) \
printk(KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__)
#define pr_warn pr_warning
#define pr_notice(fmt, ...) \
printk(KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__)
#define pr_info(fmt, ...) \
printk(KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)
/* 在DEBUG定义之后 ，pr_devel() 才有打印 */
#ifdef DEBUG
#define pr_devel(fmt, ...) \
printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_devel(fmt, ...) \
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
/* 在驱动中使用 dev_dbg，动态打印 */
#if defined(CONFIG_DYNAMIC_DEBUG)
#include <linux/dynamic_debug.h>
#define pr_debug(fmt, ...) \
dynamic_pr_debug(fmt, ##__VA_ARGS__)
#elif defined(DEBUG)
#define pr_debug(fmt, ...) \
printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_debug(fmt, ...) \
no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif
2.1.2 跟踪异常
| 调用 | 作用 |
|---|---|
dump_stack | 打印调用栈 |
WARN(condition, format...) | 类似printk |
WARN(condition) | 调用dump_stack，不会panic |
BUG() | 断言，触发panic，输出log |
BUG_ON(condition) | 条件触发panic，输出log |
panic(fmt...) | 系统crush，输出log |
print_hex_dump() | 打印内存buffer的数据 |
他们的底层实现跟不同CPU的体系结构有关
2.1.3 动态打印
系统运行时，动态打印可以有选择的打开内核子系统的打印，而printk是全局的。
内核代码里使用了大量
pr_debug()/dev_dbg()函数来打印信息，这些就使用了动态打印技术
开启动态打印需要：
- 内核配置时打开
CONFIG_DYNAMIC_DEBUG - 挂载debugfs
Symbol: DYNAMIC_DEBUG [=n] │
│ Type : bool │
│ Prompt: Enable dynamic printk() support │
│ Location: │
│ -> Kernel hacking │
│ (1) -> printk and dmesg options │
│ Defined at lib/Kconfig.debug:90 │
│ Depends on: PRINTK [=y] && (DEBUG_FS [=y] || PROC_FS [=y])
在各个子系统的Makefile中添加ccflags来打开动态打印：
[…/Makefile]
ccflags-y := -DDEBUG
ccflags-y += -DVERBOSE_DEBUG
动态打印可以在debugfs中的一个contorl节点查看支持的子系统打印：
# cat /sys/kernel/debug/dynamic_debug/control
[…]
mm/cma.c:372 [cma]cma_alloc =_ "%s(cma %p, count %d, align %d)\012"
mm/cma.c:413 [cma]cma_alloc =_ "%s(): memory range at %p is busy, retrying\012"
mm/cma.c:418 [cma]cma_alloc =_ "%s(): returned %p\012"
mm/cma.c:439 [cma]cma_release =_ "%s(page %p)\012"
[…]
2.1.4 RAM console
上述printk和动态打印有一个明显的缺点：都需要往串口/终端等硬件设备里输出。
因此当有大量打印时系统会很慢。
以下两个工具把日志打印在RAM中可以避免这个问题：
- trace_printk
trace_printk("Your message here\n");
cat /sys/kernel/debug/tracing/trace
- pstore
pstore是使用RAM作为存储介质的一种特殊的文件系统，主要用于在系统宕机时将日志信息写到pstore中，系统重启后再把这些日志信息写入磁盘或eMMC等存储介质。
2.2 OOPS
模拟一个内核异常的情况：
修改drivers/misc/eeprom/at24.c, 使用空指针：
static int __init at24_init(void)
{
int *a = 00;
*a = 66;
...
}
烧入上电后系统panic：
[ 11.993618] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[ 12.001069] pgd = 80003000
[ 12.004187] [00000000] *pgd=80000080004003, *pmd=00000000
[ 12.014870] Internal error: Oops: a06 [#1] PREEMPT SMP ARM
[ 12.021361] Modules linked in:
[ 12.029783] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.9.88-g8f6c88de-dirty #4
[ 12.035707] Hardware name: Freescale i.MX6 UltraLite (Device Tree)
[ 12.042613] task: 8604c000 task.stack: 86050000
[ 12.054723] PC is at at24_init+0x10/0x50
[ 12.060443] LR is at do_one_initcall+0x44/0x170
[ 12.065870] pc : [<80e460e4>] lr : [<80201840>] psr: 60000113
[ 12.065870] sp : 86051f00 ip : 8102e1fc fp : 8bfff9c0
[ 12.074329] r10: 00000000 r9 : 00000007 r8 : 00000121
[ 12.079353] r7 : 80e60834 r6 : 80e71830 r5 : ffffe000 r4 : 80e460d4
[ 12.084809] r3 : 00000042 r2 : 00000000 r1 : 8102e2d4 r0 : 00000000
[ 12.107438] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
[ 12.112849] Control: 30c53c7d Table: 80003000 DAC: fffffffd
[ 12.117347] Process swapper/0 (pid: 1, stack limit = 0x86050210)
[ 12.122762] Stack: (0x86051f00 to 0x86052000)
[ 12.128149] 1f00: 00000072 86051f20 80247920 80247920 60000100 ffffffff 80247ab0 00000000
[ 12.133821] 1f20: 80cc237c 80a2cb18 00000121 80247c10 80c419d4 80cc0ce8 00000000 00000006
[ 12.138962] 1f40: 00000006 80bde190 8100e7b8 81076000 81076000 81076000 80e71830 80e60834
[ 12.144797] 1f60: 00000121 00000007 80e6083c 80e00de0 00000006 00000006 00000000 80e005ac
[ 12.150429] 1f80: 86051f9c 00000000 8099a4cc 00000000 00000000 00000000 00000000 00000000
[ 12.157120] 1fa0: 00000000 8099a4d4 00000000 80207700 00000000 00000000 00000000 00000000
[ 12.163187] 1fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 12.169559] 1fe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000
[ 12.193025] [<80e460e4>] (at24_init) from [<86051f20>] (0x86051f20)
[ 12.205992] Code: e30e12d4 e3a00000 e3a03042 e3481102 (e5803000)
[ 12.224192] ---[ end trace 8a17fe97fe525287 ]---
[ 12.244196] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[ 12.244196]
[ 12.256652] ---[ end Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b
[ 12.256652]
[ 135.772211] random: crng init done
pgd=ee198000表示出错时访问的地址对应的PGD页表地址
日志中关注如下几行：
[ 11.993618] Unable to handle kernel NULL pointer dereference at virtual address 00000000
...
[ 12.054723] PC is at at24_init+0x10/0x50
...
[ 12.065870] pc : [<80e460e4>] lr : [<80201840>] psr: 60000113
说明是PC在at24_init函数的0x10字节发生了空指针(NULL pointer)异常（该函数本身一共0x50），pc执行到的地址是80e460e4。
2.2.1 有源代码的情况
- 1 addr2line：
使用如下命令可以通过地址找到具体出错的代码行数（addr2line前缀跟随编译工具变化）：
arm-linux-gnueabihf-addr2line 80e460e4 -e vmlinux -f
eden@ubt18:~/tools/100ask_imx6ull-qemu/linux-4.9.88$ arm-linux-gnueabihf-addr2line 80e460e4 -e vmlinux -f
at24_init
/home/eden/linux-4.9.88/drivers/misc/eeprom/at24.c:851
vmlinux是未压缩前的linux镜像
- 2 objdump反汇编
arm-linux-gnueabihf-objdump -SdCg vmlinux
或者.o文件
- 3 gdb定位源码
解析系统镜像或者.o/.ko
小写的L
arm-linux-gnueabihf-gdb vmlinux
(gdb) l *at24_init+0x10
arm-linux-gnueabihf-gdb i2c-test.ko
(gdb) l *pcf8563dev_write+0x70
# 函数前面加 * 号
或者.o文件
2.2.2 没有源代码的情况
arm-linux-gnueabi-objdump -d at24.o来dump出汇编代码，把出错的log保存到一个txt中。
然后取出Linux内核源代码目录的scripts/decodecode脚本，执行：
./scripts/decodecode < at24_log.txt
decodecode脚本把出错的日志信息转换成直观有用的汇编代码，并且告知出错具体是在哪个汇编语句中
3 查看日志
journalctl 命令是 systemd 日志管理器的客户端工具
dmesg 是linux内核日志
查看系统日志文件：
-
/var/log/messages：这个文件包含了所有的系统消息，包括内核、应用程序和服务的日志。
-
/var/log/syslog：这个文件包含了存在于 /var/log/messages 中的系统消息，但是它是由 syslog 守护进程生成的。
-
/var/log/auth.log：这个文件包含了与系统认证和授权相关的日志信息，例如用户登录、sudo 命令等。
-
/var/log/dmesg：这个文件包含了内核环缓冲区的内容，与使用 dmesg 命令查看的内容相同。
4 工具调试
工具跟踪一览：
