Linux 4.15で入ったWARN*_ONCE系マクロのカウンタクリア機能

この記事は[DMM.com #1 Advent Calendar 2017](https://qiita.com/advent-calendar/2017/dmm)の22日目の記事です。

DMM.comのアドベントカレンダーはこちらです。
[DMM.com #1 Advent Calendar 2017](https://qiita.com/advent-calendar/2017/dmm)
[DMM.com #2 Advent Calendar 2017](https://qiita.com/advent-calendar/2017/dmm2)

昨日は@usagi-fさんの[GUI構築でオブジェクト指向を考えてみる](https://qiita.com/usagi-f/items/72c1d06e026192a15e33)でした。
明日は@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](http://elixir.free-electrons.com/linux/v4.15-rc1/source/include/asm-generic/bug.h#L147)
[WARN_ON_ONCE](http://elixir.free-electrons.com/linux/v4.15-rc1/source/include/asm-generic/bug.h#L135)
[WARN_TAINT_ONCE](http://elixir.free-electrons.com/linux/v4.15-rc1/source/include/asm-generic/bug.h#L158)

いずれもONCEと付いていることから分かるように、これらのマクロでは一度だけ実行されます。Linux 4.15からはこのカウンタをクリアできるようになりました。ソースコード上の特定の場所にあるWARN_*ONCEマクロのカウンタのリセットはできませんが、便利になったことをは確かですね〜

マクロの使い方はWARN_ON_ONCEなら条件一つ、WARN_ONCEの場合は条件と任意のメッセージを渡せます。

```c
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](http://elixir.free-electrons.com/linux/v4.15-rc1/source/Documentation/admin-guide/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()を実行します。

### テストコード

```c
#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](https://github.com/torvalds/linux/commit/b1fca27d384e8418aac84b39f6f5179aecc1b64f)
- [kernel debug: support resetting WARN_ONCE for all architectures](https://github.com/torvalds/linux/commit/aaf5dcfb223617ac2d16113e4b500199c65689de)
 
主要なのは ```kernel debug: support resetting WARN*_ONCE``` のほうです。もう一つのほうは前者の方法ではクリアできないアーキテクチャ向けのpatchです。この記事では個々のpatchではなく、4.15-rc1に入ったコードをベースに読んでいきますが、まずはWARN_*ONCEマクロの実装を見てみましょう。どのようにWARN_*ONCEマクロが実装されているかを理解したほうがクリアの処理は簡単に理解できます(・∀・)　WARN_ON_ONCEの実装を読んでみましょう。

## WARN_ON_ONCEの実装
実装はこのようになっています。

```c
#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言語のコードだとあまり見かけないのはこの部分でしょうか。

```c
__section(.data.once)
```

これ以外は素直な内容だと思います。まずこの行はbool型の```__warned```をstatic変数として宣言しています。sectionのところは後で解説します。

```c
        static bool __section(.data.once) __warned;
```

次の行が条件を評価している部分です。条件が真なら```__ret_warn_once```は1になります。

```c
        int __ret_warn_once = !!(condition);
```

ここで条件の評価結果が1で```__warned```がfalseの場合にWARN_ONマクロでワーニングメッセージを表示しています。```__warned```をtrueにするのも忘れずに。

```c
        if (unlikely(__ret_warn_once && !__warned)) {		\
		__warned = true;				\
		WARN_ON(1);					\
	}	
```

最後の行は特に意味ありません。

```c

        unlikely(__ret_warn_once);
```

処理としては特に変わったことはありませんね。では、後回しにした ``` __section(.data.once) ``` の説明をしたいと思います。

まずセクションとはですが、ほんとに大雑把に説明するとグローバル変数は.dataセクションに配置する等の決まりがあって、それの配置場所がセクションという感じです。
ほんとに適当な説明なので実際に見てみますと、
例えば、このようなコードの場合、.bssセクションにiが置かれ、.dataセクションにはjが置かれます。

```c
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](http://elixir.free-electrons.com/linux/v4.15-rc1/source/include/asm-generic/vmlinux.lds.h#L218)にて以下のようなマクロで作成しています。.dataセクションを更に細かく分けて使用しています。

```c
#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```の２つのシンボルが定義されています。

```c
    VMLINUX_SYMBOL(__start_once) = .;               \
    *(.data.once)                           \
    VMLINUX_SYMBOL(__end_once) = .;                 \
```

これらのシンボルが[include/asm-generic/sections.h](http://elixir.free-electrons.com/linux/v4.15-rc1/source/include/asm-generic/sections.h#L47)でこのようにextern宣言されていてc言語のコードからアクセスできるようになっています。

```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](
http://elixir.free-electrons.com/linux/v4.15-rc1/source/kernel/panic.c)にclear_warn_once_set()という関数が追加されていて、これがクリアする処理です。[generic_bug_clear_once()](http://elixir.free-electrons.com/linux/v4.15-rc1/source/kernel/panic.c#L612)は今回は無視して構いません。

```c
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マクロでワーニングメッセージを出力できるようになります。

# まとめ
カウンタのクリア処理の内容は簡単でしたね( ´ー｀)ﾌｩｰ．．．