コグノスケ

Zephyr RISC-V向けのマルチコアブートを修正

目次: Zephyr

Zephyr RTOSのRISC-V向けマルチコアブート処理がバグっていて修正したので解析したメモを残しておきます。

ZephyrではCONFIG_RV_BOOT_HARTというコンフィグで設定したhartidと、mhartid CSRの値が一致するhartがメインの初期化を担当します。Zephyrのコードではfirst coreと呼び、メイン以外はsecondary coreと呼んでいます。あまり聞いたことがない呼び方ですね。この日記では素直にメインコア/サブコアと書きます。

メインコアはarch_start_cpu()という関数からサブコアを起床します。呼び出しの経路は下記です。

z_thread_entry()
  bg_thread_main()
    z_smp_init()
      arch_start_cpu()

このbg_thread_main()関数はメインスレッド実行前に必要な初期化を実施していて、最終的にmain()を呼び出します。実行タイミングはカーネルの初期化が終わって、メインスレッドにコンテキストスイッチしたあとです。ブートからそれなりに時間が経過しています。

// zephyr/arch/riscv/core/smp.c

void arch_start_cpu(int cpu_num, k_thread_stack_t *stack, int sz,
		    arch_cpustart_t fn, void *arg)
{
	riscv_cpu_init[cpu_num].fn = fn;
	riscv_cpu_init[cpu_num].arg = arg;

	riscv_cpu_sp = Z_KERNEL_STACK_BUFFER(stack) + sz;
	riscv_cpu_wake_flag = _kernel.cpus[cpu_num].arch.hartid;    //★★1-1: riscv_cpu_wake_flagに起床させるhartidを設定する★★

#ifdef CONFIG_PM_CPU_OPS
	if (pm_cpu_on(cpu_num, (uintptr_t)&__start)) {
		printk("Failed to boot secondary CPU %d\n", cpu_num);
		return;
	}
#endif

	//★★1-2: riscv_cpu_wake_flagが0になるまで待つ★★
	while (riscv_cpu_wake_flag != 0U) {
		;
	}

	//★★1-3: riscv_cpu_wake_flagが0になったら継続★★
}

サブコアは下記のようにブート直後にフラグチェックし、起動の指示があるまで待っています。

// zephyr/arch/riscv/core/reset.S

SECTION_FUNC(TEXT, __initialize)
	csrr a0, mhartid            //★★a0 <- mhartid★★
	li t0, CONFIG_RV_BOOT_HART
	beq a0, t0, boot_first_core
	j boot_secondary_core

//...

boot_secondary_core:
#if CONFIG_MP_MAX_NUM_CPUS > 1
	//★★2-1: riscv_cpu_wake_flagがmhartidになるまで待つ★★★
	la t0, riscv_cpu_wake_flag
	lr t0, 0(t0)
	bne a0, t0, boot_secondary_core

	//★★2-2: riscv_cpu_wake_flagがmhartidになったら継続する★★★
	/* Set up stack */
	la t0, riscv_cpu_sp
	lr sp, 0(t0)

	la t0, riscv_cpu_wake_flag
	sr zero, 0(t0)               //★★2-3: riscv_cpu_wake_flagに0をセット★★
	j z_riscv_secondary_cpu_init

コードの想定する動作は下記の通りです。例としてhart0がメイン、hart1がサブの2コアのブートとします。

• hart1: 2-1: riscv_cpu_wake_flag == mhartid (= 1)になるまで待つ
• hart0: 1-1: riscv_cpu_wake_flagに起床させるhartid = 1を設定する（arch_start_cpu()関数）
• hart0: 1-2: riscv_cpu_wake_flag == 0になるまで待つ
• hart1: 2-2: riscv_cpu_wake_flag == mhartid (= 1)になったので継続
• hart1: 2-3: riscv_cpu_wake_flagを0にセットする
• hart0: 1-3: riscv_cpu_wake_flag == 0になったので継続

このときriscv_cpu_wake_flagの初期値はいずれのサブコアのmhartidとも一致しないのが期待値です。

問題点

このコードはriscv_cpu_wake_flagの初期値がいずれかのサブコアのmhartidと一致するとハングアップします。riscv_cpu_wake_flagはBSS領域に配置されておりメインコアがいずれ0に初期化しますが、サブコアはメインコアがBSS領域を初期化する前にriscv_cpu_wake_flagを参照するので間に合いません。

例えば起動直後にriscv_cpu_wake_flagが偶然1だったとすると下記のような動きをしてハングアップします。

• hart1: 2-1: riscv_cpu_wake_flag == mhartid (= 1)になるまで待つ
• hart1: 2-2: riscv_cpu_wake_flag == mhartid (= 1)なので継続
• hart1: 2-3: riscv_cpu_wake_flagを0にセットする
• hart0: 1-1: riscv_cpu_wake_flagに起床させるhartid = 1を設定する（arch_start_cpu()関数）
• hart0: 1-2: riscv_cpu_wake_flag == 0になるまで待つ
• hart0: 誰もriscv_cpu_wake_flagを0に戻さないのでハングアップ

この実装をどう変更したら良くなるのか？なぜか？については少々長くなるので、以前の日記（2021年9月28日の日記参照）をご覧ください。

対策

サブコアを起こすフラグriscv_cpu_wake_flag（初期値は-1）とサブコアが起きたことを示すフラグriscv_cpu_boot_flag（初期値は0）に分けます。riscv_cpu_wake_flagはサブコアから-1に初期化してから起動待ちに入るようにして、不定値問題に対処します。

Zephyr RTOSのプロジェクトにPull Requestを送ったところあっさり取り込まれました（Zephyrへのリンク）。1週間以上は掛かるかと思っていましたが、早かったです。今は修正に向いている時期なんでしょうか。

とまあ、ここまで書いていて対策後のコードも間違っているような気がしてきました。

メインコアがhart0じゃない場合、BSS領域の初期化でriscv_cpu_wake_flagが0に変わってしまうので、hart0が間違って起動するのではなかろうか……？それは良くないな、後で確かめようと思います。

yesの高速化（パイプ限定）

目次: ベンチマーク

FizzBuzzを作っていて気づきましたが、vmsplice()を使うとメチャクチャ速いyesコマンドを実装できます。

昔に紹介した通り（2017年6月14日の日記参照）GNU yes 8.26近辺から出力がとても速くなっています。あとで分析しますがwrite()を使ったときの最速と思われる速度が出ますが、出力先をパイプに限定して良ければvmsplice()を使うことでさらに速くできます。

$ ./yes

vmsplice: Bad file descriptor

ちなみに今回紹介する高速化の手法であるvmsplice()はパイプ以外、例えば端末に出そうとするとエラーになりますから、汎用的なyesコマンドの実装としては使えません。状況に制限を掛けてまで高速なyesが欲しい場合が果たしてあるだろうか？と言われると、うーん、すぐには思いつかないですね……。ベンチマークには役に立ちますけども。

レギュレーションとテスト

本来のyesコマンドの仕様は「引数で受け取った文字列と改行を無限に出力する」ですが、ベンチマークの都合上どこか一定の場所で終わってほしいので、適当に0x2ffffffff行（128億行）くらい出力したら終わりとします。行数は多少増減しても気にしないことにします。デフォルトでは1行2バイト（'y'と改行）なので出力するデータ量の合計は24GBくらいになります。

内容的には難しくないので不要な気もしますが、正常動作を確かめるテストプログラムを作ります。基本的に延々と同じ内容の行が出力されるだけなので、全て見なくても0x0fff_ffff（2億行）も見れば十分でしょう。たぶん。

// 20231106_test_yes.c

#include <stdio.h>
#include <stdlib.h>
#include <string.h>

int main(int argc, char *argv[])
{
	const char *ex;
	char expected[256];
	char *inbufp = NULL;
	size_t insz = 0;

	if (argc < 2) {
		ex = "y";
	} else {
		ex = argv[1];
	}

	snprintf(expected, sizeof(expected), "%s\n", ex);

	for (unsigned int i = 1; i < 0xfffffff; i++) {
		getline(&inbufp, &insz, stdin);

		if ((i & 0xffffff) == 0) {
			printf("\r%u      ", i);
			fflush(stdout);
		}
		if (strcmp(expected, inbufp) != 0) {
			printf("\n");
			printf("Not matched in %u\n", i);
			printf("  expected: %s\n", expected);
			printf("  input   : %s\n", inbufp);
			return 1;
		}
	}

	printf("\nOK\n");

	return 0;
}

本物のyesをテストしてみてfailしないか確かめます。

$ yes | ./test_yes
251658240
OK


$ yes aaaaaaaa | ./test_yes aaaaaaaa
251658240
OK


### 引数の指定が効いているか確かめる

$ yes | ./test_yes aaaaaaaa

Not matched in 1
  expected: aaaaaaaa

  input   : y


$ yes aaaaaaaa | ./test_yes

Not matched in 1
  expected: y

  input   : aaaaaaaa

良さそうですね。あとは測定環境です。省電力PCの測定環境は、

• Intel Pentium J4205/1.5GHz
• DDR3L-1600 8GB x 2
• Linux kernel 6.1.52
• GCC 12.2.0 (Debian 12.2.0-14)
• glibc 2.36 (Debian 2.36-9+deb12u1)

デスクトップPCの測定環境は、

• AMD Ryzen 7 5700X
• DDR4-3200 32GB x 2
• Linux kernel 6.4.13 (Debian 6.4.13-1)
• GCC 13.2.0 (Debian 12.2.0-14)
• glibc 2.37 (Debian 2.37-7)

準備完了です。ではいってみよう。

単純なyes

最初はprintf()で普通に実装しましょう。

// 20231106_yes_simple.c

#include <stdint.h>
#include <stdio.h>

int main(int argc, char *argv[])
{
	const char *arg;

	if (argc < 2) {
		arg = "y";
	} else {
		arg = argv[1];
	}

	for (uint64_t i = 0; i < 0x2ffffffff; i++) {
		printf("%s\n", arg);
	}

	return 0;
}

$ gcc 20231106_yes_simple.c -msse4 -O3

24.0GiB 0:08:31 [48.1MiB/s] [           <=>                                    ]

real    8m31.031s
user    8m26.537s
sys     0m36.512s

一度のprintf()で2バイトしか出力しないので、メチャクチャ遅いですね。

バッファリング版yes

次はwrite()とバッファリングを使います。アイデアは単純で、適当な大きさのバッファに出力する文字を詰められるだけ詰めて、バッファをwrite()に渡して複数行を一気に出力する方法です。本来の処理では不要ですが、ベンチマークのため一度に何行出力しているか覚えておく必要があります。

// 20231106_yes_buf.c

#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>

#define CHUNKSIZE    (4096 * 2)

char output[CHUNKSIZE] __attribute__((aligned(4096)));

int main(int argc, char *argv[])
{
	const char *arg;
	char out_one[256];
	size_t len_one, len = 0;
	int d = 0;

	if (argc < 2) {
		arg = "y";
	} else {
		arg = argv[1];
	}

	len_one = snprintf(out_one, sizeof(out_one), "%s\n", arg);
	while (len + len_one < sizeof(output) - 1) {
		strcat(output, out_one);
		len += len_one;
		d++;
	}

	for (uint64_t i = 0; i < 0x2ffffffff - 1; i += d) {
		write(1, output, len);
	}

	return 0;
}

$ gcc 20231106_yes_buf.c -msse4 -O3

24.0GiB 0:00:11 [2.16GiB/s] [           <=>                                    ]

real    0m11.095s
user    0m1.564s
sys     0m20.571s


（参考 GNU yesの速度）

$ yes --version

yes (GNU coreutils) 9.1
（以下略）


$ time taskset 0x1 yes | taskset 0x4 pv > /dev/null

24.2GiB 0:00:11 [2.23GiB/s] [          <=>                                     ]
^C

real    0m11.600s
user    0m1.528s
sys     0m21.621s

一気に速くなりました。GNU yesの速度も参考に載せましたが、ほぼ同じ速度です。これがwrite()で出力するときの限界速度でしょう。

vmsplice版yes

最後はvmsplice()です。基本的なアイデアはバッファリング版yesと同じです。ただしvmsplice()に対応するために、ダブルバッファリングとバッファ終端からはみ出た場合の処理を追加します。

// 20231106_yes_vmsplice.c

#define _GNU_SOURCE

#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>

#include <fcntl.h>
#include <sys/uio.h>

#define CHUNKSIZE    (4096 * 64)

char buf2[2][CHUNKSIZE + 4096] __attribute__((aligned(4096)));
int f __attribute__((aligned(8)));
char output[2048] __attribute__((aligned(4096)));

static void vwrite(int fd, void *buf, size_t count)
{
	struct iovec iov;
	ssize_t n;

	iov.iov_base = buf;
	iov.iov_len = count;

	while (iov.iov_len > 0) {
		n = vmsplice(1, &iov, 1, 0);
		if (n < 0) {
			perror("vmsplice");
			exit(1);
		}
		iov.iov_base += n;
		iov.iov_len -= n;
	}
}

int main(int argc, char *argv[])
{
	const char *arg;
	char out_one[256];
	char *p = buf2[f];
	size_t len_one, len = 0;
	int d = 0;

	fcntl(1, F_SETPIPE_SZ, CHUNKSIZE);

	if (argc < 2) {
		arg = "y";
	} else {
		arg = argv[1];
	}

	len_one = snprintf(out_one, sizeof(out_one), "%s\n", arg);
	while (len + len_one < sizeof(output) - 1) {
		strcat(output, out_one);
		len += len_one;
		d++;
	}

	for (uint64_t i = 0; i < 0x2ffffffff - 1; i += d) {
		memcpy(p, output, len);
		p += len;

		int n = p - buf2[f] - CHUNKSIZE;
		if (n >= 0) {
			vwrite(1, buf2[f], CHUNKSIZE);
			f = !f;
			memcpy(buf2[f], &buf2[!f][CHUNKSIZE], n);
			p = &buf2[f][n];
		}
	}

	return 0;
}

$ gcc 20231106_yes_vmsplice.c -msse4 -O3
24.0GiB 0:00:03 [7.14GiB/s] [   <=>                                            ]

real    0m3.367s
user    0m1.849s
sys     0m3.297s

予想はしていましたがメチャクチャ速くなりました……。vmsplice()恐るべし。

$ gcc 20231106_yes_simple.c -msse4 -O3

24.0GiB 0:01:54 [ 213MiB/s] [              <=>                                 ]

real    1m54.938s
user    1m52.312s
sys     0m22.559s


$ gcc 20231106_yes_buf.c -msse4 -O3

24.0GiB 0:00:05 [4.49GiB/s] [     <=>                                          ]

real    0m5.347s
user    0m0.912s
sys     0m9.776s


$ gcc 20231106_yes_vmsplice.c -msse4 -O3

24.0GiB 0:00:00 [33.7GiB/s] [<=>                                               ]

real    0m0.715s
user    0m0.508s
sys     0m0.721s

PentiumとRyzen 7の測定結果、どの程度速くなったかを合わせて表にすると、

使える場所が限定されるとはいえ素晴らしい効き目ですね。ちなみにRyzen 7はバッファサイズを4倍（1MB x 2）にするとさらに速くなって、0.612秒（39.4GiB/s、187.8倍）くらいになります。まさか1秒も掛からないとは思わなんだ……。

ソースコード

ソースコードはこちらからどうぞ。

•  テストプログラム
•  単純
•  バッファリング
•  vmsplice

Googleから探しやすくしたい

この日記にはいくつかヘッダ（Hxタグ）を使っており、文書の構造は下記のようにしています。

• H1: タイトル
• H2: 不使用（昔は使っていたけどデザイン変更でなくなった）
• H3: 日記の日付
• H4: 日記内のトピック

しかしどうもGoogleさんはH4タグを拾わないときがあるようで、

H4タグの内容を拾うときと拾わないときがある？

こんな風に日付だけが出て、内容が良くわからなくなってしまうことがあります。試しに日記内のトピックを格上げし、日記の日付と同格のH3にして検索結果がどうなるか観察しようと思います。

日付を消すことも少し考えましたが、とりあえず今のままにしておきます。テキスト環境のブラウザで見るときにも日付があると結構見やすいですし（日記の切れ目が分かりやすい……気がする）。