ファイル読み込みのオーバーヘッド測定

要約

1. ファイル読み込みのオーバヘッドは大きいらしい。
2. 複数のファイルを1つにまとめて読み込めばこのオーバヘッドをかなり軽減できるらしい。
3. この効果を具体的な数字で見たかったので、適してそうなデータセットを探して環境を考えて計測した。
4. 結果、思ってたよりオーバヘッドは大きかった。

はじめに

近年、機械学習等で大量のファイルを読み込む需要が増しています。
しかし、大量のファイルを読み込もうとすると、プログラム中のメインの処理よりもファイル読み込みのオーバヘッドが大きくなってしまう場合があります。
例えば、CIFAR-10ではファイル読み込みのオーバヘッドを削減するために1つのファイルに複数の画像を保存しています。

この効果が気になったので、CIFAR-10を用いてファイル読み込みのオーバヘッドがプログラムにどの程度影響するかを調査してみました。

もくじ

1. データセット
2. 測定プログラム
3. 結果
4. 解説
5. Appendix

データセット

測定対象のデータセットは画像認識界でおなじみのCIFAR-10です。
CIFAR-10は32×32pixelの10クラスからなる画像群です。
上記のサイトでバイナリファイルとして配布されているものを用います。
1つのバイナリファイルの中に10000枚分の画像データが記述されています。
バイナリの構成は以下のようになります。

画像1枚当たりの容量は, ラベル1byte + 画像データ32 × 32 × 3byte = 3073byteなので, 1つのバイナリファイルは約30MBです。
これを読み取ることでファイル読み込みのオーバーヘッドを測定します。

測定プログラム

ファイル読み込みのオーバーヘッドを測定するために、以下の3つのプログラムを用意しました。

1. open_time.cpp
2. open_time_individual.cpp
3. open_time_loop.cpp

open_time はCIFAR-10のバイナリファイルを直接読み込むプログラムです。
fopen()、fclose()は実行中に1回のみコールされます。
open_time_individualはCIFAR-10のバイナリファイルをあらかじめ画像ごとに分割して保存したディレクトリから読み込むプログラムです。
fopen()、fclose()はプログラム中で画像の枚数である10000回コールされます。
open_time_loopはCIFAR-10のバイナリファイルを直接読み込むプログラムですが、open_timeとは異なり画像ごとにfopen()、fclose()をコールするプログラムです。
open_time_individualと同様に、fopen()、fclose()は実行中に10000回コールされます。

上記のファイル読み込みを除く, これら3つのプログラムに共通する処理を説明します。
実行時間の計測はchronoライブラリのsystem_clockで行います。
データセットで述べたようにバイナリファイルの先頭1byteは画像のラベルなので、fseek(fp,1L,SEEK_CUR)によって1byte分スキップしています。
画像の読み込みはfread(pic, sizeof(uint8_t), 3072, fp)で行い、ループ内の処理として各pixelの値をロードし加算してストアする処理を行っています。
なお、ファイル操作のエラー処理は省略しています。

open_time.cpp

#include <stdio.h>
#include <chrono>
int main(int argc, char** argv) {
    chrono::system_clock::time_point start, end;
    uint8_t pic[3072] = {0};
    start = chrono::system_clock::now();
    auto fp = fopen("./cifar-10-batches-bin/data_batch_1.bin", "rb");
    for(int j=0;j<10000;++j){
        fseek(fp,1L,SEEK_CUR);
        fread(pic, sizeof(uint8_t), 3072, fp);
        for(int i=0;i<3072;++i){
            pic[i]++;
        }
    }
    fclose(fp);
    end = chrono::system_clock::now();
    double time = static_cast<double>(chrono::duration_cast<chrono::microseconds>(end - start).count() / 1000.0);
    printf("time %lf[ms]\n", time);

    return 0;

open_time_individual.cpp

#include <stdio.h>
#include <chrono>
#include <string>
int main(int argc, char** argv) {
    chrono::system_clock::time_point start, end;
    std::string filenames[10000] = {""};
    for(int j=0; j<10000;++j){
        filenames[j] = "./cifar10-raw/" + std::to_string(j) + ".bin";
    }
    uint8_t pic[3072] = {0};
    start = chrono::system_clock::now();
    for(int j=0;j<10000;++j){
        auto fp = fopen(filenames[j].c_str(), "rb");
        fseek(fp,1L,SEEK_CUR);
        fread(pic, sizeof(uint8_t), 3072, fp);
        for(int i=0;i<3072;++i){
            pic[i]++;
        }
        fclose(fp);
    }
    end = chrono::system_clock::now();
    double time = static_cast<double>(chrono::duration_cast<chrono::microseconds>(end - start).count() / 1000.0);
    printf("time %lf[ms]\n", time);

    return 0;

open_time_loop.cpp

#include <stdio.h>
#include <chrono>
int main(int argc, char** argv) {
    chrono::system_clock::time_point start, end;
    uint8_t pic[3072] = {0};
    start = chrono::system_clock::now();
    for(int j=0;j<10000;++j){
        auto fp = fopen("./cifar-10-batches-bin/data_batch_1.bin", "rb");
        fseek(fp,1L+3073L*j,SEEK_CUR);
        fread(pic, sizeof(uint8_t), 3072, fp);
        for(int i=0;i<3072;++i){
            pic[i]++;
        }
        fclose(fp);
    }
    end = chrono::system_clock::now();
    double time = static_cast<double>(chrono::duration_cast<chrono::microseconds>(end - start).count() / 1000.0);
    printf("time %lf[ms]\n", time);

    return 0;
}

結果

実際に実行した結果を以下に示します。

 % ./open_time
time 62.964000[ms]
 % ./open_time_individual
time 1154.943000[ms]
 % ./open_time_loop
time 1086.277000[ms]

open_time に対して、open_time_individualとopen_time_loopでは約20倍の実行時間がかかることがわかります。
また、open_time_individualとopen_time_loopの実行時間は同程度あることがわかります。

解説

open_time とopem_time_loopは同じデータ領域を読み込むプログラムであるが、実行時間はfopen()に依存することがわかります。
また、open_time_individualとopen_time_loopの実行時間は同程度であることから、実行時間はfopen()するファイルの種類ではなく回数に依存することがわかります。

fopen()の際はシステムコールでファイルをOpenする必要があり、ユーザーモードからカーネルモードに切り替える必要があります。
メモリアクセスの場合は、一度アロケイトされたアドレス空間なら切り替えのオーバヘッドなく実行できます。
CIFAR-10程度の画像であれば、メモリアクセスよりもfopen()を処理する時間が大きいことがわかりました。

Appendix

CIFAR-10のバイナリファイルから各画像ごとに分割したバイナリファイルを生成するのに用いたシェルスクリプト

for i in `seq 0 9999` 
do
    t=$(($i * 3073))
    tail -c +$t cifar-10-batches-bin/data_batch_1.bin | head -c 3073 > "cifar10-raw/"$i".bin"
done

分割したバイナリファイルが画像として正しいか判断するために、pngに変換するPythonスクリプト

import numpy as np
from PIL import Image

fp = open("sample.bin", "rb")
label = fp.read(1)
data = np.zeros(3072, dtype='uint8')
for i in range(3072):
    data[i] =  int.from_bytes(fp.read(1), 'little')

fp.close()
data = data.reshape(3, 32, 32)
data = np.swapaxes(data, 0, 2)
data = np.swapaxes(data, 0, 1)
with Image.fromarray(data) as img:
    img.save("sample.png")