Linux起動時のカーネルパニック(at ring_buffer_set_clock())修正めも

機種依存ですが、fedoraで5.4系のカーネルで起動時にカーネルパニックするようになり、自分もこのバグに当たったので修正してパッチをlkmlに投稿しました。 このパッチはLinux5.5.に取り込まれました🎉

github.com

ついでなのでどんな感じでデバッグしたかの記録です。10日前くらいの話だし、デバッグ時の思考の時系列は多少違う気もしますがだいたいこんな感じということで。

環境

こんな感じです。

バグの内容

自分がこのバグに当たったときにはfedoraのbugzillaにすでにバグ登録されてました

bugzilla.redhat.com

5.4系のカーネルだと起動時にカーネルパニックする☠という内容です。実際こんな感じでした。

f:id:masami256:20200127191203j:plain
oops

ただ、自分が普段使ってるデスクトップPCでも同じカーネルを使ってますがこちらでは同様の現象は起きてませんでした。ということで機種依存っぽい感じがします。そして、bugzillaを見てると共通点が見えてきました。 それは次の二点です。

  • Ryzenが載ってるThinkPadを使っている
  • Secure Bootが有効

暫定対策

上に貼り付けたoopsはカーネルコマンドラインオプションにquietが付いているので表示されていないですが、quietを外すと↓のprintk()の部分が表示されました。

 /* sched_clock_stable() is determined in late_initcall */
    if (!trace_boot_clock && !sched_clock_stable()) {
        printk(KERN_WARNING
               "Unstable clock detected, switching default tracing clock to \"global\"\n"
               "If you want to keep using the local clock, then add:\n"
               "  \"trace_clock=local\"\n"
               "on the kernel command line\n");
        tracing_set_clock(&global_trace, "global");
    }

ってことで、これを試すと起動成功したのでbugzillaにtrace_clock=locakを付けたら大丈夫だったよとコメントしました。また、他の人はSecure bootを無効にすることで対応したりもしてました。

原因を探す

NULL pointer dereference の原因箇所

ring_buffer_set_clock()はこんな関数です。

void ring_buffer_set_clock(struct ring_buffer *buffer,
               u64 (*clock)(void))
{
    buffer->clock = clock;
}

どこでエラーになったか一目瞭然ですね。

この関数に至る流れはtracing_set_default_clock()から始まり、 tracing_set_clock() -> ring_buffer_set_clock()となります。

初期化されていない状態でring_buffer_set_clock()が呼ばれてる感じですね。

ちなみにここで変更しようとしているclockは/sys/kernel/debug/tracing/trace_clockとして見えます。

masami@moon:~$ sudo cat  /sys/kernel/debug/tracing/trace_clock
[local] global counter uptime perf mono mono_raw boot x86-tsc

Unstable clock detected?

5.3系では問題なかったので5.4系からのバグではあるのですが、まず以下の部分でUnstable clock detectedとなるのは5.3ではどうだったのか?というのを調べます。trace_boot_clockはtrace_clockオプションなので普段は設定してないので気にしません。

 if (!trace_boot_clock && !sched_clock_stable()) {

調べるといっても、5.3系カーネルの起動時にquietオプションを外すだけですが。そして結果はどうだったかと言うと5.3系でも5.4.7でも同じパスを通っていました。このPCはUnstable clock detectedと判断されるようですね。デスクトップPC(cpuはi7-9700K)のほうはこのパスは通ってませんでした。

upstraem / 他のディストリビューションの様子

とくに同じようなエラーが出てる感じはありませんでした。

ここまでのまとめ

以下の条件に当てはまる人がバグに当たっている感じです。

回避策はtrace_clock=localを設定するかSecure Bootを無効にする。

原因特定のためのデバッグ

Secure Boot環境で動くカーネルを作る方法を調べる

Secure Bootを無効にしちゃったら再現しないので自前でビルドしたカーネルへの署名方法を調べます。調べた結果は↓にまとめました。

kernhack.hatenablog.com

upstreamカーネルを試す

まずはバージョン同じものを使って、カーネルのコンフィグはfedoraの5.4.7のコンフィグを使います。ビルドしてこのカーネルから起動してみると無事に起動しました。ということで、次の手順に進みます。

fedora固有のパッチを調べる

調べると言うかパッチを一旦外せるだけ外してから足していくとかそんな感じですね。fedoraカーネルパッケージのソース一式はgitリポジトリにあるのでクローンしてきて、f31ブランチからブランチを切手作業していきます。この時点でf31ブランチは5.4.12カーネルになっていました。

src.fedoraproject.org

手順的にはspecファイルでパッチをコメントアウトして、fedpkgでsrpmを作ります。そして、必要最小限のパッケージだけ作りたかったので出来たsrpmをインストールしてrpmbuildでビルドするという方法を取りました。fedpkgで同じようなことができるんでしょうか? それはともかくrpmbuildはこんなオプションでやりました。

$ rpmbuild -bb --with baseonly --without debuginfo --target=$(uname -m) kernel.spec

arm64-Add-option-of-13-for-FORCE_MAX_ZONEORDER.patchのように外すと他に直さなきゃいけないところが出てくるパッチもあったりするのですが、まあこの辺は今回のバグに関係ないだろってことでこういうパッチは外さずに進めました。そして、efi-secureboot.patchを外せば問題ないというところまで判明しました。

efi-secureboot.patchの内容を調べる

efi-secureboot.patchLinux 5.4から入ったlockdownに関係するパッチです。

lockdownについてはこちらを参照してもらうとして。。

kernelnewbies.org

このパッチの内容は大きく分けると

最後のCONFIG_LOCK_DOWN_IN_EFI_SECURE_BOOTの値に応じて処理してる部分は以下のifdefのところです。

diff --git a/arch/x86/kernel/setup.c b/arch/x86/kernel/setup.c
index 77ea96b794bd..a119e1bc9623 100644
--- a/arch/x86/kernel/setup.c
+++ b/arch/x86/kernel/setup.c
@@ -73,6 +73,7 @@
 #include <linux/jiffies.h>
 #include <linux/mem_encrypt.h>
 #include <linux/sizes.h>
+#include <linux/security.h>
 
 #include <linux/usb/xhci-dbgp.h>
 #include <video/edid.h>
@@ -1027,6 +1028,13 @@ void __init setup_arch(char **cmdline_p)
    if (efi_enabled(EFI_BOOT))
        efi_init();
 
+   efi_set_secure_boot(boot_params.secure_boot);
+
+#ifdef CONFIG_LOCK_DOWN_IN_EFI_SECURE_BOOT
+   if (efi_enabled(EFI_SECURE_BOOT))
+       security_lock_kernel_down("EFI Secure Boot mode", LOCKDOWN_CONFIDENTIALITY_MAX);
+#endif
+
    dmi_setup();
 
    /*

上記のコードはカーネルuefiのsecure boot環境で起動されてたらlockdownしてます。

ここまでくるとCONFIG_LOCK_DOWN_IN_EFI_SECURE_BOOTが疑わしい感じしてきます。そこでこのオプションは選択せずにカーネルをビルドします。オプションはkernel-x86_64-fedora.configにてこのように行われています。

CONFIG_LOCK_DOWN_IN_EFI_SECURE_BOOT=y
# CONFIG_LOCK_DOWN_KERNEL_FORCE_CONFIDENTIALITY is not set
# CONFIG_LOCK_DOWN_KERNEL_FORCE_INTEGRITY is not set
CONFIG_LOCK_DOWN_KERNEL_FORCE_NONE=y

オプションの設定はkernel-x86_64-fedora.configでCONFIG_LOCK_DOWN_IN_EFI_SECURE_BOOTをコメントアウトしてsrpmを作ってからビルドしました。そしたら予想通り起動できたので、さらなるデバッグに入ります。

upstreamのソースを再確認

5.4.12のコードを見てたらこんなコードが入っていたんですね。これはregister_tracer()のコードです。

 if (security_locked_down(LOCKDOWN_TRACEFS)) {
        pr_warning("Can not register tracer %s due to lockdown\n",
               type->name);
        return -EPERM;
    }

他にも同じようなチェックがいくつかありました。それでlockdownされているとtracerの初期化しないんだなということかってわかり、初期化されていないのにtrace clockを変更しようとしたからヌルポになるということなんだなと理解しました。

upsteamで再現できるか確認

このときは5.4.7ではなくてfedoraカーネルパッケージのgitでは5.4.12だったのでstable treeの5.4.12を使いました。原因はほぼ掴めたというところなんですが、upstreamで再現するかどうか再度検証します。

まずlockdown機能に関するコンフィグを調べます。lockdownではCONFIG_SECURITY_LOCKDOWN_LSMが最重要の設定でY/Nの2択です。これでYを選べばlockdownの機能が使えます。Yを選択すると更にどのレベルでlockするかという選択があります。選択肢は3個でデフォルトはNoneです。fedoraカーネルもCONFIG_LOCK_DOWN_KERNEL_FORCE_NONEを選択していました。

  • CONFIG_LOCK_DOWN_KERNEL_FORCE_NONE
  • CONFIG_LOCK_DOWN_KERNEL_FORCE_INTEGRITY
  • CONFIG_LOCK_DOWN_KERNEL_FORCE_CONFIDENTIALITY

fedoraの場合はCONFIG_LOCK_DOWN_IN_EFI_SECURE_BOOTが4個目の選択肢ってところでしょうか。

オプションの内容ですがKconfigによるとCONFIG_LOCK_DOWN_KERNEL_FORCE_NONEは何もしません。CONFIG_LOCK_DOWN_KERNEL_FORCE_INTEGRITYは「Features that allow the kernel to be modified at runtime are disabled.」とあり、CONFIG_LOCK_DOWN_KERNEL_FORCE_CONFIDENTIALITY「Features that allow the kernel to be modified at runtime or that permit userland code to read confidential material held inside the kernel are disabled」で一番制限が厳しくなっています。

最初にfedoraのコンフィグでmainlineカーネルをビルドしたときはCONFIG_LOCK_DOWN_KERNEL_FORCE_NONEが選択されてたので残りの2パターンを試したところCONFIG_LOCK_DOWN_KERNEL_FORCE_CONFIDENTIALITYを設定したときに再現しましたキタ━━━━(゚∀゚)━━━━!!

修正する

lockdownが有効になっているときはtrace_clockを変更できないようにするのが良いだろうと思い、このようなパッチを書きました。

@@ -9420,6 +9420,11 @@ __init static int tracing_set_default_clock(void)
 {
        /* sched_clock_stable() is determined in late_initcall */
        if (!trace_boot_clock && !sched_clock_stable()) {
+               if (security_locked_down(LOCKDOWN_TRACEFS)) {
+                       pr_warn("Can not set tracing clock due to lockdown\n");
+                       return -EPERM;
+               }
+
                printk(KERN_WARNING
                       "Unstable clock detected, switching default tracing clock to \"global\"\n"
                       "If you want to keep using the local clock, then add:\n"

patchを送る

upstreamのカーネルでも再現できたのでupstreamにパッチを送ります。lkmlをみてたらtracing系はlkmlにccで良さげだったのでccにはlkml、toはscripts/get_maintainer.plで出てきたメンテナの人にしてgit format-patchでパッチを作りgit send-emailで送りました。

パッチを送ってしばらくしたらメンテナの人からmainlineへのpull rquestに自分のパッチが入っていたのでacceptされということがわかり、良かったって感じでしたね。5.5-rc8が出るのかと思ってたけどrc8は出ずに5.5が2020/01/27にでて、これに修正が含まれました。

lkml.org

mainlineに修正が取り込まれたのでそのうち5.4のstable treeにも修正が取り込まれるんじゃないかと思います。

まとめ

今回のバグは機種依存・カーネルの設定依存な面もありましたが、バグの原因はわかってしまえば簡単だったのと修正も単純な方法で済ますことができて良かったです😊 あとfedora向けの単純なsecure boot用の署名方法がわかったのは良かったかも。

追記

5.5系は5.5から、5.4系は5.4.16からパッチが入った。

5.5リリースメール

lwn.net

5.4.16リリースメール

https://lwn.net/Articles/811027/