このページの内容

WindowsのC++コンソールアプリでprintf、std::coutなどの実行速度を比べてみた。
std::coutが早く、std::wcoutがものすごく遅かった。
setvbufを使うことでかなり高速化できた。

きっかけ

WindowsでC++のコンソールアプリケーションを作るとき、標準出力に書き出す方法はstd::coutやstd::wcout、printfなどいくつかあります。
C++であれば一般的なのはstd::coutかstd::wcoutだと思いますが、パフォーマンス的にどれが良いのかという情報はあまり見つけられませんでした。
そこでprintf、wprintf、std::cout、std::wcoutなどの速度を比べてみることにしました。

計測方法

以下のコードをそれぞれ10万回ずつ実行して、その時間を計測するプログラムを作成しました。計測ノイズを減らすため、コード的にはそれぞれを1000回ずつ100セット実行して、時間を合計しました。

std::printf("Hello World!")
std::wprintf(L"Hello World!")
std::cout << "Hello World!"
std::wcout << L"Hello World!"
fmt::print("Hello World!")
fmt::print(L"Hello World!")
L"Hello World!"をWideCharToMultiByteで変換してstd::cout

fmt::printはfmtというOSSの関数で、printfに近い書き方ができて、さらに型チェックなども行ってくれる、printfの上位ともいえる関数です。
https://fmt.dev/latest/index.html
fmtのsprintfに相当するfmt::formatはC++20でstd::formatとして採用されています。（fmt::printはstdにはありません）

実行方法は以下のパターンを試しました。

x64ビルドでコンソールに出力
x86ビルドでコンソールに出力
x64ビルドでファイルにリダイレクト
x86ビルドでファイルにリダイレクト
x64ビルドでnulにリダイレクト（出力を破棄）
x86ビルドでnulにリダイレクト（出力を破棄）

計測結果

計測結果は以下のようになりました。時間の単位はミリ秒です。

	Con(x64)	Con(x86)	File(x64)	File(x86)	nul(x64)	nul(x86)
1. printf	3804.5	3796.6	18.0	34.1	87.3	117.8
2. wprintf	3832.6	3857.4	45.1	40.4	114.2	119.8
3. std::cout	3824.3	3849.8	9.9	14.9	81.9	102.0
4. std::wcout	36964.1	37460.9	52.5	67.1	955.9	1148.9
5. fmt::print	3740.5	3753.4	12.5	16.7	82.9	102.9
6. fmt::print(wchar)	3788.8	3791.4	40.0	35.3	112.6	118.2
7. WideCharToMultiByte	3825.8	3888.0	14.6	18.4	86.7	105.2

分析

色々と興味深い結果です。特に気になる点を見ていきます。

std::wcoutがとても遅い

まず目につくのがstd::wcoutの異様な遅さです。特にコンソール出力では他の10倍ほどの時間がかかっています。
原因を調べていたところ以下のようなページを見つけました。
https://github.com/microsoft/STL/issues/605
あまり詳しくは書かれていませんが、どうもstd::wcoutのときは１文字ずつ処理が行われてしまうために、処理が重たくなっているようです。

wprintfも遅い

std::wcoutほどではないですが、wprintfも遅いです。fmt::printもwchar版は遅いです。
WideCharToMultiByteを使用して自分でwcharからcharに変換した方が早いです。
Windowsの文字列は基本wcharだと思っていたのでこの結果は予想外でした。
歴史的なことを考えてもコンソールはいまだにマルチバイト（シフトJIS）を基本に動作しているのかもしれません。

std::coutが早い

これは予想通りです。printfはフォーマット文字列の解析を実行時に行うのに対して、std::coutはコンパイル時に行うので処理が早いといわれていますが、その通りでした。

fmt::printも早い

コンソールに出力した場合はfmt::printの方が早いです。fmtは高速な動作も売りにしているので、さすがといったところです。

ファイルよりnulにリダイレクトする方が遅い

これは本題とは少し異なりますが興味深いです。
nulへのリダイレクトはOSレベルでの出力の破棄なので、普通に考えれば最速になりそうなものです。
nulへのリダイレクトはあまり使われないので、最適化されていないとかそういう理由なのかもしれません。

setvbufによる高速化

std::wcoutが重いことを調べていたときに見つけたページには、setvbufを使用することで改善できると書かれていました。
https://github.com/microsoft/STL/issues/605
コンソールへの出力はデフォルトではバッファリングされておらず、setvbufを呼び出すことでバッファリングされるようになるようです。（setvbufのリファレンス）
ということで先ほどのパフォーマンス計測プログラムに以下のコードを追加して、再計測してみました。

setvbuf(stdout, 0, _IOLBF, 4096);

_IOLBFを指定することにより、改行されるまでバッファリングされます。
計測結果は以下のようになりました。

	Con(x64)	Con(x86)	File(x64)	File(x86)	nul(x64)	nul(x86)
1. printf	315.0	322.4	16.9	31.5	13.7	29.0
2. wprintf	329.5	328.5	45.4	36.4	42.0	34.3
3. std::cout	306.7	298.9	10.6	13.6	8.7	9.8
4. std::wcout	343.2	345.9	57.8	64.9	56.7	60.5
5. fmt::print	304.2	290.0	12.1	15.7	10.2	12.7
6. fmt::print(wchar)	329.3	316.4	42.4	32.7	40.6	31.2
7. WideCharToMultiByte	315.0	306.3	14.8	16.2	10.4	14.1

このままだと比較がしにくいので、x64版だけをsetvbufを使用しないときと並べてみます。

実行環境 setvbufの有無	Con(x64) なし	Con(x64) あり	File(x64) なし	File(x64) あり	nul(x64) なし	nul(x64) あり
1. printf	3804.5	315.0	18.0	16.9	87.3	13.7
2. wprintf	3832.6	329.5	45.1	45.4	114.2	42.0
3. std::cout	3824.3	306.7	9.9	10.6	81.9	8.7
4. std::wcout	36964.1	343.2	52.5	57.8	955.9	56.7
5. fmt::print	3740.5	304.2	12.5	12.1	82.9	10.2
6. fmt::print(wchar)	3788.8	329.3	40.0	42.4	112.6	40.6
7. WideCharToMultiByte	3825.8	315.0	14.6	14.8	86.7	10.4

ファイルへのリダイレクトではほぼ変わりませんが、nulとコンソールへの出力ではかなり早くなっています。
std::wcoutもいまだに一番遅いですが、他との差はかなり縮まっています。コンソールへの出力なら他と比べて少し遅い程度です。
これはかなり有効な方法のようです。

setvbufの問題点

setvbufを使用することで気になるのは、バッファリングされることによるデメリットです。そこで以下のようなコードを試してみました。setvbufの_IOLBFによって改行までバッファリングされるなら、最後の\nのときに実際の出力が行われるはずです。

setvbuf(stdout, 0, _IOLBF, 4096);
setvbuf(stderr, 0, _IOLBF, 4096);
printf("print ");
fprintf(stderr, "error ");
printf("print ");
fprintf(stderr, "error ");
printf("\n");
fprintf(stderr, "\n");

これは予想通り以下のような結果になりました。

print print
error error

もちろんsetvbufをコメントアウトすると結果は以下のようになります。

print error print error

今度は同じことをstd::coutとstd::cerrでも試してみました。

setvbuf(stdout, 0, _IOLBF, 4096);
setvbuf(stderr, 0, _IOLBF, 4096);
std::cout << "cout ";
std::cerr << "cerr ";
std::cout << "cout ";
std::cerr << "cerr ";
std::cout << std::endl;
std::cerr << std::endl;

この結果は以下のようになりました。

print error print error

不思議なことにバッファリングしていないときと結果が変わりませんでした。
調べてみるとstd::cerrには呼び出しごとにバッファを出力するフラグが設定されているようです。
https://cpprefjp.github.io/reference/iostream/cerr.html
そしてこのフラグが設定されていないエラー出力としてstd::clogというオブジェクトがあるようです。std::cerrをstd::clogに変えて試したところ、printfと同じく改行までバッファリングされるようになりました。

以上が思いついたデメリットですが、これが実際に問題になる状況もあまりなさそうではあります。

結論

パフォーマンス的にはstd::coutかfmt::printが良さそうです。逆にwcharを標準出力に出力するのはあまり良くなさそうです。特にstd::wcoutはかなり遅いです。
いずれの場合でも標準出力が重たい場合は、setvbufを使用することでかなり改善できそうです。

とはいえ

ここまで書いておいてなんですが、標準出力が重たいことが問題になった場合、そもそもそこまでの大量の出力を行っていること自体が問題な気もします。別のログファイルに出力することなどを検討したほうが良さそうです。

Windows C++の標準出力（printf cout wcout）はどれが早いのか？