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

# このページの内容

- 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セット実行して、時間を合計しました。

1. `std::printf("Hello World!")`
2. `std::wprintf(L"Hello World!")`
3. `std::cout << "Hello World!"`
4. `std::wcout << L"Hello World!"`
5. `fmt::print("Hello World!")`
6. `fmt::print(L"Hello World!")`
7. `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のリファレンス](https://docs.microsoft.com/ja-jp/cpp/c-runtime-library/reference/setvbuf?view=msvc-170)）
ということで先ほどのパフォーマンス計測プログラムに以下のコードを追加して、再計測してみました。
```cpp
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`を使用しないときと並べてみます。

| 実行環境<br>setvbufの有無 | Con(x64)<br>なし | Con(x64)<br>あり | File(x64)<br>なし | File(x64)<br>あり | nul(x64)<br>なし | nul(x64)<br>あり |
|:-|-:|-:|-:|-:|-:|-:|
| 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`のときに実際の出力が行われるはずです。
```cpp
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`でも試してみました。
```cpp
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`を使用することでかなり改善できそうです。

# とはいえ

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