みつきんのメモ

組み込みエンジニアです。Interface誌で「Yocto Projectではじめる 組み込みLinux開発入門」連載中

kdb入門

linux debug

はじめに

カーネルデバッガが便利だという噂は聞いたことがあったが、実際使ったことがなかった。 kdbをすこしだけ試してみたのでメモ。

kdb vs kgdb

Linuxのカーネルデバッガを調べるとかならずkdbとkgdbが引っかかる。

これらは別物で、どちらが良い悪いはなくてケースによって両方使うことになる。

kgdbのほうは名前にgdbが含まれていることからわかるようにGDBのサーバとなって、 デバッギーで動作させておいて、デバッガとなるホストのGDBからリモート接続してデバッグする。 こちらはカーネルがシンボル情報持っていて、アクセス可能なソースツリーが設定されていればソースレベルのデバッグが可能。

kdbの方はソースレベルでのデバッグはできないが、あらかじめ設定しておくとカーネルで何か発生した時に起動して、その時のメモリの状態とかいろいろ有用な情報を見ることができる。

今回はkdbの方を試す。

環境

Yocto Projectのmeta-raspberrypiで作成したraspberrypi4(32bit)環境で試す。

kdbを使用するにはカーネルを作成する際に下記のようなコンフィグが有効になっている必要がある。

CONFIG_KGDB=y
CONFIG_KGDB_KDB=y

ただ、meta-raspberrypiのカーネルではデフォルトで有効になっているので省略する。

デバッグ対象

今回も毎度お馴染みのhello-modをベースに作業する。

ビルド方法などはこちらを参照。

hello.cを下記の内容で作成する。今回はあらかじめバグを仕込んでおく。

#include <linux/module.h>

int init_module(void)
{
        int *p = NULL;

        printk("hello: init_module is called\n");
        *p = 10; // dereference the NULL pointer.
        return 0;
}

void cleanup_module(void)
{
}

MODULE_LICENSE("GPL");

これをビルドする。

$ source /opt/poky/3.1.4/environment-setup-aarch64-poky-linux
$ export KERNEL_SRC=${OECORE_TARGET_SYSROOT}/usr/src/kernel
$ make

デバッグする時に使うためにディスアセンブリも作っておく。

$ arm-poky-linux-gnueabi-objdump -S ./hello.ko

./hello.ko:     ファイル形式 elf32-littlearm


セクション .text.unlikely の逆アセンブル:

00000000 <init_module>:
   0:   e1a0c00d    mov ip, sp
   4:   e92dd800    push    {fp, ip, lr, pc}
   8:   e24cb004    sub fp, ip, #4
   c:   e52de004    push    {lr}        ; (str lr, [sp, #-4]!)
  10:   ebfffffe    bl  0 <__gnu_mcount_nc>
  14:   e3000000    movw    r0, #0
  18:   e3400000    movt    r0, #0
  1c:   ebfffffe    bl  0 <printk>
  20:   e3a00000    mov r0, #0
  24:   e3a0300a    mov r3, #10
  28:   e5803000    str r3, [r0]
  2c:   e89da800    ldm sp, {fp, sp, pc}

00000030 <cleanup_module>:
  30:   e1a0c00d    mov ip, sp
  34:   e92dd800    push    {fp, ip, lr, pc}
  38:   e24cb004    sub fp, ip, #4
  3c:   e52de004    push    {lr}        ; (str lr, [sp, #-4]!)
  40:   ebfffffe    bl  0 <__gnu_mcount_nc>
  44:   e3000000    movw    r0, #0
  48:   e3400000    movt    r0, #0
  4c:   ebfffffe    bl  0 <printk>
  50:   e89da800    ldm sp, {fp, sp, pc}

セクション .plt の逆アセンブル:

000000c0 <.plt>:
    ...

これでデバッグ対象は準備完了

実機側の準備

今回はUARTコンソールを使用する必要があるのであらかじめブートパーティションにあるconfig.txtに下記の設定をしておく。

enable_uart=1

bitbakeする時にlocal.confに下記を設定している場合は不要(というか設定済み)

ENABLE_UART = "1"

この状態でラズパイを起動して、PCからminicomなどのシリアルコンソールで接続する。

raspberrypi4 login: root
root@raspberrypi4:~#

下記のコマンドでカーネルデバッガが使用するシリアルポートを設定しておく。

$ echo ttyS0 > /sys/module/kgdboc/parameters/kgdboc

ラズパイを使用している場合、少しノウハウがありBTの有効/無効によって設定するポートが異なる。

BT有無 シリルポート
無効 ttyAMA0
有効 ttyS0

これはBTを使用している場合HCIにUARTを取られてしまうためで、デバイスツリーの設定で「dtoverlay=miniuart-bt」とかする場合はBT有効でもttyAMA0を指定することになる。

デバッグ

先ほど作成したバグ有りのhello.koをラズパイに書き込んでinsmodする。

# insmod ./hello.ko
[  452.512402] hello: loading out-of-tree module taints kernel.
[  452.518998] hello: init_module is called
[  452.523001] 8<--- cut here ---
[  452.526152] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[  452.534374] pgd = 5a6455cf
[  452.537155] [00000000] *pgd=1710d003, *pmd=00000000
[  452.542127] Internal error: Oops: a06 [#1] SMP ARM

Entering kdb (current=0xd6d19e80, pid 425) on processor 1 Oops: (null)
due to oops @ 0xbf07a028
CPU: 1 PID: 425 Comm: insmod Tainted: G         C O      5.4.79-v7l #1
Hardware name: BCM2711
PC is at init_module+0x28/0x30 [hello]
LR is at irq_work_queue+0x14/0x2c
pc : [<bf07a028>]    lr : [<c035287c>]    psr: 60030013
sp : ef959d88  ip : 00000007  fp : ef959d94
r10: 00000124  r9 : ef959f30  r8 : 00000028
r7 : d71c0580  r6 : 00000000  r5 : d71c0640  r4 : bf07a000
r3 : 0000000a  r2 : 00000000  r1 : 00000000  r0 : 00000000
Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
Control: 30c5383d  Table: 173a0fc0  DAC: 55555555
CPU: 1 PID: 425 Comm: insmod Tainted: G         C O      5.4.79-v7l #1
Hardware name: BCM2711
Backtrace:
[<c020e054>] (dump_backtrace) from [<c020e3b8>] (show_stack+0x20/0x24)
 r7:ffffffff r6:00000000 r5:60030193 r4:c12a5cb0
[<c020e398>] (show_stack) from [<c0b80d0c>] (dump_stack+0xd0/0x114)
[<c0b80c3c>] (dump_stack) from [<c0209c80>] (show_regs+0x1c/0x20)
 r9:c1205ff0 r8:00000005 r7:ffffe000 r6:0000000f r5:c1212728 r4:c12ef2cc
[<c0209c64>] (show_regs) from [<c0308d94>] (kdb_main_loop+0x470/0x984)
more>

プロンプトがmore>の時は出力が途中なので任意のキーを押すと次の行が表示される。qを押すと中断できる。

下記の状態になるとコマンド入力できる。

[1]kdb>

まず最初にバックトレースを確認する。

[1]gdb> bt
...(snip)...
pc[<c0217310>] (do_DataAbort) from [<c02019b4>] (__dabt_svc+0x54/0x80)
Exception stack(0xef959d38 to 0xef959d80)
9d20:                                                       00000000 00000000
9d40: 00000000 0000000a bf07a000 d71c0640 00000000 d71c0580 00000028 ef959f30
9d60: 00000124 ef959d94 00000007 ef959d88 c035287c bf07a028 60030013 ffffffff
 r8:00000028 r7:ef959d6c r6:ffffffff r5:60030013 r4:bf07a028
[<bf07a000>] (init_module [hello]) from [<c0203110>] (do_one_initcall+0x54/0x268)
[<c02030bc>] (do_one_initcall) from [<c02d2a6c>] (do_init_module+0x70/0x2a4)
 r7:d71c0580 r6:00000002 r5:d71c0640 r4:bf07c000
[<c02d29fc>] (do_init_module) from [<c02d53c0>] (load_module+0x2680/0x29fc)
 r6:00000002 r5:00000002 r4:d71c0540
[<c02d2d40>] (load_module) from [<c02d59b4>] (sys_finit_module+0xe0/0xf8)
 r10:0000017b r9:ef958000 r8:c02011c4 r7:0000017b r6:004cd9e8 r5:00000003
 r4:00000000
[<c02d58d4>] (sys_finit_module) from [<c0201000>] (ret_fast_syscall+0x0/0x28)
Exception stack(0xef959fa8 to 0xef959ff0)
9fa0:                   00000000 00000000 00000003 004cd9e8 00000000 becaec44
9fc0: 00000000 00000000 01335190 0000017b becaec88 004cb9d0 00000002 004df768
9fe0: becaec50 becaec40 004c6e0d b6eb1f12
 r6:01335190 r5:00000000 r4:00000000

do_DataAbortが発生しているいることがわかる。

次にレジスタを確認する。

[1]kdb> rd
r0: 00000000  r1: 00000000  r2: 00000000  r3: 0000000a  r4: bf07a000
r5: d71c0640  r6: 00000000  r7: d71c0580  r8: 00000028  r9: ef959f30
r10: 00000124  fp: ef959d94  ip: 00000007  sp: ef959d88  lr: c035287c
pc: bf07a028  f0: ??  f1: ??  f2: ??  f3: ??  f4: ??  f5: ??  f6: ??  f7: ??
fps: 00000000  cpsr: 60030013

pcがbf07a028であることに注目。つまりこのアドレスでプログラムがアボードしている。

次にロードされているモジュールの一覧を確認する。

[1]kdb> lsmod
Module                  Size  modstruct     Used by
hello                  16384  0xbf07c000    1  (Loading) 0xbf07a000 [ ]
nfc                    81920  0xbf1ac280    0  (Live) 0xbf19e000 [ ]
bnep                   20480  0xbf071180    2  (Live) 0xbf06e000 [ ]
bluetooth             376832  0xbf337400    9  (Live) 0xbf2ec000 [ bluetooth ]
ecdh_generic           16384  0xbf04c1c0    1  (Live) 0xbf04a000 [ ecdh_generic ]
ecc                    36864  0xbf1051c0    1  (Live) 0xbf0ff000 [ ecc ]
ipv6                  466944  0xbf2d39c0   28  (Live) 0xbf279000 [ ]
hid_logitech_hidpp     40960  0xbf09d100    0  (Live) 0xbf096000 [ ]
rpivid_mem             16384  0xbf06b080    0  (Live) 0xbf069000 [ ]
joydev                 20480  0xbf057080    0  (Live) 0xbf054000 [ ]
brcmfmac              323584  0xbf15af80    0  (Live) 0xbf121000 [ ]
brcmutil               24576  0xbf03c040    1  (Live) 0xbf039000 [ brcmutil ]
sha256_generic         16384  0xbf051400    0  (Live) 0xbf04f000 [ ]
libsha256              20480  0xbf003000    1  (Live) 0xbf000000 [ libsha256 ]
cfg80211              688128  0xbf249300    1  (Live) 0xbf1d0000 [ cfg80211 ]
bcm2835_codec          36864  0xbf046080    0  (Live) 0xbf040000 [ ]
bcm2835_isp            32768  0xbf02e080    0  (Live) 0xbf029000 [ ]
bcm2835_v4l2           49152  0xbf024300    0  (Live) 0xbf01c000 [ ]
rfkill                 28672  0xbf11d200    4  (Live) 0xbf119000 [ rfkill rfkill rfkill ]
v4l2_mem2mem           32768  0xbf10f000    1  (Live) 0xbf10b000 [ v4l2_mem2mem ]
bcm2835_mmal_vchiq     28672  0xbf092000    3  (Live) 0xbf08e000 [ bcm2835_mmal_vchiq bcm2835_mmal_vchiq bcm2835_mmal_vchiq ]

プログラムがアボードしたアドレスに一番近いモジュールは、当然ながらhelloとなっている。

これらから読み取れること

hello.koは0xbf07a000にロードされている。

hello                  16384  0xbf07c000    1  (Loading) 0xbf07a000 [ ]

レジスタの状態からプログラムがアボートしたと思われるアドレス(pcのアドレス)はbf07a028

[1]kdb> rd
r0: 00000000  r1: 00000000  r2: 00000000  r3: 0000000a  r4: bf07a000
r5: d71c0640  r6: 00000000  r7: d71c0580  r8: 00000028  r9: ef959f30
r10: 00000124  fp: ef959d94  ip: 00000007  sp: ef959d88  lr: c035287c
pc: bf07a028  f0: ??  f1: ??  f2: ??  f3: ??  f4: ??  f5: ??  f6: ??  f7: ??
fps: 00000000  cpsr: 60030013

つまりhello.koの先頭から0x28進んだ場所だと推測される。

hello.koのアセンブリは次のようになっている。

00000000 <init_module>:
   0:   e1a0c00d    mov ip, sp
   4:   e92dd800    push    {fp, ip, lr, pc}
   8:   e24cb004    sub fp, ip, #4
   c:   e52de004    push    {lr}        ; (str lr, [sp, #-4]!)
  10:   ebfffffe    bl  0 <__gnu_mcount_nc>
  14:   e3000000    movw    r0, #0
  18:   e3400000    movt    r0, #0
  1c:   ebfffffe    bl  0 <printk>
  20:   e3a00000    mov r0, #0
  24:   e3a0300a    mov r3, #10
  28:   e5803000    str r3, [r0]    <-------------ここ
  2c:   e89da800    ldm sp, {fp, sp, pc}

つまり28: e5803000 str r3, [r0]の行で問題が発生していると推測することができる。

アセンブリと直近レジスタの値を当てはめていくと下記のように読める。

r0: 00000000  r1: 00000000  r2: 00000000  r3: 0000000a  r4: bf07a000
r5: d71c0640  r6: 00000000  r7: d71c0580  r8: 00000028  r9: ef959f30
r10: 00000124  fp: ef959d94  ip: 00000007  sp: ef959d88  lr: c035287c

  20:   e3a00000    mov r0, #0   // r0に0を代入
  24:   e3a0300a    mov r3, #10  // r3に10を代入
  28:   e5803000    str r3, [r0] // r0が指し示すアドレスにr3を代入

つまり0番地に10を書き込もうとしている。

hello.cに仕込んだバグが下記なので、

int init_module(void)
{
        int *p = NULL;

        printk("hello: init_module is called\n");
        *p = 10; // <-- 28:    e5803000    str r3, [r0] と一致する
        return 0;
}

*p = 10でプログラムがアボートしていることがわかる。

まとめ

実際にカーネルで問題が発生した場合はこんなに簡単に解析できることはないと思うが、 問題が発生した直後のスタックの状態やレジスタの状態が覗けるので、かなり便利だと思う。

また、今回は言及しなかったが、dumpallコマンドを実行すると、この時点で実行中の全てのプロセスの一覧およびすべてのCPUのスタックダンプ、dmesgの内容などが取れるため、この出力結果を保存しておいて机上でデバッグをする。なんてこともできる。

今度何かあったらkdbを使ってみようと思う。

参考

Using Serial kdb / kgdb to Debug the Linux Kernel