天狗会議録 Posts Pages About

printf vs fwrite

#experiment2023/3/20

背景

ゲーム開発フレームワークを作る上で、ロガーが欲しくなった。 C言語のみで記述している都合上、言語(あるいは主要言語処理系)標準のロガーは存在しない。 文字列を出力するだけの簡単なもので良いため、外部ライブラリを用いるのは大げさである。 従って、簡単なロガーを実装することにした。

ロガーを実装するには、高速な標準出力の手法を把握していなければならない。 lwlogを見たところ、fwriteとsetvbufだけで高速になるように見える。

これが本当か否かぱっと調べたところ、printfとfwrite・あるいはバッファリング有無の速度比較に関する文献がない。 あまりにも検証が簡単だからであろうか。 それとも、あまりにも初級的な議論であるからであろうか。

ということで、簡単な実験をしたため、結果をまとめる。

プログラム

既定の文字列と外部から与えられた文字列を、10000行(一行ずつflush)出力するプログラムにおいて、次の四パターンを検証した。

  • printf
  • fwrite
  • printf(バッファリング有り)
  • fwrite(バッファリング有り)

環境は以下。

  • Windows 10 Home
  • gcc.exe (x86_64-win32-seh-rev2, Built by MinGW-W64 project) 12.2.0
  • Powershell

ソースコードは以下。 gccの-Dオプションでパターンを切り替えられるようにした。「gcc -DPRINTF -DIOFBF main.c」のようにビルドして欲しい。

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

LARGE_INTEGER freq;
LARGE_INTEGER before;
LARGE_INTEGER after;

void test_printf(const char *msg) {
    QueryPerformanceCounter(&before);
    for (int i = 0; i < 10000; ++i) {
        printf("hello %s\n", msg);
#ifdef IOFBF
        fflush(stdout);
#endif
    }
    QueryPerformanceCounter(&after);
}

void test_fwrite(const char *msg) {
    QueryPerformanceCounter(&before);
    for (int i = 0; i < 10000; ++i) {
        fwrite("hello ", sizeof(char), 6, stdout);
        fwrite(msg, sizeof(char), strlen(msg), stdout);
        fwrite("\n", sizeof(char), 1, stdout);
#ifdef IOFBF
        fflush(stdout);
#endif
    }
    QueryPerformanceCounter(&after);
}

int main() {
    QueryPerformanceFrequency(&freq);
#ifdef IOFBF
    setvbuf(stdout, NULL, _IOFBF, 1024);
#endif
#ifdef PRINTF
    test_printf("world!");
    printf("printf\n");
#elif FWRITE
    test_fwrite("world!");
    printf("fwrite\n");
#endif
#ifdef IOFBF
    printf("with _IOFBF\n");
#endif
    printf("%lf ms\n", (after.QuadPart - before.QuadPart) * 1000.0 / freq.QuadPart);
    return 0;
}

ラインバッファリング(_IOLBF)を用いるべきであろうが、何故か期待通りにflushされなかったため、フルバッファリング(_IOFBF)にした上で一行ずつfflush()を呼び出すことにした。

結果

五回実行した。結果を以下にまとめる。単位はミリ秒(ms)である。小数点以下は切り捨てる。

printffwriteprintf(_IOFBF)fwrite(_IOFBF)
149922439425432
260601919542430
347222411440542
460991876544461
550801923433543
Average53902113476481

バッファリングなしでは圧倒的にfwriteが速く、バッファリングありでは両者大差ないという結果を得られた。

printfは整形をする分遅いであろうと想定できるが、であればバッファリングありで大差ない理由がわからない。 この点は検証の余地がある。

取り敢えずロガーは、取り回しの良いバッファリングありのprintfで実装するのが良さそうだ。