カーネルパッチを書いてみようとした話
KVM上で稼働する Linux で clocksourceに tsc を認識できない問題があり、これを修正しようと試行錯誤したときの話。
これは、ディストリビューションにカスタムパッチを当ててパッチを書いたつもりになった人が、本家のパッチを発見して勉強になった？話です。
簡単に自己紹介
エンジニアみならいです。 趣味で低レイヤーのプログラミングをしています。好きな言語は Rust です。 GBA でベアメタルプログラミングしたり、Linux向けにブートローダー自作したりしてます。
経緯
これは半年以上前の話ですが、KVM上で稼働する Linux の clocksourceを調べていたら、tscが認識されないことがあるのに気がつきました。
tscは、x86系のハイパーバイザで稼働するLinuxのゲストにとっては、最も早くて正確な？タイマデバイスであり、場合によってはこれが認識されないと困ってしまうかもしれません[1]。 特にやることもないし、楽しそうだったので、すぐに終わったらいいなとバグ探しを始めました。
[1]: clocksourceがなんのことかわからない方はこちらをご参照ください。
具体的な症状
詳細：
clocksource に tscが登録されていない。
$ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
kvm-clock acpi_pm
実例と類推
当時使用していたOS は、CentOS7 のカーネル kernel-3.10.0-957.el7 です。 まず、どのような問題がどこの部分にあるのか、Xenの場合と比較し、その症状から類推してみます。
実例：CentOS7 on KVM
以下はdmesgの出力まで含めた確認の結果です。
$ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
kvm-clock acpi_pm
[ 0.000000] tsc: Detected 3000.000 MHz processor
[ 1.834422] TSC deadline timer enabled
[ 2.600920] Switched to clocksource kvm-clock
CentOS 7のカーネルは Ubuntu などに比べて何も出力しなさすぎる気がしますが、、、 ただ上記のメッセージでも、デバイスとしてのTSC自体は認識されていることがわかって、結構なヒントになりそうな気がしました。
あとは正常な場合と比較しておくのも大事じゃないかということで確認してみました。 比較対象として適切かどうかはわかりませんが、幸いなことに今回は Xen で稼働する Linux ゲストでは問題が発生しないことがわかっていたので、そちらと比較しました。
Xenとの比較：CentOS7 on Xen
$ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
xen tsc hpet acpi_pm
$ dmesg | grep -iE '(clocksource|tsc)'
[ 0.000000] tsc: Fast TSC calibration using PIT
[ 0.000000] tsc: Detected 2394.486 MHz processor
[ 0.031000] tsc: Detected 2394.476 MHz TSC
[ 0.607022] Switched to clocksource xen
[ 2.244080] tsc: Refined TSC clocksource calibration: 2394.455 MHz
類推
TSC の周波数を検知するところまでにわずかに差はあるものの、違いは Refined TSC clocksource calibrationの有無にあることがわかります。
もちろんこの段階では、あくまで大雑把な推測の域を出ず、思い込みは厳禁です。
でも、ど素人の意見ですが、とにかく問題のある方(KVM で稼働するゲストの方)では、 本当に何かエラーが出てるわけでもなくて、何も出力されていないというところが特に異常であるということが想像できます。
- ここから、少なくとも、
clocksource登録のロジック自体にも何か問題がありそうなことが予想できます。 - 普通ダメな
clocksourceがあるなら、それがダメなことを示すメッセージが出力されるはずなのです。
普段 Linux で遊んでいる経験上？こういう場合はある程度あたりをつけやすいので、(個人的には)デバッガを使うよりもソースコードを見たほうが早い気がしています。 あと、あまり褒められた方法ではないかもしれませんが、僕はprintkデバッグと組み合わせるのが大好きです。
原始的なデバッグ
printkであたりをつけて、ソースコードをじっと見てデバッグする。
僕にはカーネル開発者の知り合いがいたことはないし本や雑誌やネットで得た知識しかないですが、printkデバッグもなかなかいい気がします。
いつ頃の話なのか不明ですが、netfilter開発者のラスティ・ラッセルさんはprintkとソースリストのにらめっこで問題を解決しているという記事を、古の雑誌で読んだことがあります[2]。
[2]: 確かオープンソースマガジン。大学でCSを学んだこともなく、近くに Linux のことを教えてくれる存在がいないので、基本的に僕の知っている知識のほとんどが中古で購入した古の雑誌と書籍から吸収したものです。
実際、関数ポインタでぴょんぴょん飛んだり、何か複雑な処理のロジックで調査しなければいけないようなシチュエーションでない限りでは、だいたいソースコードを眺めてれば問題の箇所を見つけられる気がします。 また、そうではない場合はデバッガを使っても厳しい可能性があるような気がしています。
今回はprintkデバッグで解決できる典型だと思います。
ソースの準備
以下のコマンドでソースなどをインストールして準備しておきます。
$ sudo yumdownloader --source kernel-3.10.0-957.el7
$ sudo yum groupinstall "Development Tools" -y
$ sudo yum install rpmdevtools -y
$ rpmdev-setuptree
$ rpm -Uvh kernel-3.10.0-957.el7.src.rpm
$ sudo yum-builddep -y --enablerepo=* rpmbuild/SPECS/kernel.spec
$ rpmbuild -bp ~/rpmbuild/SPECS/kernel.spec
$ cp -r ~/rpmbuild/BUILD/kernel-3.10.0-957.el7 ~/rpmbuild/BUILD/kernel-3.10.0-957.el7.orig
$ cp -al ~/rpmbuild/BUILD/kernel-3.10.0-957.el7.orig ~/rpmbuild/BUILD/kernel-3.10.0-957.el7.new
cp -al なのでvimで編集する場合には書き込み時にハードリンクを切る設定にすること。 例えば下記の .vimrc
set nobackup
set writebackup
set backupcopy=no
マクロを組む
いちいちprintkの引数を考えるのは面倒なので、当たり前ですが、単純なマクロを組んでおきます。
例えば以下のもの:
#define __dprintk(n) \
printk("No.%s, func: %s, line: %d, file: %s\n", \
#n, __FUNCTION__, __LINE__, __FILE__);
何個目に挿入した printk なのかと、関数名、行番号、ファイル名を出力します。
バグのありそうな場所はどこですか?
それはもちろんclocksourceの登録がうまくいっていないので、clocksource tsc の登録を行う場所です。
printkをどのように打ったのかと共に、怪しそうな箇所を見ていきます。
入り口
基本的に TSC の処理に関するコードは /arch/x86/kernel/tsc.c に定義されていて、 clocksource は clocksource_registar_hogehoge 関数で登録するのでその呼び出し箇所を確認します。
適当にgrepすると下記であるとわかります。
static int __init init_tsc_clocksource(void)
{
if (!cpu_has_tsc || tsc_disabled > 0 || !tsc_khz)
return 0;
if (tsc_clocksource_reliable)
clocksource_tsc.flags &= ~CLOCK_SOURCE_MUST_VERIFY;
/* lower the rating if we already know its unstable: */
if (check_tsc_unstable()) {
clocksource_tsc.rating = 0;
clocksource_tsc.flags &= ~CLOCK_SOURCE_IS_CONTINUOUS;
}
if (boot_cpu_has(X86_FEATURE_NONSTOP_TSC_S3))
clocksource_tsc.flags |= CLOCK_SOURCE_SUSPEND_NONSTOP;
/*
* Trust the results of the earlier calibration on systems
* exporting a reliable TSC.
*/
if (boot_cpu_has(X86_FEATURE_TSC_RELIABLE)) {
clocksource_register_khz(&clocksource_tsc, tsc_khz);
return 0;
}
schedule_delayed_work(&tsc_irqwork, 0);
return 0;
}
/*
* We use device_initcall here, to ensure we run after the hpet
* is fully initialized, which may occur at fs_initcall time.
*/
device_initcall(init_tsc_clocksource);
clocksource_register_khzがあるし。device_initcallもある。
これで間違いないと思う訳です。
TSCの周波数が信頼できるよとわかっていれば、X86_FEATURE_TSC_RELIABLE を立てて、clocksource_tsc をさっさと登録しちゃうことがわかります。
TSC の周波数は起動時に都度計算するもので、普通は、そんなことはわからないので、このifブロックの中に入る訳ないよなぁと想像します。
ただ、これは本来おかしい気がします。pvclockの仕組み詳しい方なら、共有情報ページより周波数がハイパーバイザから割り当てらているを知っているので、X86_FEATURE_TSC_RELIABLEを立てちゃえば万事解決じゃない？と気がつけます。
発生の仕方から考えてこれは今回の問題の本質ではなさそうなので、一旦後回しにします。
すると関数の最後まで到達して、下記の処理が問題になっているのではと推測できます。
schedule_delayed_work(&tsc_irqwork, 0);
schedule_delayed_workは頻繁に使用する関数でご存知な方も多いと思います[3]。
普通にドキュメントに載っていますが、ドキュメントを見なくても、予想できます。なんかの処理へのポインタと遅延期間を渡して、非同期処理しているなとわかる訳です。
[3]: schedule_delayed_work
目印の打ち方
なお、init_tsc_clocksource関数内部ではエラーを出力せずに早期リターンをしてそうな箇所があるので、念のため次の処理へ進んでいるか否かを確認するために、先ほど定義した__dprintkを打っておきます。
どこまで処理が進んでいるのか把握しているわけではないので、後々カーネルメッセージから追いかけやすいようにこのようにしました。
static int __init init_tsc_clocksource(void)
{
if (!cpu_has_tsc || tsc_disabled > 0 || !tsc_khz)
return 0;
__dprintk(1);
if (tsc_clocksource_reliable)
clocksource_tsc.flags &= ~CLOCK_SOURCE_MUST_VERIFY;
/* lower the rating if we already know its unstable: */
if (check_tsc_unstable()) {
clocksource_tsc.rating = 0;
clocksource_tsc.flags &= ~CLOCK_SOURCE_IS_CONTINUOUS;
}
if (boot_cpu_has(X86_FEATURE_NONSTOP_TSC_S3))
clocksource_tsc.flags |= CLOCK_SOURCE_SUSPEND_NONSTOP;
/*
* Trust the results of the earlier calibration on systems
* exporting a reliable TSC.
*/
if (boot_cpu_has(X86_FEATURE_TSC_RELIABLE)) {
clocksource_register_khz(&clocksource_tsc, tsc_khz);
return 0;
}
__dprintk(2);
schedule_delayed_work(&tsc_irqwork, 0);
__dprintk(3);
return 0;
}
以降も怪しそうな箇所をprintkを打ち込みながら見ていきます。見栄えは悪いです（苦笑い)。
また、printkを打ちすぎるのもよろしくないので考えものです。。。
怪しそうな箇所
処理の続きはtsc_irqworkでした。
ソースリストの中からその正体を探すと下記だとわかります。
static DECLARE_DELAYED_WORK(tsc_irqwork, tsc_refine_calibration_work);
static void tsc_refine_calibration_work(struct work_struct *work)
{
static u64 tsc_start = -1, ref_start;
static int hpet;
u64 tsc_stop, ref_stop, delta;
unsigned long freq;
/* Don't bother refining TSC on unstable systems */
if (check_tsc_unstable()) // もしここでTSCが不正だと判定されていたら、
goto out; // outまで行った際に、エラーメッセージが出るはずなので
// ここは問題ではなさそうだが、念のため__dprintkを打っておく
__dprintk(4);
/*
* Since the work is started early in boot, we may be
* delayed the first time we expire. So set the workqueue
* again once we know timers are working.
*/
// timerが正常に稼働していることが確認できるまで、
// schedule_delayed_workで同じ処理を再帰的に呼び出そうとしているみたい。
// 怪しそうなので内部に __dprintk を打っておく
if (tsc_start == -1) {
__dprintk(5);
/*
* Only set hpet once, to avoid mixing hardware
* if the hpet becomes enabled later.
*/
hpet = is_hpet_enabled();
schedule_delayed_work(&tsc_irqwork, HZ); // ここが怪しく見える。
tsc_start = tsc_read_refs(&ref_start, hpet);
return;
}
__dprintk(6);
// ここでも tsc_read_refs が出ていてこの関数が大事そうとわかる
tsc_stop = tsc_read_refs(&ref_stop, hpet);
// ref_startとref_stopには acpi_pmかhpetの値が入りそうとわかる。
// ただこの場合も out まで行ったら何かメッセージが出そうなので関係なさそう。
// 念のため printk
// ACPI PM 自体は Nitro にもある。
/* hpet or pmtimer available ? */
if (ref_start == ref_stop)
goto out;
__dprintk(7);
// 以下をみると他もoutまで行けば何かしらのメッセージが出そうだと予測できる。
// gotoの後ろに dprintk を挟みつつ先に進む
/* Check, whether the sampling was disturbed by an SMI */
goto out;
__dprintk(8);
delta = tsc_stop - tsc_start;
delta *= 1000000LL;
if (hpet)
freq = calc_hpet_ref(delta, ref_start, ref_stop);
else
freq = calc_pmtimer_ref(delta, ref_start, ref_stop);
/* Make sure we're within 1% */
if (abs(tsc_khz - freq) > tsc_khz/100)
goto out;
__dprintk(9);
tsc_khz = freq;
// ここまで到達できていないことは明らか
pr_info("Refined TSC clocksource calibration: %lu.%03lu MHz\n",
(unsigned long)tsc_khz / 1000,
(unsigned long)tsc_khz % 1000);
out:
if (boot_cpu_has(X86_FEATURE_ART))
art_related_clocksource = &clocksource_tsc;
__dprintk(10);
clocksource_register_khz(&clocksource_tsc, tsc_khz);
}
上記からも問題のありそうな位置がある程度予測できますが、printkがどうなるか確認してみましょう。
上記を確認用のパッチと仕立ててビルドしてみる
$ cd ~/rpmbuild/BUILD
$ diff -uNrp kernel-3.10.0-957.el7.orig kernel-3.10.0-957.el7.new > ../SOURCES/linux-3.10.0-957.el7.patch
$ cd ../SOURCES
$ (rm linux-3.10.0-957.el7.patch && sed 's/kernel-[^ ][^ ]*[gw]\/lin/lin/g' > linux-3.10.0-957.el7.patch) < linux-3.10.0-957.el7.patch
$ cd ../BUILD
$ cd ~/rpmbuild/BUILD/kernel-3.10.0-957.el7/linux-3.10.0-957.el7.x86_64/
$ cp /boot/config-3.10.0-957.el7.x86_64 .config
$ make oldconfig
$ cp .config ~/rpmbuild/SOURCES/config-uname -m-generic
$ cd ~/rpmbuild/SPECS
$ vim kernel.spec
$ cat kernel.spec | grep -E '(tscheck|ApplyOptionalPatch.*[3].*|Patch1000)'
%define buildid .tscheck
Patch1000: linux-3.10.0-957.el7.patch
ApplyOptionalPatch linux-3.10.0-957.el7.patch
$ rpmbuild -bb --with baseonly --without debuginfo --without debug --without doc --without perf --without tools --without kdump --without bootwrapper --target=uname -m kernel.spec
$ sudo yum localinstall -y ~/rpmbuild/RPMS/x86_64/kernel-*.rpm
printk の威力
下記のようになりました。 問題のありそうな箇所は一目瞭然でわかります。
$ dmesg | grep -iE '(clocksource|tsc)'
[ 0.000000] Linux version 3.10.0-957.el7.tscheck.x86_64 ...
...
[ 0.000000] tsc: Detected 3000.000 MHz processor
[ 1.804286] TSC deadline timer enabled
[ 2.557401] Switched to clocksource kvm-clock
[ 3.035763] No.1, func: init_tsc_clocksource, line: 1309, file: arch/x86/kernel/tsc.c
[ 3.044996] No.2, func: init_tsc_clocksource, line: 1330, file: arch/x86/kernel/tsc.c
[ 3.054436] No.3, func: init_tsc_clocksource, line: 1332, file: arch/x86/kernel/tsc.c
[ 3.063727] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 3.073240] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
[ 4.083424] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 4.092902] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
[ 5.085423] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 5.085424] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
...
[ 76.453766] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
[ 77.464261] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 77.473952] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
[ 78.484266] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 78.494070] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
...
[ 627.100177] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
[ 628.110663] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 628.120099] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
No.4とNo.5を延々とループしていることがわかります。 どうやら１秒おきの繰り返し処理で延々と続いていることがわかります。
ということで、予想通りに下記に問題がありそうであると断定できます。
if (tsc_start == -1) {
__dprintk(5);
/*
* Only set hpet once, to avoid mixing hardware
* if the hpet becomes enabled later.
*/
hpet = is_hpet_enabled();
schedule_delayed_work(&tsc_irqwork, HZ); // ここが怪しく見える。
tsc_start = tsc_read_refs(&ref_start, hpet);
return;
}
処理内容からは、上記のブロックのtsc_startが常に -1となり、tsc_irqworkの再帰呼び出しが延々トループしてしまい。
結果、処理が進まずエラーも何も出力していない状況だったことがわかります。
この手の問題はむしろデバッガを使ってもわからない可能性の方が高いので今回printkを使ったのもそこまで悪くなさそうです。
では、tsc_startが-1となるのはどんな時でしょうか？
それは、tsc_read_refsを読むとわかります。
問題の分析
tsc_read_refsは下記の定義
#define MAX_RETRIES 5
#define SMI_TRESHOLD 50000
/*
* Read TSC and the reference counters. Take care of SMI disturbance
*/
static u64 tsc_read_refs(u64 *p, int hpet)
{
u64 t1, t2;
int i;
for (i = 0; i < MAX_RETRIES; i++) {
t1 = get_cycles();
if (hpet)
*p = hpet_readl(HPET_COUNTER) & 0xFFFFFFFF;
else
*p = acpi_pm_read_early();
t2 = get_cycles();
if ((t2 - t1) < SMI_TRESHOLD)
return t2;
}
return ULLONG_MAX;
}
なんと、どうやら-1だと思っていたのはULONG_MAXが返っていたらしいです。
具体的な処理は、以下のようになっているようです。
- まず
t1 = get_cycles();で TSC のカウント値を読み取り - 次に
hpetかacpi_pmのカウント値をIOアクセスして読み取る。 - その後、すぐ
t2 = get_cycles();でまた TSC のカウント値を読み取り - IOアクセスの間に経過したカウント回数が
SMI_TRESHOLDより小さければt2を返す。 - そうでなければ
ULLONG_MAXを返す。
つまりまとめると、このコードは下記の点で問題になっています。
原因の発見
TSCのカウントアップ速度が相対的に速すぎる（またはACPI_PMかHPETタイマーへの入出力が相対的に遅い）場合は、
t1 = get_cycles() とt2 = get_cycles()の差が大きすぎ、t2 - t1は常にSMI_TRESHOLDより大きくなる。
その結果、tsc_startは常に-1になり、ブートプロセスが終了してもschedule_delayed_wor(＆tsc_irqwork、HZ)で再試行を続ける。
最終的にに、TSCクロックソースの初期化が延々と遅れ、クロックソースtscが際限なく存在しない。
そして、この再試行プロセスはメッセージを表示しないために何がおきているのかわかりにくい。
パッチを書いてみる
デバッグのためにprintkを挿入するだけのパッチを書きましたが、実際に問題を修正するパッチも、もうかけます。
正しいか正しくないかは別にして、、、
ド素人の考えですが、この問題は２つの修正方法が考えられます。
- TSC の速さが早くなるのも、機器によってはIOのレイテンシが上がるのも十分考えられるので、
SMI_TRESHOLDが固定値なのは少しおかしい。 何かいい方法がありそうな気がします。 - そもそも最初に触れましたが、
pvclockではTSCの周波数はあらかじめわかっています。 それを利用すれば煩わしい事とはおさらばなはずです。
上記の 1. と 2. の解決策で何かできないか具体的に考えていきます。
解決策1: SMI_TRESHOLDが固定値なのは少しおかしい。
SMI_TRESHOLDが固定値なのは少しおかしい気がします。
Linuxカーネルの深淵は僕にはわかりかねますが、素人目にみるとここは随分アバウトな処理で、システムに合わせてある程度スケールできるようになっておくべきだと思いました。
おそらく TSC の周波数に比例するような値にすべきだと思いますが。。。
でも正直どれだけとかは僕にはわからない。
(たった１日の祝日であり脳死状態で出した答え) 「もっと大きい固定値にしよう！ 」 （大問題、ただし何が問題かはわからない）
50000 -> 5000000
下記のパッチを書いて見たよ。vol.1
diff -uNrp linux-3.10.0-957.el7.x86_64/arch/x86/kernel/tsc.c linux-3.10.0-957.el7.x86_64/arch/x86/kernel/tsc.c
--- linux-3.10.0-957.el7.x86_64/arch/x86/kernel/tsc.c 2019-07-28 18:54:36.422551294 +0000
+++ linux-3.10.0-957.el7.x86_64/arch/x86/kernel/tsc.c 2019-07-28 18:55:24.100351452 +0000
@@ -391,7 +391,7 @@ static int __init tsc_setup(char *str)
__setup("tsc=", tsc_setup);
#define MAX_RETRIES 5
-#define SMI_TRESHOLD 50000
+#define SMI_TRESHOLD 5000000
/*
* Read TSC and the reference counters. Take care of SMI disturbance
直ったよ。vol.1
$ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
kvm-clock tsc acpi_pm
$ dmesg | grep -iE '(clocksource|tsc)'
[ 0.000000] tsc: Detected 3000.000 MHz processor
[ 1.835560] TSC deadline timer enabled
[ 2.605330] Switched to clocksource kvm-clock
[ 3.086972] No.1, func: init_tsc_clocksource, line: 1309, file: arch/x86/kernel/tsc.c
[ 3.096286] No.2, func: init_tsc_clocksource, line: 1330, file: arch/x86/kernel/tsc.c
[ 3.105617] No.3, func: init_tsc_clocksource, line: 1332, file: arch/x86/kernel/tsc.c
[ 3.114963] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 3.124533] No.5, func: tsc_refine_calibration_work, line: 1256, file: arch/x86/kernel/tsc.c
[ 4.209357] No.4, func: tsc_refine_calibration_work, line: 1248, file: arch/x86/kernel/tsc.c
[ 4.219336] No.6, func: tsc_refine_calibration_work, line: 1266, file: arch/x86/kernel/tsc.c
[ 4.229233] No.7, func: tsc_refine_calibration_work, line: 1273, file: arch/x86/kernel/tsc.c
[ 4.239024] No.8, func: tsc_refine_calibration_work, line: 1278, file: arch/x86/kernel/tsc.c
[ 4.248844] No.9, func: tsc_refine_calibration_work, line: 1290, file: arch/x86/kernel/tsc.c
[ 4.258687] tsc: Refined TSC clocksource calibration: 3000.004 MHz
[ 4.264562] No.10, func: tsc_refine_calibration_work, line: 1300, file: arch/x86/kernel/tsc.c
解決策2: 仮想化ゲストなのに、pvclockのTSC周波数を用いないのは少しおかしい
最初の方にも言いましたが、pvclockの仕組み詳しい方なら、共有情報ページより周波数が基盤から割り当てられていることを知っているので、TSCを認識した(kvm-clockを認識した)時点でTSCの周波数は基盤から計算済みのものが与えられているとわかっている。
なので、kvm-clockを認識した時点で、X86_FEATURE_TSC_RELIABLEを立てちゃえば万事解決じゃない？と気がつけます。
下記の部分ですね。
/*
* Trust the results of the earlier calibration on systems
* exporting a reliable TSC.
*/
if (boot_cpu_has(X86_FEATURE_TSC_RELIABLE)) {
clocksource_register_khz(&clocksource_tsc, tsc_khz);
return 0;
}
kvm-clock を認識した際にTSCの周波数を検知する処理があるはずなので、 上記の部分で if の中に入れるように、kvm-clockのコードを修正して見ます。
対象のkvm-clockのソースは下記です。
KVMで稼働したゲストの初期化処理の中でkvm_get_tsc_khzが呼ばれることがわかります。
ソースコードのコメントからもここで TSC の周波数を早めに求めてしまうことがなんとなくわかります。
static unsigned long kvm_get_tsc_khz(void)
{
struct pvclock_vcpu_time_info *src;
int cpu;
unsigned long tsc_khz;
...
src = &hv_clock[cpu].pvti;
tsc_khz = pvclock_tsc_khz(src);
preempt_enable();
return tsc_khz;
}
...
void __init kvmclock_init(void)
{
...
x86_platform.calibrate_tsc = kvm_get_tsc_khz;
x86_platform.calibrate_cpu = kvm_get_tsc_khz;
...
なお、cpuのフラグは arch/x86/kernel/cpu/mkcapflags.pl と arch/x86/include/asm/cpufeature.h のマクロで管理しているのは Linux User ならご存知かと思います。
フラグを強制的に立てるものはないか探してみるとarch/x86/include/asm/cpufeature.h下記がありました。
#define set_cpu_cap(c, bit) set_bit(bit, (unsigned long *)((c)->x86_capability))
extern void setup_clear_cpu_cap(unsigned int bit);
extern void clear_cpu_cap(struct cpuinfo_x86 *c, unsigned int bit);
#define setup_force_cpu_cap(bit) do { \
set_cpu_cap(&boot_cpu_data, bit); \
set_bit(bit, (unsigned long *)cpu_caps_set); \
} while (0)
これを使います。
下記のパッチを書いて見たよ。vol.2
diff -uNrp linux-3.10.0-957.el7.x86_64/arch/x86/kernel/kvmclock.c linux-3.10.0-957.el7.x86_64/arch/x86/kernel/kvmclock.c
--- linux-3.10.0-957.el7.x86_64/arch/x86/kernel/kvmclock.c 2019-07-29 02:35:27.318987845 +0000
+++ linux-3.10.0-957.el7.x86_64/arch/x86/kernel/kvmclock.c 2019-07-29 03:04:11.015862936 +0000
@@ -338,6 +338,7 @@ void __init kvmclock_init(void)
x86_platform.calibrate_tsc = kvm_get_tsc_khz;
x86_platform.calibrate_cpu = kvm_get_tsc_khz;
+ setup_force_cpu_cap(X86_FEATURE_TSC_RELIABLE);
x86_platform.get_wallclock = kvm_get_wallclock;
x86_platform.set_wallclock = kvm_set_wallclock;
#ifdef CONFIG_X86_LOCAL_APIC
直ったよ。vol.2
$ cat /sys/devices/system/clocksource/clocksource0/available_clocksource
kvm-clock tsc acpi_pm
$ dmesg | grep -iE '(clocksource|tsc)'
[ 0.000000] Linux version 3.10.0-957.21.3.el7.tsc_fixed.x86_64...
...
[ 0.000000] tsc: Detected 3000.000 MHz processor
[ 1.832686] TSC deadline timer enabled
[ 1.929653] Skipped synchronization checks as TSC is reliable.
[ 2.598602] Switched to clocksource kvm-clock
[ 3.078334] No.1, func: init_tsc_clocksource, line: 1309, file: arch/x86/kernel/tsc.c
パッチが書かれていないはずがない！
ディストリビューションで使われてるカーネルってちょっと古めです。なので、正直に言ってディストリビューションで見つかるバグっていうのは、たいていの場合、upstreamではもうすでに修正済みなことがほとんどだと思います。 ということで探してみたら、あっさりと見つかってしまいました。
解決策1 よりも優れたパッチ
予想通り、TSCの周波数に比例してスケールするような修正が施されていました。 ULONG_MAX の比較方法も修正されています。
何かの値と比例させていときにはシフトしておけばいいと理解しました（違う。 細かい部分はよくわからないけどCSの真髄みたいなパッチだなと思いました。 ほーこういう感じかととても勉強になったので次回に生かしたいです。
x86/tsc: Make calibration refinement more robust
特徴的なところだけ抜粋
diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index e9f777b..3fae238 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -297,15 +297,16 @@ static int __init tsc_setup(char *str)
__setup("tsc=", tsc_setup);
-#define MAX_RETRIES 5
-#define SMI_TRESHOLD 50000
+#define MAX_RETRIES 5
+#define TSC_DEFAULT_THRESHOLD 0x20000
/*
- * Read TSC and the reference counters. Take care of SMI disturbance
+ * Read TSC and the reference counters. Take care of any disturbances
*/
static u64 tsc_read_refs(u64 *p, int hpet)
{
u64 t1, t2;
+ u64 thresh = tsc_khz ? tsc_khz >> 5 : TSC_DEFAULT_THRESHOLD;
int i;
for (i = 0; i < MAX_RETRIES; i++) {
@@ -315,7 +316,7 @@ static u64 tsc_read_refs(u64 *p, int hpet)
else
*p = acpi_pm_read_early();
t2 = get_cycles();
- if ((t2 - t1) < SMI_TRESHOLD)
+ if ((t2 - t1) < thresh)
return t2;
}
return ULLONG_MAX;
解決策2 と類似のパッチ
RHELのコードは少し古いので、セットする CPU フラグに少し差がありますが、
正直、 setup_force_cpu_capをこのブロックに挿入した意味は僕には良くわかりませんでした。
kvmclock: fix TSC calibration for nested guests
diff --git a/arch/x86/kernel/kvmclock.c b/arch/x86/kernel/kvmclock.c
index d79a18b..4c53d12 100644
--- a/arch/x86/kernel/kvmclock.c
+++ b/arch/x86/kernel/kvmclock.c
@@ -138,6 +138,7 @@ static unsigned long kvm_get_tsc_khz(void)
src = &hv_clock[cpu].pvti;
tsc_khz = pvclock_tsc_khz(src);
put_cpu();
+ setup_force_cpu_cap(X86_FEATURE_TSC_KNOWN_FREQ);
return tsc_khz;
}
まとめ
- Linux 難しい
TAGS: #kernel/hack/1