【続】CentOS7.5 の perf probe / perf record のバグと思われる挙動を調べ中

hiboma.hatenadiary.jp

上記のエントリを書いたのだが、VM を作り直したところ再現がとれなくなったので改めて検証しなおした.

(別のバグを調査した VM を使いまわしたのだが、パッケージインストール後にカーネルパニックを起こした影響かでパッケージ/ファイルの一部が欠損しまったらしい)

環境 / Environment

[vagrant@localhost ~]$ uname -a
Linux localhost.localdomain 3.10.0-862.3.3.el7.x86_64 #1 SMP Fri Jun 15 04:15:27 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

[vagrant@localhost ~]$ rpm -q perf
perf-3.10.0-862.3.3.el7.x86_64

[vagrant@localhost ~]$ rpm -q glibc
glibc-2.17-222.el7.x86_64

再現方法 / Steps to reproduce

perf probe で malloc を追加する

[root@localhost ~]# perf probe -x /usr/lib64/libc.so.6 malloc
Added new event:
  probe_libc:malloc    (on malloc in /usr/lib64/libc-2.17.so)

You can now use it in all perf tools, such as:

        perf record -e probe_libc:malloc -aR sleep 1
[root@localhost ~]# perf record -e probe_libc:malloc -aR sleep 1
perf: Segmentation fault
Segmentation fault

perf が Segmentation fault する.

続きを読む

【続】CentOS7.5 の fsnotify がレースコンディションを起こすバグ : CentOSPlus kernel-plus での fix がリリースされた

hiboma.hatenadiary.jp

このエントリを書いたのちに kernel-3.10.0-862.3.3.el7.x86_64.rpm がリリースされていますが、 Intel® Core-based microprocessors の Lazy FP state restore の脆弱性 - CVE-2018-3665 を対象としたセキュリティフィックスを含むのみで、↑ のエントリで取り上げたバグは修正されていません

kernel-3.10.0-862.3.3.el7 の changelog

changelog を見ても下記の通り CVE-2018-3665 の fix のみです

%changelog
* Wed Jun 13 2018 Rado Vrbovsky <rvrbovsk@redhat.com> [3.10.0-862.3.3.el7]
- [x86] always enable eager FPU by default on non-AMD processors (Paolo Bonzini) [1589051 1589048] {CVE-2018-3665}

kernel-3.10.0-862.3.3.el7.x86_64 で再現を取る

前回のエントリ通り、再現コードを実行して確認をとりました 🔥

CentOS Linux 7 (Core)
Kernel 3.10.0-862.3.3.el7.x86_64 on an x86_64

localhost login: [  377.118566] BUG: unable to handle kernel paging request at 000000000004c200
[  377.129371] IP: [<ffffffffb77f75f4>] kmem_cache_alloc+0x74/0x1f0
[  377.137867] PGD 8000000044262067 PUD 55b66067 PMD 0 
[  377.146259] Oops: 0000 [#1] SMP 
[  377.148965] Modules linked in: vboxvideo(OE) ttm drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm vboxsf(OE) vboxguest(OE) nls_utf8 isofs loop sunrpc iosf_mbi crc32_pclmul crc32c_intel snd_intel8x0 ghash_clmulni_intel snd_ac97_codec ac97_bus aesni_intel snd_pcm lrw ppdev snd_timer gf128mul sg snd e1000 i2c_piix4 glue_helper ablk_helper soundcore cryptd i2c_core parport_pc parport video pcspkr ip_tables xfs libcrc32c sd_mod crc_t10dif crct10dif_generic ata_generic pata_acpi ata_piix crct10dif_pclmul libata crct10dif_common serio_raw dm_mirror dm_region_hash dm_log dm_mod
[  377.246153] CPU: 1 PID: 28685 Comm: inotify Tainted: G           OE  ------------   3.10.0-862.3.3.el7.x86_64 #1
[  377.282811] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  377.309794] task: ffff9092180caf70 ti: ffff909202318000 task.ti: ffff909202318000
[  377.588542] RIP: 0010:[<ffffffffb77f75f4>]  [<ffffffffb77f75f4>] kmem_cache_alloc+0x74/0x1f0
[  377.621774] RSP: 0018:ffff90920231be48  EFLAGS: 00010282
[  377.655148] RAX: 0000000000000000 RBX: ffff909204619a10 RCX: 0000000000006924
[  377.692181] RDX: 0000000000006923 RSI: 00000000000000d0 RDI: ffff90923907f800
[  377.698113] RBP: ffff90920231be78 R08: 000000000001cdd0 R09: ffffffffb786316d
[  377.709186] R10: ffff90923cc9bb40 R11: ffffd95580d93200 R12: 000000000004c200
[  377.719453] R13: 00000000000000d0 R14: ffff90923907f800 R15: ffff90923907f800
[  377.728466] FS:  00007f14d71c1740(0000) GS:ffff90923cc80000(0000) knlGS:0000000000000000
[  377.740987] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  377.754305] CR2: 000000000004c200 CR3: 00000000396a0000 CR4: 00000000000606e0
[  377.766051] Call Trace:
[  377.766776]  [<ffffffffb786316d>] ? fsnotify_add_mark_locked+0x12d/0x300
[  377.772651]  [<ffffffffb786316d>] fsnotify_add_mark_locked+0x12d/0x300
[  377.786170]  [<ffffffffb7865137>] SyS_inotify_add_watch+0x2f7/0x370
[  377.791428]  [<ffffffffb7d2082f>] system_call_fastpath+0x1c/0x21
[  377.802655]  [<ffffffffb7d2077b>] ? system_call_after_swapgs+0xc8/0x160
[  377.809983] Code: 9b 81 48 49 8b 50 08 4d 8b 20 49 8b 40 10 4d 85 e4 0f 84 28 01 00 00 48 85 c0 0f 84 1f 01 00 00 49 63 46 20 48 8d 4a 01 4d 8b 06 <49> 8b 1c 04 4c 89 e0 65 49 0f c7 08 0f 94 c0 84 c0 74 ba 49 63 
[  378.035309] RIP  [<ffffffffb77f75f4>] kmem_cache_alloc+0x74/0x1f0
[  378.086423]  RSP <ffff90920231be48>
[  378.122637] CR2: 000000000004c200
[  378.144306] ---[ end trace 284b8f40714989c1 ]---
[  378.171508] Kernel panic - not syncing: Fatal exception
[  378.196196] Kernel Offset: 0x36600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)

CentOSPlus リポジトリの kernel-plus で修正されています

代わりに CentOS Plus の kernel-plus-3.10.0-862.3.3.el7.centos.plus.x86_64.rpm でパッチが当てられて fix されています

f:id:hiboma:20180616182152p:plain

0006828: Tracking for centosplus kernels for CentOS-7 - CentOS Bug Tracker

CentOSPlus ってこういうリリースのされ方をするんだな ... 今まで CentOS にお世話になりまくっているのに全然知らずにいました.

加えて、本エントリとはあまり関係ありませんが iotop が動かないバグ の修正も入っています

CentOS Plus リポジトリで kernel-plus をインストールする

$ sudo yum install --enablerepo=centosplus kernel-plus

インストール後、reboot してカーネルのバージョンを確認する

$ uname -a
Linux localhost.localdomain 3.10.0-862.3.3.el7.centos.plus.x86_64 #1 SMP Fri Jun 15 13:49:54 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

直ったの?

再現コードを 30分くらい回してみたけど何も起こらなかったので大丈夫 ... なはずです (レースコンデションのバグだとほんとに直ったのかどうか 言い切るの難しいですね). メンテナさんも確認してるから大丈夫だろう

感想

  • はやく無印カーネル ( yum install kernel で入る方 ) で修正はいらないかなぁ〜

CentOS7.5 の perf probe / perf record のバグと思われる挙動を調べ中

(2018/6/16 14:15 追記) VM を作り直したら systemd が segmentaion fault するもののカーネルパニックは再現しなくなったので、私の VM がおかしかった可能性があります . 中途半端な検証ですいません. 引き続き調べてい ます


Dynamically Obtain Shared Object Library Data with uprobes - Wind River Knowledge Library

ここを参照しながら perf probeperf record を試していたのだが、 CentOS7.5 - 3.10.0-862.3.2.el7.x86_64 でバグと思われる挙動に遭遇した. 調べている途中だが、記録を書き出す

続きを読む

CentOS7.5 カーネルの fsnotiy のバグと libev の inotify_add_watch(2) と inotify_rm_watch(2) を調べたけどよくわからん

hiboma.hatenadiary.jp

というエントリを書いたのちに、下記のような感想を頂いていて

確かにそうだなぁ〜〜 と思って td-agent -> libev のソースを追って見ました。

が、設計の意図は理解できず、特に収穫はなかった内容です 😯 せっかくなのでソースを突き止めたあたりのメモ等を残しておきます

環境

再現の環境は前回書いたエントリに倣う

hiboma.hatenadiary.jp

inotify_add_watch(2) と inotify_add_rm_watch(2) が呼びだされる場所を特定する

まずは問題となっているシステムコールがどういったパスで呼び出されるかを調べた. いろいろな方法があると思うが perf trace --call-graph dwarf で絞り込んだ.

続きを読む

都民の森〜風張峠〜奥多摩 🚲

暑いので海か山か迷ったが、山に向かい都民の森〜風張峠〜奥多摩を巡ってきた

走行距離 149 km 獲得標高 1400m

f:id:hiboma:20180611175429p:plain

以前に登った時も檜原〜都民の森は「アップダウンがしんどい!!!」という感想だったけど、やっぱり今回もしんどかった. 苦手

続きを読む

CentOS7.5 の fsnotify がレースコンディションを起こすバグを nginx + td-agent + in_tail プラグインで踏む

2018/7/18 追記 3.10.0-862.9.1.el7 で fix されました

hiboma.hatenadiary.jp

2018/7/4 追記 最新の情報はこちらにまとめています

hiboma.hatenadiary.jp

2018/6/16 追記 CentOS Plus の kernel-plus では修正が入っています. 詳しくはこちらをご覧ください

hiboma.hatenadiary.jp

エントリの概要

CentOS7.5 の fsnotify() がレースコンディションを起こすバグを、 nginx + td-agent (fluentd) + in_tail プラグインで踏んだ際の調査内容を記していきます.

イントロダクション

このエントリを書いた時点では、CentOS 7.5.1804 以降でリリースされているカーネルは 3つありますが、カーネルの fsnotify() がレースコンディションを起こすバグを抱えています

  • kernel-3.10.0-862.el7.x86_64
  • kernel-3.10.0-862.2.3.el7.x86_64
  • kernel-3.10.0-862.3.2.el7.x86_64

レースコンディションの修正パッチ

mainline では修正済みです。詳細と修正パッチは以下のコミットで確かめられます

github.com

v4.17-rc3 でパッチがマージされており、 stable にもバックポートされています

CentOS / RHEL は?

CentOS (というか RHEL) で問題は修正されていません.

下記のリンクを見るに、RHEL では問題を認識済みであるようです (サブスクリプションがないので詳細はわかりません)

Soft lockups occur in fsnotify() after updating to RHEL 7.5 - Red Hat Customer Portal

CentOSのバグトラッキングシステムでも把握されているようです

0014823: 3.10.0-862.2.3.el7.x86_64 kernel panic and crash under Xen PV with NMI watchdog: BUG: soft lockup - CPU#2 - CentOS Bug Tracker

2018/6/7 13:50 追記

0006828: Tracking for centosplus kernels for CentOS-7 - CentOS Bug Tracker

f:id:hiboma:20180607135306p:plain

次のリリースで修正が入らない場合に CentOS 側で修正パッチを含めたカーネルを出すようですね. (注意 : distro kernelRHEL を指すのか CentOS を指すのか? CentOS Plus として出すのかな? )

レースコンディションの詳細

コミットログに詳細が記してある のですが ... SRCU という仕組みが関連するあたりが難しくてワカリマセン

勉強中です


カーネル内部で何が起こるには目をつぶり、ユーザランドで「どういう条件が重なる」と「どんなことが起こってしまう」のかでレースコンディションの問題を見ていきましょう.

続きを読む

perf trace で コールグラフを出す

以前こんなエントリを書いたが、それの perf trace 版

hiboma.hatenadiary.jp

perf trace で --call-graph というオプションを指定する

環境

CentOS7.5 で試した

使い方

こんな感じでワラワラと コールグラフ を出しつつトレースできる

続きを読む