メモの日々


2011年10月14日(金) [長年日記]

  • しばらく何もメモすることが無かった。成長していないということ。

[c++] std::ostringstream がマルチスレッド動作時に遅い

std::ostringstreamはログ出力などによく使うのだけれど、Linux上のマルチスレッドで動くプログラムの中では異様に遅いことが観測されたので調べてみた。

測定結果

最後に示すプログラムにより、

  • func0: 文字列構築の度にostringstreamオブジェクトを作り直す
  • func1: 1度作ったostringstreamオブジェクトを使い回す
  • func2: sprintfを使う

の3通りで時間を計ってみた結果、次のようになった。環境により傾向が少し違った(どちらも古い環境で恐縮ですが)。

CPU数16, カーネル2.6.9, GCC 3.4.6

スレッド数1スレッド数2スレッド数4スレッド数8
func04.3656.38010.32921.490
func13.3953.3443.3353.598
func22.6222.5352.5472.740

数字はtimeコマンドで計った実行時間(単位は秒)。func0だけスレッド数の増加と共に性能が劣化している。

表には書いていないが、func0だけはスレッド数が増加するとシステム時間の比率がどんどん増え、8スレッドの場合はスレッドあたりのユーザ時間7.6秒に対しシステム時間13.0秒となっていた。どうしてそうなるのかはわからない。

ostringstreamを使っても、func1のようにオブジェクトを使い回すようにすると性能は劣化しない(sprintfよりは遅いが)。ということは、ostringstreamのコンストラクタに問題があると考えられる。

CPU数8, カーネル2.6.18, GCC 4.1.2

スレッド数1スレッド数2スレッド数4スレッド数8
func04.5925.8947.37013.933
func13.3743.4233.3773.838
func22.6892.7062.7093.050

こちらの方が少しバージョンが高いが、同じくfunc0だけ性能が劣化していく。ただし、先の環境よりは改善されている。

また、こちらの環境だとスレッド数が増えてもシステム時間は増えず、ずっとほぼ0秒だった。

使ったプログラム

上の測定は、以下のプログラムの実行時間をtimeコマンドを使って測定した。

#include <cstdio>
#include <iomanip>
#include <ios>
#include <iostream>
#include <sstream>
#include <boost/bind.hpp>
#include <boost/function.hpp>
#include <boost/lexical_cast.hpp>
#include <boost/thread.hpp>

using namespace std;
using namespace boost;

// 毎回ostringstreamを作成
string func0(long l) {
    ostringstream oss;
    oss << l << " " << showpoint << fixed << setprecision(3) << l * 1.05;
    return oss.str();
}

thread_specific_ptr<ostringstream> ts_oss;

// スレッドローカルなostringstreamを使い回す
string func1(long l) {
    ostringstream* oss = ts_oss.get();
    if (oss) {
        oss->str("");
    } else {
        ts_oss.reset(new ostringstream());
        oss = ts_oss.get();
    }

    *oss << l << " " << showpoint << fixed << setprecision(3) << l * 1.05;
    return oss->str();
}

// sprintfを使う
string func2(long l) {
    char s[1000];
    sprintf(s, "%ld %.3f", l, l * 1.05);
    return s;
}

// boost::threadが実行する関数
void loop(function1<string, long> func) {
    string s;
    for (long l = 0; l < 2000000; ++l) {
        s = func(l);
    }
    cerr << s << endl;
}

void print_usage(const char* program) {
    cerr << "Usage: " << program << " NUM_THREADS FUNC_TYPE" << endl;
}

int main(int argc, char* argv[]) {
    if (argc != 3) {
        print_usage(argv[0]);
        exit(1);
    }
    int num_threads = lexical_cast<int>(argv[1]);
    int func_type = lexical_cast<int>(argv[2]);
    if (func_type < 0 || func_type > 2) {
        print_usage(argv[0]);
        exit(1);
    }

    string (*functions[])(long) = {func0, func1, func2};

    thread_group threads;
    for (int i = 0; i < num_threads; ++i) {
        threads.create_thread(bind(loop, functions[func_type]));
    }
    threads.join_all();
}

[c++] std::ostringstreamのコンストラクタの実装

GCC 3.4.6(古いです)のソースをSVNからチェックアウトして、ostringstreamのコンストラクタを見てみたのでメモ。途中で力尽きています。

STL関連のソースは libstdc++-v3/include/ 配下の std/ や bits/ 辺りにあった。

basic_ostringstream

まず、basic_ostringstreamクラスのコンストラクタを見てみる。

libstdc++-v3/include/std/std_sstream.h

  459       explicit
  460       basic_ostringstream(ios_base::openmode __mode = ios_base::out)
  461       : __ostream_type(), _M_stringbuf(__mode | ios_base::out)
  462       { this->init(&_M_stringbuf); }
  • __ostream_typeは、基底クラスのbasic_ostreamのこと。また、_M_stringbufは本クラスのストリームバッファであるbasic_stringbufクラスのインスタンス。だから、461行目ではbasic_ostreamクラスとbasic_stringbufクラスのコンストラクタが呼ばれる。
  • this->init()は基底クラスのメンバ関数のようだ。

basic_ostream

次に、basic_ostreamクラスのコンストラクタを見てみる。

libstdc++-v3/include/std/std_ostream.h

  104       explicit
  105       basic_ostream(__streambuf_type* __sb)
  106       { this->init(__sb); }
  • this->init()はこのクラスにも定義されていない。更なる基底クラスのメンバ関数のようだ。基底クラスはbasic_ios。

basic_ios

basic_iosクラスのコンストラクタを見てみる。

libstdc++-v3/include/bits/basic_ios.h

  255       explicit
  256       basic_ios(basic_streambuf<_CharT, _Traits>* __sb)
  257       : ios_base(), _M_tie(0), _M_fill(), _M_fill_init(false), _M_streambuf(0),
  258       _M_ctype(0), _M_num_put(0), _M_num_get(0)
  259       { this->init(__sb); }
  • 色々呼んでるな…。
  • _M_tieはbasic_ostreamオブジェクトへのポインタ。
  • _M_fillはchar型の変数と考えてよい。
  • _M_fill_initはbool。
  • _M_streambufはbasic_streambufオブジェクトへのポインタ。
  • _M_ctypeはstd::ctypeオブジェクトへのポインタ。ctypeて知らない。「文字を分類するためのファセット」とのこと。
  • _M_num_putはstd::num_putオブジェクトへのポインタ。num_putも知らないが「数値出力のためのファセット」らしい。
  • _M_num_getはstd::num_getオブジェクトへのポインタ。num_getは「数値入力のためのファセット」。ファセットとはlocale関連処理を行う何かみたい。
  • this->init()はこのクラスで宣言されていた。実装は別ファイル。
  • 結局、見るべきは基底クラスios_baseのコンストラクタとinit()の呼び出しだけだった。

先にinit()の内容を確認。

libstdc++-v3/include/bits/basic_ios.tcc

  137   template<typename _CharT, typename _Traits>
  138     void
  139     basic_ios<_CharT, _Traits>::init(basic_streambuf<_CharT, _Traits>* __sb)
  140     {
  141       // NB: This may be called more than once on the same object.
  142       ios_base::_M_init();
  143
  144       // Cache locale data and specific facets used by iostreams.
  145       _M_cache_locale(_M_ios_locale);
  146
  147       // NB: The 27.4.4.1 Postconditions Table specifies requirements
  148       // after basic_ios::init() has been called. As part of this,
  149       // fill() must return widen(' ') any time after init() has been
  150       // called, which needs an imbued ctype facet of char_type to
  151       // return without throwing an exception. Unfortunately,
  152       // ctype<char_type> is not necessarily a required facet, so
  153       // streams with char_type != [char, wchar_t] will not have it by
  154       // default. Because of this, the correct value for _M_fill is
  155       // constructed on the first call of fill(). That way,
  156       // unformatted input and output with non-required basic_ios
  157       // instantiations is possible even without imbuing the expected
  158       // ctype<char_type> facet.
  159       _M_fill = _CharT();
  160       _M_fill_init = false;
  161
  162       _M_tie = 0;
  163       _M_exception = goodbit;
  164       _M_streambuf = __sb;
  165       _M_streambuf_state = __sb ? goodbit : badbit;
  166     }
  • 見るべきはios_base::_M_init()と_M_cache_locale(_M_ios_locale)しかない。後者のソースは同じファイルにあった。
  168   template<typename _CharT, typename _Traits>
  169     void
  170     basic_ios<_CharT, _Traits>::_M_cache_locale(const locale& __loc)
  171     {
  172       if (__builtin_expect(has_facet<__ctype_type>(__loc), true))
  173         _M_ctype = &use_facet<__ctype_type>(__loc);
  174       else
  175         _M_ctype = 0;
  176
  177       if (__builtin_expect(has_facet<__num_put_type>(__loc), true))
  178         _M_num_put = &use_facet<__num_put_type>(__loc);
  179       else
  180         _M_num_put = 0;
  181
  182       if (__builtin_expect(has_facet<__num_get_type>(__loc), true))
  183         _M_num_get = &use_facet<__num_get_type>(__loc);
  184       else
  185         _M_num_get = 0;
  186     }
  • __builtin_expect()が分からない(gccの方でマクロを使って定義されているみたい)けど、ロケールがファセットをサポートしているならファセットをキャッシュしているのだろう。ここはスルーする。

ios_base

ios_baseクラスのソースを見てみる。このクラスのソースは別のディレクトリにあった。まずはコンストラクタ。

libstdc++-v3/src/ios.cc

  115   ios_base::ios_base()
  116   : _M_precision(), _M_width(), _M_flags(), _M_exception(),
  117   _M_streambuf_state(), _M_callbacks(0), _M_word_zero(),
  118   _M_word_size(_S_local_word_size), _M_word(_M_local_word), _M_ios_locale()
  119   {
  120     // Do nothing: basic_ios::init() does it.
  121     // NB: _M_callbacks and _M_word must be zero for non-initialized
  122     // ios_base to go through ~ios_base gracefully.
  123   }
  • うーん、基本的には何もしていないに等しいと思われる。
  • ただし、最後の_M_ios_localeはlocaleクラスのインスタンスなので、localeクラスは見る必要がありそう。

あとはさっき呼ばれていたios_base::_M_init()のソースを確認する必要がある。別ファイル。

libstdc++-v3/src/ios_locale.cc

   40   // Called only by basic_ios<>::init.
   41   void
   42   ios_base::_M_init()
   43   {
   44     // NB: May be called more than once
   45     _M_precision = 6;
   46     _M_width = 0;
   47     _M_flags = skipws | dec;
   48     _M_ios_locale = locale();
   49   }
  • む、ここでも_M_ios_localeを初期化している。

locale

ここでlocaleクラスのコンストラクタを見ておく。

libstdc++-v3/src/locale_init.cc

  100   locale::locale() throw() : _M_impl(0)
  101   {
  102     _S_initialize();
  103     __gnu_cxx::lock sentry(__gnu_internal::locale_mutex);
  104     _S_global->_M_add_reference();
  105     _M_impl = _S_global;
  106   }
  • あ、なんかロックしてる!!これが悪いのか!?
  • _S_globalというのが「Current global locale」を表しているようで、これはstaticなメンバ変数。これへのアクセスの際に排他制御が必要なんだな。

同ファイルにある_S_initialize()も見ておく。

  147   void__
  148   locale::_S_initialize()
  149   {
  150 #ifdef __GTHREADS
  151     if (__gthread_active_p())
  152       __gthread_once(&_S_once, _S_initialize_once);
  153 #endif
  154     if (!_S_classic)
  155       _S_initialize_once();
  156   }
  • うーん。__GTHREADSが定義されているのかは不明。

_S_initialize_once()は

  137   void
  138   locale::_S_initialize_once()
  139   {
  140     // 2 references.
  141     // One reference for _S_classic, one for _S_global
  142     _S_classic = new (&c_locale_impl) _Impl(2);
  143     _S_global = _S_classic;
  144     new (&c_locale) locale(_S_classic);
  145   }
  • えー、ここでlocaleをnewするのか。

きりがないのでここで終わり。

わかったこと

  • basic_ostringstreamのコンストラクタを呼ぶと、色々な処理が動く。
  • localeオブジェクトの構築時にロックをしている。これがボトルネックになっている可能性あり。
  • そのlocaleオブジェクトを2度構築しているようだ。益々怪しい。
  • コンストラクタの中で色々やらないで欲しい。深い継承も罪だ。