基础介绍
qemu-riscv64 -d help可以看到支持的各种debug选项，我们一般用的有in_asm/exec/cpu
以及singlestep等，其他的参数，比如，out_asm是翻译后得到的host上的汇编，op是qemu的
中间码，这些都和qemu自己的调试有关。
我们看下前面的几个：in_asm是输出guest的汇编，exec是记录每个翻译块执行的trace，
cpu是在执行一个翻译块之前打印当前的CPU各个寄存器的值，在没有配置singlestep的时候，
上面的打印都是和翻译块(TB)相关的，singlestep可以看到每条guest指令模拟执行后的各种
调试信息。上面的调试配置可以配合使用，使用-D file，可以输出到文件file，需要注意
的是调试信息往往比较多。如果是用user mode调试小的程序，输出的log的大小还可以接受，
如果，比如你用system mode起Linux内核的时候加上了上面的调试选项，运行的速度就会
很慢，因为要输出的log太多了，qemu还有-dfilter可以只输出特定地址区间的log，这样就
可以先不加-dfilter运行一遍，大概知道需要debug的地方，然后再加上-dfilter仔细的跟踪。
qemu里还可以用-d mmu去跟踪mmu翻译，用-d int去跟踪中断和异常。
举个例子
qemu上运行的代码：(test.c)
1
2
3
4
5
6
7
8
9
10
11
12
13
| int __attribute__ ((noinline)) test_add(int a, int b)
{
return a + b;
}
int main()
{
volatile int c = 0;
c = test_add(1, 2);
return 0;
}
|
riscv64-linux-gnu-gcc test.c –static
riscv64-linux-gnu-objdump -D a.out > test.s
我们这样运行下: qemu-riscv64 -d in_asm,exec,cpu -D ./log a.out
然后看看test_add这个函数前后的各种调试信息。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
| [...]
----------------
IN: main
0x0000000000010458: 1101 addi sp,sp,-32
0x000000000001045a: ec06 sd ra,24(sp)
0x000000000001045c: e822 sd s0,16(sp)
0x000000000001045e: 1000 addi s0,sp,32
0x0000000000010460: fe042623 sw zero,-20(s0)
0x0000000000010464: 4589 addi a1,zero,2
0x0000000000010466: 4505 addi a0,zero,1
0x0000000000010468: fc9ff0ef jal ra,-56 # 0x10430
Trace 0: 0xffff98026780 [0000000000000000/0000000000010458/00006100/00000000] main
pc 0000000000010458
x0/zero 0000000000000000 x1/ra 0000000000010610 x2/sp 0000004000800360 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 000000000001094a x9/s1 00000000000109da x10/a0 0000000000000001 x11/a1 00000040008004a8
x12/a2 00000040008004b8 x13/a3 0000000000000000 x14/a4 0000004000800388 x15/a5 0000000000010458
x16/a6 0000000000071140 x17/a7 4a5e000112702f5b x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
----------------
IN: test_add
0x0000000000010430: 1101 addi sp,sp,-32
0x0000000000010432: ec22 sd s0,24(sp)
0x0000000000010434: 1000 addi s0,sp,32
0x0000000000010436: 87aa mv a5,a0
0x0000000000010438: 872e mv a4,a1
0x000000000001043a: fef42623 sw a5,-20(s0)
0x000000000001043e: 87ba mv a5,a4
0x0000000000010440: fef42423 sw a5,-24(s0)
0x0000000000010444: fec42703 lw a4,-20(s0)
0x0000000000010448: fe842783 lw a5,-24(s0)
0x000000000001044c: 9fb9 addw a5,a5,a4
0x000000000001044e: 2781 sext.w a5,a5
0x0000000000010450: 853e mv a0,a5
0x0000000000010452: 6462 ld s0,24(sp)
0x0000000000010454: 6105 addi sp,sp,32
0x0000000000010456: 8082 ret
Linking TBs 0xffff98026780 [0000000000010458] index 0 -> 0xffff98026900 [0000000000010430]
Trace 0: 0xffff98026900 [0000000000000000/0000000000010430/00006100/00000000] test_add
pc 0000000000010430
x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800340 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 0000004000800360 x9/s1 00000000000109da x10/a0 0000000000000001 x11/a1 0000000000000002
x12/a2 00000040008004b8 x13/a3 0000000000000000 x14/a4 0000004000800388 x15/a5 0000000000010458
x16/a6 0000000000071140 x17/a7 4a5e000112702f5b x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
----------------
IN: main
0x000000000001046c: 87aa mv a5,a0
0x000000000001046e: fef42623 sw a5,-20(s0)
0x0000000000010472: 4781 mv a5,zero
0x0000000000010474: 853e mv a0,a5
0x0000000000010476: 60e2 ld ra,24(sp)
0x0000000000010478: 6442 ld s0,16(sp)
0x000000000001047a: 6105 addi sp,sp,32
0x000000000001047c: 8082 ret
Trace 0: 0xffff98026ac0 [0000000000000000/000000000001046c/00006100/00000000] main
pc 000000000001046c
x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800340 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 0000004000800360 x9/s1 00000000000109da x10/a0 0000000000000003 x11/a1 0000000000000002
x12/a2 00000040008004b8 x13/a3 0000000000000000 x14/a4 0000000000000001 x15/a5 0000000000000003
x16/a6 0000000000071140 x17/a7 4a5e000112702f5b x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
[...]
|
如上，IN: xxx后面是guest的汇编，in_asm会显示这一部分。exec打印出来的是诸如，Linking TBs xxx
Trace 0：xxx的部分，这些都是qemu TB的信息，其中中括号里的第二个参数对调试guest
代码有用，比如，Trace 0: 0xffff98026900 [0000000000000000/0000000000010430/00006100/00000000] test_add
中的0000000000010430是这个TB对应的第一个guest指令的地址，中括号后面是符号名字。
exec可以用来跟踪程序执行到哪里了，运行时的跟踪。
qemu把若干条guest指令翻译到一个TB里，TB的划分一般是程序跳转的地方，可以看到main
函数的前几条指令放到了一个TB里，test_add的指令都放到一个TB，main的后面几条指令
放到了下一个TB里。
需要注意的一个地方是，CPU寄存器打印表示的是进入当前TB翻译执行代码之前寄存器的数值。
所以，可以看到test_add这一段log的a0是1、a1是2，表示进入test_add这段代码对应的TB
之前CPU寄存器的值。逻辑上，test_add调用之前先把1放到a0、2放到a1，和log是一致的。
使用singlestep可以看到一条guest指令执行后CPU的状态，我们只看CPU的状态，使用如下
的命令：qemu-riscv64 -d in_asm,cpu -singlestep -D ./log a.out
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
| [...]
----------------
IN: main
0x0000000000010468: fc9ff0ef jal ra,-56 # 0x10430
pc 0000000000010468
x0/zero 0000000000000000 x1/ra 0000000000010610 x2/sp 0000004000800340 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 0000004000800360 x9/s1 00000000000109da x10/a0 0000000000000001 x11/a1 0000000000000002
x12/a2 00000040008004b8 x13/a3 0000000000000000 x14/a4 0000004000800388 x15/a5 0000000000010458
x16/a6 0000000000071140 x17/a7 4a5e000112702f5b x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
----------------
IN: test_add
0x0000000000010430: 1101 addi sp,sp,-32
pc 0000000000010430
x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800340 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 0000004000800360 x9/s1 00000000000109da x10/a0 0000000000000001 x11/a1 0000000000000002
x12/a2 00000040008004b8 x13/a3 0000000000000000 x14/a4 0000004000800388 x15/a5 0000000000010458
x16/a6 0000000000071140 x17/a7 4a5e000112702f5b x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
----------------
IN: test_add
0x0000000000010432: ec22 sd s0,24(sp)
pc 0000000000010432
x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800320 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 0000004000800360 x9/s1 00000000000109da x10/a0 0000000000000001 x11/a1 0000000000000002
x12/a2 00000040008004b8 x13/a3 0000000000000000 x14/a4 0000004000800388 x15/a5 0000000000010458
x16/a6 0000000000071140 x17/a7 4a5e000112702f5b x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
----------------
IN: test_add
0x0000000000010434: 1000 addi s0,sp,32
pc 0000000000010434
x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800320 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
[...]
|
如上，因为显示的寄存器是执行本条指令之前的寄存器的数值，比如，test_add的第一条指令
addi sp,sp,-32对sp寄存器的更新要在test_add的第二个指令(sd s0,24(sp))的打印log里
才能看到：x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800320 x3/gp 0000000000071028。
如果你想用qemu跟踪指令指令的流程，只要用脚本处理下如上的-singlestep的反汇编log就好，
具体的处理方式可以参考下面代码分析中的介绍。
我们加上-dfilter运行下qemu-riscv64 -d in_asm,exec,cpu -dfilter 0x10430+0x26 -D ./log a.out
dfilter的这种写法表示只输出pc在[0x10430, 0x10430+0x26]区间的log，这段区间是test_add
函数的代码。全部log就只有：
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
| ----------------
IN: test_add
0x0000000000010430: 1101 addi sp,sp,-32
0x0000000000010432: ec22 sd s0,24(sp)
0x0000000000010434: 1000 addi s0,sp,32
0x0000000000010436: 87aa mv a5,a0
0x0000000000010438: 872e mv a4,a1
0x000000000001043a: fef42623 sw a5,-20(s0)
0x000000000001043e: 87ba mv a5,a4
0x0000000000010440: fef42423 sw a5,-24(s0)
0x0000000000010444: fec42703 lw a4,-20(s0)
0x0000000000010448: fe842783 lw a5,-24(s0)
0x000000000001044c: 9fb9 addw a5,a5,a4
0x000000000001044e: 2781 sext.w a5,a5
0x0000000000010450: 853e mv a0,a5
0x0000000000010452: 6462 ld s0,24(sp)
0x0000000000010454: 6105 addi sp,sp,32
0x0000000000010456: 8082 ret
Trace 0: 0xffffa00265c0 [0000000000000000/0000000000010430/0x6100] test_add
pc 0000000000010430
x0/zero 0000000000000000 x1/ra 000000000001046c x2/sp 0000004000800160 x3/gp 0000000000071028
x4/tp 0000000000072710 x5/t0 0000000000072000 x6/t1 2f2f2f2f2f2f2f2f x7/t2 0000000000072000
x8/s0 0000004000800180 x9/s1 00000000000109da x10/a0 0000000000000001 x11/a1 0000000000000002
x12/a2 00000040008002d8 x13/a3 0000000000000000 x14/a4 00000040008001a8 x15/a5 0000000000010458
x16/a6 0000000000071140 x17/a7 0112702f5b5a4001 x18/s2 0000000000000000 x19/s3 0000000000000000
x20/s4 0000000000000000 x21/s5 0000000000000000 x22/s6 0000000000000000 x23/s7 0000000000000000
x24/s8 0000000000000000 x25/s9 0000000000000000 x26/s10 0000000000000000 x27/s11 0000000000000000
x28/t3 ffffffffffffffff x29/t4 000000000006ead0 x30/t5 0000000000000000 x31/t6 0000000000072000
|
dfilter参数还有其他的描述格式，从qemu的自测试代码可以看到具体的使用方式：qemu/tests/test-logging.c。
还可以用: 基地址-区间大小、基地址..结尾地址，用逗号分开可以加多段不同的地址，比如：
-dfilter 0x1000+0x100,0x2100-0x100,0x3000..0x3100
加上-d mmu可以打印出qemu上MMU相关的行为，打印大概是这样的：
1
2
| riscv_cpu_tlb_fill ad ffffffe001003fe0 rw 0 mmu_idx 1
riscv_cpu_tlb_fill address=ffffffe001003fe0 ret 0 physical 0000000081203fe0 prot 3
|
上面表示MMU要查ffffffe001003fe0对应的物理地址，并且查到的结果是0000000081203fe0，
rw后面的数字表示访问类型，0表示数据load，1表示数据store，2表示指令fetch，ret后面
的数字，0表示翻译成功，1表示翻译失败。
加上-d int可以打印中断和异常的log，但是在5.1.50的版本上，这个打印还没有加上，在
7.0.50上, 这个打印大概是这样的：
1
2
3
| riscv_cpu_do_interrupt: hart:0, async:0, cause:0000000000000009, epc:0xffffffe00020455e, tval:0x0000000000000000, desc=supervisor_ecall
[...]
riscv_cpu_do_interrupt: hart:0, async:1, cause:0000000000000005, epc:0xffffffe000201558, tval:0x0000000000000000, desc=s_timer
|
hart表示异常或中断的cpu，async后面的数据，0表示异常，1表示中断，cause/epc/tval
就是相关寄存器中的值，最后一个desc是一个描述异常或中断的字符串。
qemu代码分析
in_asm的入口在：translator_loop的最后，可见guest汇编只在翻译的时候会打印，这些
打印不反应执行的流程。另外，qemu对于同一段代码是可能会翻译到不同的TB里的，这个
和翻译参数有关系。guest指令的反汇编是独立的逻辑，不在本文中描述。
exec和cpu的入口在：cpu_tb_exec的log_cpu_exec里，可见是在TB执行的时候打印。但是，
qemu为了提高执行效率，TB和TB之间可以直接跳过去，这个叫chained TB，而log_cpu_exec
是在翻译-执行的循环里加的打印，所以，要跟踪程序执行流程，必须断开qemu里的chained
TB，所以参数变成了：-d in_asm,cpu,nochain -singlestep，如果只要得到程序的执行流程，
cpu可以去掉，就变成了-d in_asm,exec,nochain –singlestep, in_asm可以打出反汇编，
但是，只是翻译的时候打一下，随后执行的时候不会打印，exec + nochain可以打印具体执行
的流程，但是没有反汇编，所以，我们可以对得到的log在exec的log下插入对应的汇编代码，
再把所有exec对应的汇编代码提取到一个文件里就得到了实际指令执行流程，可以写一个脚本
搞定这个事情。
qemu里有两个singlestep相关的flag，一个是全局变量singlestep，一个是cpu结构体里的
singlestep_enabled。后者应该和gdb单步运行有关系，不是我们考虑东西。singlestep
的相关逻辑在翻译执行主循环里，如果是singlestep就配置翻译flag(cflags)为CF_NO_GOTO_TB，
并且一个TB只进行一条guest指令的翻译执行，CF_NO_GOTO_TB禁止qemu在TB之间跳转。
这里有个点需要注意，GOTO_PTR也可能在TB之间跳转，这里之所没有连CF_NO_GOTO_PTR也
配置上，是因为GOTO_PTR的help函数里调用了log_cpu_exec，所以，在GOTO_PTR的时候是
可以打印trace的。
可以看到，singlestep和nochain改变了qemu翻译执行的粒度，效率上是变差了很多的。
实际在qemu system mode上用-d in_asm,cpu -singlestep跑，会慢的一塌糊涂，这个时候
就可以用-dfilter指定输出log的指令地址区间。
