この記事はDMM.com #1 Advent Calendar 2017の22日目の記事です。
DMM.comのアドベントカレンダーはこちらです。
DMM.com #1 Advent Calendar 2017
DMM.com #2 Advent Calendar 2017
昨日は@usagi-fさんのGUI構築でオブジェクト指向を考えてみるでした。
明日は@Ihara-kentaさんです。
Kia Ora @masami256です。
この記事ではLinux 4.15で入ったWARN*_ONCE系マクロのカウンタクリア機能について書いてみます。記事の執筆時点では4.15は正式にリリースされてないので、もしかしたらrevertされる可能性もないとは言えませんが、まあ大丈夫でしょう。
この記事ではカーネルやc言語に慣れていなくても雰囲気を掴めることを目標にします。
tl;dr
dataセクションにonceという領域が出来て、WARN_*ONCEマクロで使うカウンタはそこに置かれるようになりました。そして、カウンタのクリアはこの領域をmemcet()で0クリアします。
WARN*_ONCE系マクロ
このマクロはカーネルのワーニングメッセージを出すためのマクロで、以下のようなマクロがあります。
WARN_ONCE
WARN_ON_ONCE
WARN_TAINT_ONCE
いずれもONCEと付いていることから分かるように、これらのマクロでは一度だけ実行されます。Linux 4.15からはこのカウンタをクリアできるようになりました。ソースコード上の特定の場所にあるWARN_*ONCEマクロのカウンタのリセットはできませんが、便利になったことをは確かですね〜
マクロの使い方はWARN_ON_ONCEなら条件一つ、WARN_ONCEの場合は条件と任意のメッセージを渡せます。
WARN_ON_ONCE(i != j); // 条件式を使う場合
WARN_ON_CONE(1); // 常に
WARN_ON(i != j, "error");
ワーニングメッセージの読み方
ワーニングは以下のように出力されます。スタックトレースやレジスタのダンプが出るのでちょっとしたprintfデバッグ用途で使う人もいると思います（自分とか）。
[ 457.560235] WARNING: CPU: 3 PID: 1267 at /home/masami/warn_on_once_test/warn_on_once_test.c:19 warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
[ 457.560236] Modules linked in: warn_on_once_test(OE) ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables kvm_intel kvm irqbypass crct10dif_pclmul ppdev crc32_pclmul crc32c_intel ghash_clmulni_intel parport_pc parport virtio_balloon virtio_net i2c_piix4 qxl drm_kms_helper virtio_console virtio_blk ttm drm ata_generic virtio_pci virtio_ring serio_raw pata_acpi virtio qemu_fw_cfg [last unloaded: warn_on_once_test]
[ 457.560288] CPU: 3 PID: 1267 Comm: sh Tainted: G W OE 4.15.0-rc1-ktest+ #27
[ 457.560290] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-2.fc27 04/01/2014
[ 457.560291] task: ffff91946877cc00 task.stack: ffffb346c22d0000
[ 457.560295] RIP: 0010:warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
[ 457.560296] RSP: 0018:ffffb346c22d3e20 EFLAGS: 00010282
[ 457.560298] RAX: 0000000000000039 RBX: 00005635d48e9c50 RCX: 0000000000000000
[ 457.560300] RDX: 0000000000000000 RSI: ffff91947fd8e0f8 RDI: ffff91947fd8e0f8
[ 457.560301] RBP: ffff91946826e600 R08: 000000000000020a R09: 0000000000000004
[ 457.560303] R10: 000000000000000a R11: 0000000000000001 R12: ffff91946b36f6c0
[ 457.560304] R13: 00005635d48e9c50 R14: 0000000000000002 R15: ffffb346c22d3f20
[ 457.560307] FS: 00007f3ac18efb80(0000) GS:ffff91947fd80000(0000) knlGS:0000000000000000
[ 457.560308] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 457.560310] CR2: 00005635d48eac58 CR3: 00000004293b6004 CR4: 00000000001606e0
[ 457.560316] Call Trace:
[ 457.560325] full_proxy_write+0x4d/0x70
[ 457.560332] __vfs_write+0x33/0x170
[ 457.560337] ? handle_mm_fault+0xaa/0x1f0
[ 457.560345] ? __do_page_fault+0x280/0x4e0
[ 457.560348] vfs_write+0xad/0x1a0
[ 457.560352] SyS_write+0x52/0xc0
[ 457.560359] entry_SYSCALL_64_fastpath+0x1a/0x7d
[ 457.560362] RIP: 0033:0x7f3ac0fc8ea4
[ 457.560363] RSP: 002b:00007ffc1374ee58 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 457.560365] RAX: ffffffffffffffda RBX: 00007f3ac129fc20 RCX: 00007f3ac0fc8ea4
[ 457.560367] RDX: 0000000000000002 RSI: 00005635d48e9c50 RDI: 0000000000000001
[ 457.560368] RBP: 00007f3ac129fc78 R08: 000000000000000a R09: 0000000000000001
[ 457.560369] R10: 000000000000000a R11: 0000000000000246 R12: 0000000000001010
[ 457.560370] R13: 0000000000001000 R14: 00007f3ac129fc78 R15: 0000000000000000
[ 457.560373] Code: 0f 1f 44 00 00 8b 15 f5 1f 00 00 53 48 c7 c7 28 60 6b c0 48 89 f3 48 c7 c6 10 61 6b c0 8d 42 01 89 05 da 1f 00 00 e8 60 70 a4 d6 <0f> ff 48 89 df be 08 00 00 00 5b e9 75 63 d8 d6 0f 1f 44 00 00
[ 457.560415] ---[ end trace 4a3b9d9db1b9dcf2 ]---
このログを見慣れない方向けに簡単に内容を説明すると、先頭行はこのワーニングを出した時に動いていたcpuコア、プロセスID、ファイル名と行数、関数名、実行箇所の関数先頭からのオフセット/関数のサイズとなっています。
[ 457.560235] WARNING: CPU: 3 PID: 1267 at /home/masami/warn_on_once_test/warn_on_once_test.c:19 warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
次のModules linked in〜の行はロードされているモジュールのリストです。
[ 457.560236] Modules linked in: warn_on_once_test(OE) ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables kvm_intel kvm irqbypass crct10dif_pclmul ppdev crc32_pclmul crc32c_intel ghash_clmulni_intel parport_pc parport virtio_balloon virtio_net i2c_piix4 qxl drm_kms_helper virtio_console virtio_blk ttm drm ata_generic virtio_pci virtio_ring serio_raw pata_acpi virtio qemu_fw_cfg [last unloaded: warn_on_once_test]
その次の最初のほうは先頭行と同じです。Commは実行したプログラム名で、この場合はshです。Taintedは直訳すると汚染されているという意味なんですが、例えばプロプライエタリなモジュールがロードされているとか、カーネル本体のソースにないモジュールがロードされているなどの状況です。ここではG、W、O、Eの4つの記号が表示されています。これらの意味はカーネルソースに付属のドキュメントtainted-kernels.rstに説明があります。
[ 457.560288] CPU: 3 PID: 1267 Comm: sh Tainted: G W OE 4.15.0-rc1-ktest+ #27
次の行はハードウェアの情報です。
[ 457.560290] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-2.fc27 04/01/2014
残りはレジスタのダンプ、スタックトレース、実行してた部分のバイナリダンプです。
WARN_*ONCEマクロを使っている分には不要なんですが、バイナリダンプはカーネルソースのscripts/decode_stacktrace.shというツールでデコードすることができます。
使い方はこうです。
masami@kerntest:~/linux-kernel/scripts (ktest %)$ ./decode_stacktrace.sh
Usage:
./decode_stacktrace.sh [vmlinux] [base path] [modules path]
base pathはカーネルソールのディレクトリで、アウトオブツリーなモジュールの場合はmodule pathも指定します。
そして、トレースのログを読み込ませます。
./decode_stacktrace.sh ../vmlinux ~/linux-kernel ~/warn_on_once_test/ < ~/warn.log
途中を省略して、Codeの部分はこのように出力されます。
[ 457.560373] Code: 0f 1f 44 00 00 8b 15 f5 1f 00 00 53 48 c7 c7 28 60 6b c0 48 89 f3 48 c7 c6 10 61 6b c0 8d 42 01 89 05 da 1f 00 00 e8 60 70 a4 d6 <0f> ff 48 89 df be 08 00 00 00 5b e9 75 63 d8 d6 0f 1f 44 00 00
All code
========
0: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
5: 8b 15 f5 1f 00 00 mov 0x1ff5(%rip),%edx # 0x2000
b: 53 push %rbx
c: 48 c7 c7 28 60 6b c0 mov $0xffffffffc06b6028,%rdi
13: 48 89 f3 mov %rsi,%rbx
16: 48 c7 c6 10 61 6b c0 mov $0xffffffffc06b6110,%rsi
1d: 8d 42 01 lea 0x1(%rdx),%eax
20: 89 05 da 1f 00 00 mov %eax,0x1fda(%rip) # 0x2000
26: e8 60 70 a4 d6 callq 0xffffffffd6a4708b
2b:* 0f ff (bad) <-- trapping instruction
2d: 48 89 df mov %rbx,%rdi
30: be 08 00 00 00 mov $0x8,%esi
35: 5b pop %rbx
36: e9 75 63 d8 d6 jmpq 0xffffffffd6d863b0
3b: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
Code starting with the faulting instruction
===========================================
0: 0f ff (bad)
2: 48 89 df mov %rbx,%rdi
5: be 08 00 00 00 mov $0x8,%esi
a: 5b pop %rbx
b: e9 75 63 d8 d6 jmpq 0xffffffffd6d86385
10: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
[ 457.560415] ---[ end trace 4a3b9d9db1b9dcf2 ]---
クリア機能の使い方
使い方は簡単で、/sys/kernel/debug/clear_warn_onceに何か書き込むだけです。こんな感じで使います。
sudo sh -c "echo 1 > /sys/kernel/debug/clear_warn_once"
試してみる
実際に試してみましょう。テスト用にカーネルモジュールを作ります。このモジュールでは/sys/kernel/debug/warn_on_once_testというファイルに何かを書き込むとwarn_on_once_test_write()が呼ばれます。warn_on_once_test_write()ではWARN_ON_ONCE()を実行します。
テストコード
#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt
#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/debugfs.h>
#include <asm/uaccess.h>
MODULE_DESCRIPTION("warn_on_once test");
MODULE_AUTHOR("masami256");
MODULE_LICENSE("GPL");
static struct dentry *warn_on_once_test_file;
static ssize_t warn_on_once_test_write(struct file *filp, const char __user *buf, size_t len, loff_t *ppos)
{
static int called_cnt = 1;
pr_info("%s called %d times\n", __func__, called_cnt++);
WARN_ON_ONCE(1);
return strnlen_user(buf, 8);
}
static struct file_operations warn_on_once_test_fops = {
.owner = THIS_MODULE,
.write = warn_on_once_test_write,
};
static int warn_on_once_test_setup_debugfs(void)
{
warn_on_once_test_file = debugfs_create_file("warn_on_once_test", 0200,
NULL, NULL,
&warn_on_once_test_fops);
return !warn_on_once_test_file ? -1 : 0;
}
static int warn_on_once_test_init(void)
{
int ret;
ret = warn_on_once_test_setup_debugfs();
if (ret) {
WARN_ON(1);
return -1;
}
pr_info("setup done.\n");
return 0;
}
static void warn_on_once_test_cleanup(void)
{
pr_info("cleanup\n");
debugfs_remove(warn_on_once_test_file);
}
module_init(warn_on_once_test_init);
module_exit(warn_on_once_test_cleanup);
こちらはMakefileです。
KERNDIR := /lib/modules/`uname -r`/build
BUILD_DIR := $(shell pwd)
VERBOSE = 0
obj-m := warn_on_once_test.o
smallmod-objs := warn_on_once_test.o
all:
make -C $(KERNDIR) SUBDIRS=$(BUILD_DIR) KBUILD_VERBOSE=$(VERBOSE) modules
clean:
rm -f *.o
rm -f *.ko
rm -f *.mod.c
rm -f *~
実行結果
以下の手順を行います
1. モジュールをロード
2. warn_on_once_testファイルに3回データを書き込み
3. clear_warn_onceファイルにデータを書き込んで回数をクリア
4. warn_on_once_testファイルにデータを書き込み
masami@kerntest:~/warn_on_once_test$ sudo insmod warn_on_once_test.ko
masami@kerntest:~/warn_on_once_test$ sudo sh -c "echo 1 > /sys/kernel/debug/warn_on_once_test"
masami@kerntest:~/warn_on_once_test$ sudo sh -c "echo 1 > /sys/kernel/debug/warn_on_once_test"
masami@kerntest:~/warn_on_once_test$ sudo sh -c "echo 1 > /sys/kernel/debug/warn_on_once_test"
masami@kerntest:~/warn_on_once_test$ sudo sh -c "echo 1 > /sys/kernel/debug/clear_warn_once"
masami@kerntest:~/warn_on_once_test$ sudo sh -c "echo 1 > /sys/kernel/debug/warn_on_once_test"
dmesgの出力内容はこのようになります。
masami@kerntest:~/warn_on_once_test$ dmesg
[ 6510.997145] warn_on_once_test: setup done.
[ 6516.822001] warn_on_once_test: warn_on_once_test_write called 1 times
[ 6516.822037] WARNING: CPU: 0 PID: 2155 at /home/masami/warn_on_once_test/warn_on_once_test.c:19 warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
[ 6516.822038] Modules linked in: warn_on_once_test(OE) ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables kvm_intel kvm irqbypass crct10dif_pclmul ppdev crc32_pclmul crc32c_intel ghash_clmulni_intel parport_pc parport virtio_balloon virtio_net i2c_piix4 qxl drm_kms_helper virtio_console virtio_blk ttm drm ata_generic virtio_pci virtio_ring serio_raw pata_acpi virtio qemu_fw_cfg [last unloaded: warn_on_once_test]
[ 6516.822064] CPU: 0 PID: 2155 Comm: sh Tainted: G W OE 4.15.0-rc1-ktest+ #27
[ 6516.822065] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-2.fc27 04/01/2014
[ 6516.822065] task: ffff919468ca2600 task.stack: ffffb346c19cc000
[ 6516.822067] RIP: 0010:warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
[ 6516.822067] RSP: 0018:ffffb346c19cfe20 EFLAGS: 00010282
[ 6516.822068] RAX: 0000000000000039 RBX: 0000564088595c50 RCX: 0000000000000000
[ 6516.822069] RDX: 0000000000000000 RSI: ffff91947fc0e0f8 RDI: ffff91947fc0e0f8
[ 6516.822069] RBP: ffff919469743500 R08: 0000000000000251 R09: 0000000000000004
[ 6516.822069] R10: 000000000000000a R11: 0000000000000001 R12: ffff91944aa14d80
[ 6516.822070] R13: 0000564088595c50 R14: 0000000000000002 R15: ffffb346c19cff20
[ 6516.822071] FS: 00007f7f80d6bb80(0000) GS:ffff91947fc00000(0000) knlGS:0000000000000000
[ 6516.822072] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6516.822072] CR2: 0000564088596c58 CR3: 0000000427b31005 CR4: 00000000001606f0
[ 6516.822076] Call Trace:
[ 6516.822081] full_proxy_write+0x4d/0x70
[ 6516.822085] __vfs_write+0x33/0x170
[ 6516.822088] ? handle_mm_fault+0xaa/0x1f0
[ 6516.822092] ? __do_page_fault+0x280/0x4e0
[ 6516.822093] vfs_write+0xad/0x1a0
[ 6516.822095] SyS_write+0x52/0xc0
[ 6516.822099] entry_SYSCALL_64_fastpath+0x1a/0x7d
[ 6516.822100] RIP: 0033:0x7f7f80444ea4
[ 6516.822100] RSP: 002b:00007fff8ed27698 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 6516.822101] RAX: ffffffffffffffda RBX: 00007f7f8071bc20 RCX: 00007f7f80444ea4
[ 6516.822102] RDX: 0000000000000002 RSI: 0000564088595c50 RDI: 0000000000000001
[ 6516.822102] RBP: 00007f7f8071bc78 R08: 000000000000000a R09: 0000000000000001
[ 6516.822102] R10: 000000000000000a R11: 0000000000000246 R12: 0000000000001010
[ 6516.822103] R13: 0000000000001000 R14: 00007f7f8071bc78 R15: 0000000000000000
[ 6516.822104] Code: 0f 1f 44 00 00 8b 15 f5 1f 00 00 53 48 c7 c7 28 60 6b c0 48 89 f3 48 c7 c6 10 61 6b c0 8d 42 01 89 05 da 1f 00 00 e8 60 70 a4 d6 <0f> ff 48 89 df be 08 00 00 00 5b e9 75 63 d8 d6 0f 1f 44 00 00
[ 6516.822120] ---[ end trace 4a3b9d9db1b9dcf4 ]---
[ 6518.897400] warn_on_once_test: warn_on_once_test_write called 2 times
[ 6519.747239] warn_on_once_test: warn_on_once_test_write called 3 times
[ 6543.229030] warn_on_once_test: warn_on_once_test_write called 4 times
[ 6543.229081] WARNING: CPU: 2 PID: 2220 at /home/masami/warn_on_once_test/warn_on_once_test.c:19 warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
[ 6543.229082] Modules linked in: warn_on_once_test(OE) ip6t_rpfilter ip6t_REJECT nf_reject_ipv6 xt_conntrack ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c iptable_mangle iptable_raw iptable_security ebtable_filter ebtables ip6table_filter ip6_tables kvm_intel kvm irqbypass crct10dif_pclmul ppdev crc32_pclmul crc32c_intel ghash_clmulni_intel parport_pc parport virtio_balloon virtio_net i2c_piix4 qxl drm_kms_helper virtio_console virtio_blk ttm drm ata_generic virtio_pci virtio_ring serio_raw pata_acpi virtio qemu_fw_cfg [last unloaded: warn_on_once_test]
[ 6543.229133] CPU: 2 PID: 2220 Comm: sh Tainted: G W OE 4.15.0-rc1-ktest+ #27
[ 6543.229139] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-2.fc27 04/01/2014
[ 6543.229141] task: ffff919467f7a600 task.stack: ffffb346c1f74000
[ 6543.229145] RIP: 0010:warn_on_once_test_write+0x2b/0x40 [warn_on_once_test]
[ 6543.229146] RSP: 0018:ffffb346c1f77e20 EFLAGS: 00010282
[ 6543.229148] RAX: 0000000000000039 RBX: 0000555b3e648c50 RCX: 0000000000000000
[ 6543.229150] RDX: 0000000000000000 RSI: ffff91947fd0e0f8 RDI: ffff91947fd0e0f8
[ 6543.229151] RBP: ffff9194683ce700 R08: 0000000000000274 R09: 0000000000000004
[ 6543.229152] R10: 000000000000000a R11: 0000000000000001 R12: ffff91944aa14d80
[ 6543.229154] R13: 0000555b3e648c50 R14: 0000000000000002 R15: ffffb346c1f77f20
[ 6543.229156] FS: 00007fdc053d2b80(0000) GS:ffff91947fd00000(0000) knlGS:0000000000000000
[ 6543.229158] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6543.229159] CR2: 0000555b3e649c58 CR3: 0000000428fcd006 CR4: 00000000001606e0
[ 6543.229165] Call Trace:
[ 6543.229173] full_proxy_write+0x4d/0x70
[ 6543.229179] __vfs_write+0x33/0x170
[ 6543.229184] ? handle_mm_fault+0xaa/0x1f0
[ 6543.229190] ? __do_page_fault+0x280/0x4e0
[ 6543.229193] vfs_write+0xad/0x1a0
[ 6543.229197] SyS_write+0x52/0xc0
[ 6543.229203] entry_SYSCALL_64_fastpath+0x1a/0x7d
[ 6543.229205] RIP: 0033:0x7fdc04aabea4
[ 6543.229207] RSP: 002b:00007ffe86be5438 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
[ 6543.229209] RAX: ffffffffffffffda RBX: 00007fdc04d82c20 RCX: 00007fdc04aabea4
[ 6543.229210] RDX: 0000000000000002 RSI: 0000555b3e648c50 RDI: 0000000000000001
[ 6543.229211] RBP: 00007fdc04d82c78 R08: 000000000000000a R09: 0000000000000001
[ 6543.229212] R10: 000000000000000a R11: 0000000000000246 R12: 0000000000001010
[ 6543.229214] R13: 0000000000001000 R14: 00007fdc04d82c78 R15: 0000000000000000
[ 6543.229216] Code: 0f 1f 44 00 00 8b 15 f5 1f 00 00 53 48 c7 c7 28 60 6b c0 48 89 f3 48 c7 c6 10 61 6b c0 8d 42 01 89 05 da 1f 00 00 e8 60 70 a4 d6 <0f> ff 48 89 df be 08 00 00 00 5b e9 75 63 d8 d6 0f 1f 44 00 00
[ 6543.229258] ---[ end trace 4a3b9d9db1b9dcf5 ]---
一回目のwarn_on_once_testへの書き込みでログが出て、その後の3回はワーニングは出ません。そして、回数をクリアすることで次のwarn_on_once_testへの書き込みでワーニングが出てますね！
patch
patchは2つあります。
- kernel debug: support resetting WARN*_ONCE
- kernel debug: support resetting WARN_ONCE for all architectures
主要なのは kernel debug: support resetting WARN*_ONCE のほうです。もう一つのほうは前者の方法ではクリアできないアーキテクチャ向けのpatchです。この記事では個々のpatchではなく、4.15-rc1に入ったコードをベースに読んでいきますが、まずはWARN_*ONCEマクロの実装を見てみましょう。どのようにWARN_*ONCEマクロが実装されているかを理解したほうがクリアの処理は簡単に理解できます(・∀・) WARN_ON_ONCEの実装を読んでみましょう。
WARN_ON_ONCEの実装
実装はこのようになっています。
#define WARN_ON_ONCE(condition) ({ \
static bool __section(.data.once) __warned; \
int __ret_warn_once = !!(condition); \
\
if (unlikely(__ret_warn_once && !__warned)) { \
__warned = true; \
WARN_ON(1); \
} \
unlikely(__ret_warn_once); \
})
普通のc言語のコードだとあまり見かけないのはこの部分でしょうか。
__section(.data.once)
これ以外は素直な内容だと思います。まずこの行はbool型の__warnedをstatic変数として宣言しています。sectionのところは後で解説します。
static bool __section(.data.once) __warned;
次の行が条件を評価している部分です。条件が真なら__ret_warn_onceは1になります。
int __ret_warn_once = !!(condition);
ここで条件の評価結果が1で__warnedがfalseの場合にWARN_ONマクロでワーニングメッセージを表示しています。__warnedをtrueにするのも忘れずに。
if (unlikely(__ret_warn_once && !__warned)) { \
__warned = true; \
WARN_ON(1); \
}
最後の行は特に意味ありません。
unlikely(__ret_warn_once);
処理としては特に変わったことはありませんね。では、後回しにした __section(.data.once) の説明をしたいと思います。
まずセクションとはですが、ほんとに大雑把に説明するとグローバル変数は.dataセクションに配置する等の決まりがあって、それの配置場所がセクションという感じです。
ほんとに適当な説明なので実際に見てみますと、
例えば、このようなコードの場合、.bssセクションにiが置かれ、.dataセクションにはjが置かれます。
static int i;
static int j = 0xdeadbeef;
int main(int argc, char **argv)
{
return 0;
}
上記のコードをコンパイルしてobjdumpコマンドで.bssと.dataセクションを見てみます。
masami@kerntest:~$ objdump -D -j .bss -j .data ./a.out
./a.out: file format elf64-x86-64
Disassembly of section .data:
0000000000601018 <__data_start>:
601018: 00 00 add %al,(%rax)
...
000000000060101c <j>:
60101c: ef out %eax,(%dx)
60101d: be .byte 0xbe
60101e: ad lods %ds:(%rsi),%eax
60101f: de .byte 0xde
Disassembly of section .bss:
0000000000601020 <__bss_start>:
601020: 00 00 add %al,(%rax)
...
0000000000601024 <i>:
601024: 00 00 add %al,(%rax)
...
jは.dataセクションに置かれて、下から読むとdeadbeefとなってるのがわかると思います。
iは00 00なんで０です。
これを踏まえてstatic bool __section(.data.once) __warnedに戻ると、これは__warned変数をどのセクションに置くかを決めています。
そしてLinuxカーネルの.dataセクションはinclude/asm-generic/vmlinux.lds.hにて以下のようなマクロで作成しています。.dataセクションを更に細かく分けて使用しています。
#define DATA_DATA \
*(.xiptext) \
*(DATA_MAIN) \
*(.ref.data) \
*(.data..shared_aligned) /* percpu related */ \
MEM_KEEP(init.data) \
MEM_KEEP(exit.data) \
*(.data.unlikely) \
VMLINUX_SYMBOL(__start_once) = .; \
*(.data.once) \
VMLINUX_SYMBOL(__end_once) = .; \
STRUCT_ALIGN(); \
~略
これは最終的にはarch/x86/kernel/vmlinux.ldsというファイルになります。
このマクロ内で__start_onceと__end_onceの２つのシンボルが定義されています。
VMLINUX_SYMBOL(__start_once) = .; \
*(.data.once) \
VMLINUX_SYMBOL(__end_once) = .; \
これらのシンボルがinclude/asm-generic/sections.hでこのようにextern宣言されていてc言語のコードからアクセスできるようになっています。
extern char __start_once[], __end_once[];
これで__warned変数が.dataセクションの中のonceという領域に置かれることがわかりました。
あ、変数名は全て__warnedですが、マクロは{}で囲われていて、その中で変数を定義しているので重複定義にはなりません。
ここまでで __warningを出力したかを判定する変数は.dataセクションのonceという領域に置く__ ということがわかりました。
ちなみに、以前はonceではなくてunlikelyとなっていました。
c
static bool __section(.data.unlikely) __warned; \
カウンタのクリア処理
では、カウンタをクリアする処理を見てみましょう。kernel/panic.cにclear_warn_once_set()という関数が追加されていて、これがクリアする処理です。generic_bug_clear_once()は今回は無視して構いません。
static int clear_warn_once_set(void *data, u64 val)
{
generic_bug_clear_once();
memset(__start_once, 0, __end_once - __start_once);
return 0;
}
memsetで０クリアしてるだけですね。__start_onceと__end_onceがここででてきてますね。ここの処理はメモリの開始アドレス__start_onceから__end_once - __start_onceバイトの領域を０でクリアしています。
これでWARN_ONを行ってtrueとなった変数達が一気にfalseに変わることになり、再度WARN_*ONCEマクロでワーニングメッセージを出力できるようになります。
まとめ
カウンタのクリア処理の内容は簡単でしたね( ´ー｀)ﾌｩｰ．．．