マルチスレッドセーフになったrtlog-cppを使う
リアルタイムログ処理は面倒くさい
一般的なデスクトップアプリケーションでエラーが発生した場合、それをコンソールやGUI上に何らかのかたちでユーザーにレポートすることになるのだけど、オーディオプラグインやプラグインホストのようなリアルタイムオーディオのアプリケーションで、リアルタイム処理中に問題が発生した場合、そういったログ出力の処理をリアルタイム処理で行うのはほぼ不可能だ。GUI処理はもちろんリアルタイムセーフではないし、標準出力へのアクセスもI/Oを伴うのでリアルタイムセーフではない。何ならログ出力のために文字列をsprintf()やstd::format()でフォーマットする処理もアロケーションを伴うのでリアルタイムセーフではない。
リアルタイム処理の中でログ出力を可能にするには、ログを出力したいリアルタイムスレッド上で「何らかの方法で」ログ文字列を加工して、その文字列バッファを非リアルタイムのログ出力担当スレッドに伝達する、というやり方をとるのが一般解となるだろう。これを実現するためには、リアルタイムセーフなメッセージング機構（FIFOキューなど）が必要だ。「メッセージを伝達する」だけの処理でも、リアルタイムセーフに実装されている必要がある。たとえばjuce::MessageManager::callAsync()はリアルタイムセーフではないので、ここでは使えないし、Androidで実装する場合もきちんとnon-blockingでメッセージサイズをPIPE_BUF未満に抑えて出力する必要がある（といった話を以前に書いた）。
文字列加工も、決して不可能というわけではなくて、事前にメモリ確保されている領域にメモリアロケーション不要なかたちで数値等をフォーマットできるsprintf()が無ければならない。メッセージを受け取る側も、単に文字列を受信するイベントハンドラー関数（やラムダ式）を書くだけじゃなくて、独自にログ受信スレッドを立てて、ログクライアントスレッドから届いたメッセージを受信してハンドラー関数する必要がある。
rtlog-cppを使う
たかだかログを出力したいだけなのにずいぶんと面倒なことだ。幸いなことに、こういったログ処理をみんなが自前で実装しなくても、大体の部分を肩代わりしてくれるrtlog-cppというライブラリがある:
2023年のADCx SFというカンファレンスで開発者が詳しく説明している動画もある:
これを使えば、リアルタイムログ処理で面倒な部分はほぼ解決できる。公式READMEの使い方を見れば、使い方もざっくり伝わると思う。クライアント側はrtlog::Loggerのインスタンスを生成して（このときデータコンテキスト型などを渡すことになる）、log()を呼び出すだけだ（ExampleLogData型の中にアプリケーション固有のlog levelやエラーコードなどを含める）:
using RealtimeLogger = rtlog::Logger<ExampleLogData, MAX_NUM_LOG_MESSAGES, MAX_LOG_MESSAGE_LENGTH, gSequenceNumber>;
RealtimeLogger logger;
void SomeRealtimeCallback()
{
logger.Log({ExampleLogLevel::Debug, ExampleLogRegion::Audio}, "Hello, world! %i", 42);
// using RTSAN_USE_LIBFMT
logger.Log({ExampleLogData::Debug, ExampleLogRegion::Audio, FMT_STRING("Hello, world! {}", 42);
}
rtlog::Logger::Log()はva_argsも処理できるので、sprintf()のように使うこともできる（これはrtlog自身がやっているのではなくて、nothings/stbというライブラリに含まれるstb_sprintf()というリアルタイムセーフなフォーマット関数を利用しているだけだ）。ちょっと前までのバージョンでは自分のログ関数がva_argsを保持していると使える関数が無かったのだけど、Logv()という関数を作ってプルリクを取り込んでもらったので、最新のバージョンなら使えるはずだ。
ログを受信するサーバー側も簡単に準備できる:
static auto PrintMessage = [](const ExampleLogData& data, size_t sequenceNumber, const char* fstring, ...) __attribute__ ((format (printf, 4, 5)))
{
// 可変長引数を処理してprintfやGUI表示に投げる
};
...
rtlog::LogProcessingThread thread(logger, PrintMessage, std::chrono::milliseconds(10));
こっちは非リアルタイムスレッドなので、特別に難しいことをやっているわけではない。rtlog::LogProcessingThreadはもちろんStop()を呼び出せば止められる。
Single Producer Single Consumerの壁を破る
こんな感じでrtlog-cppは便利なので、自分が最近作っているプラグインホストのライブラリでも活用していたのだけど、ひとつ困ったことに気付いた。rtlog-cppは内部的にcameron314/readerwriterqueueというリアルタイムセーフなFIFO実装を使っていた（いる）のだけど、このFIFOは複数スレッドからの読み書きに対応していないのだ。ログ出力を要求するスレッドは1つ、要求を受け取って実際に処理するスレッドも1つということになる。メッセージキューの実装方式でいえばsingle producer, single consumer（SPSC）なキューということになる。これでは複数のスレッドから呼び出せないことになる。
大抵の場合は1つのロガーでリアルタイムオーディオスレッドからもI/OやGUIのスレッドからもログを出力したいだろうし、複数のCPUコアを使って複数のリアルタイムオーディオ処理が動いている場合も、別々のLoggerインスタンスが必要ということになってしまう。しかもSPSCなので、Loggerのインスタンスの数だけサーバースレッドが生成されることになってしまう。リアルタイムセーフである必要もないのに、これは無駄と言わざるを得ない。
複数のログクライアントと単一のログサーバーは、multi producer, single consumer（MPSC）なキューを使うことで実現できる。readerwriterqueueの開発者はconcurrentqueueというmulti producer, multi consumer（MPMC）なキュー実装も公開していて、これを使えば解決するように見えた（見える）ので、readerwriterqueueをconcurrentqueueに置き換えた実装を作ってみた（ここではリンクしない）。結論からいえば「多分解決する」なのだけど、MPMCなキューはウェイトフリーでは実装できないというのが伝統的な理解で、rtlog-cppの開発者もconcurrentqueueはウェイトフリーではないという想定で使っておらず、concurrentqueueが本当にウェイトフリーで動作するのかきちんと確認できない、というので、なるほどじゃあ使えないな…となった（第一幕）。
ただ実際には、MPSCの実装は難しいけど可能ではあると、ADC 2019であったReal-Time 101 (Part II)というセッションで言われている:
そういうわけで、とりあえずこのセッションで講演者が開発して公開しているfarbotというライブラリに含まれるMPSCキューの実装であれば、複数クライアントからのログ出力を問題なく捌けるのではないかと思って実装してみた（第二幕、これもリンクしない）。それでrtlog-cppの作者に投げてみたら、筋としては良いのだけど、FIFO実装にはそれぞれ長所・短所があるようなので、それらを切り替えられるようにしたくない?という話になって、最終的に新しくFIFO実装型のテンプレート引数が追加されることになった:
using RealtimeLogger = rtlog::Logger<LogContext, MAX_NUM_LOG_MESSAGES, MAX_LOG_MESSAGE_LENGTH, log_serial, rtlog::MultiRealtimeWriterQueueType>;
今はreaderwriterqueue実装がデフォルト引数で渡されているので、後方互換性あるのだけど、farbotを使ったMPSC版は単なるサンプル扱いになっていて、たぶん最初からMPSC版を使いたいユーザーが少なからず出てくるんじゃないか?と相談して、最終的にreaderwriterqueue版をfarbot版で置き換えよう、という話になった。これが（現在取り込み予定の実装で）問題なければ、近い内にmainブランチに取り込まれる予定だ。
カスタムFIFOキュー実装型をconstraintsとstatic_assert()で検証する
ここからは、rtlog-cppを使うだけならほぼ読む必要のない、ソーセージの中身の話をしていく。
新しいAPIではカスタムFIFOキューを利用できるようになっている。concurrentqueueのほうが高速であれば（その可能性は割と高そうだ）、farbot実装をconcurrentqueue実装に書き換えることもこれなら簡単にできる。
今回のカスタムFIFOキュー型は特定のクラスを継承する仕組みにはなっていない。ではどういう型なら渡せるかというと、テンプレート引数で指定された型の中でtry_enqueue()やtry_dequeue()、value_typeといったメンバーが存在していることを、C++ constraintsとstatic assertionでチェックしている。割と黒魔術感があるのでコードからtry_enqueue()のチェックの部分を抜粋して説明しよう。static_assert()で使われるチェック関数の定義はこんな感じだ（内容は後で説明するので読み流しても問題ない）:
namespace detail {
template <typename T, typename = void>
struct has_try_enqueue_by_move : std::false_type {};
template <typename T>
struct has_try_enqueue_by_move<
T, std::void_t<decltype(std::declval<T>().try_enqueue(
std::declval<typename T::value_type &&>()))>> : std::true_type {};
template <typename T>
inline constexpr bool has_try_enqueue_by_move_v =
has_try_enqueue_by_move<T>::value;
template <typename T, typename = void>
struct has_try_enqueue_by_value : std::false_type {};
template <typename T>
struct has_try_enqueue_by_value<
T, std::void_t<decltype(std::declval<T>().try_enqueue(
std::declval<typename T::value_type const &>()))>> : std::true_type {
};
template <typename T>
inline constexpr bool has_try_enqueue_by_value_v =
has_try_enqueue_by_value<T>::value;
template <typename T>
inline constexpr bool has_try_enqueue_v =
has_try_enqueue_by_move_v<T> || has_try_enqueue_by_value_v<T>;
(...)
} // namespace detail
これらの制約がLoggerの新しいテンプレート引数QTypeに適用される。Loggerの型定義の中で一連のstatic_assert()がこれを確認しているので、要件を満たさない型はコンパイル時に弾かれることになる（もちろんstatic assertが無くてもテンプレートの適用時にコンパイルエラーになる可能性は高い）:
template <typename LogData, size_t MaxNumMessages, size_t MaxMessageLength,
std::atomic<std::size_t> &SequenceNumber,
template <typename> class QType = rtlog_SPSC>
class Logger {
public:
using InternalLogData = detail::BasicLogData<LogData, MaxMessageLength>;
using InternalQType = QType<InternalLogData>;
static_assert(
detail::has_int_constructor_v<InternalQType>,
"QType must have a constructor that takes an int - `QType(int)`");
static_assert(detail::has_value_type_v<InternalQType>,
"QType must have a value_type - `using value_type = T;`");
static_assert(detail::has_try_enqueue_v<InternalQType>,
"QType must have a try_enqueue method - `bool try_enqueue(T "
"&&item)` and/or `bool try_enqueue(const T &item)`");
static_assert(
detail::has_try_dequeue_v<InternalQType>,
"QType must have a try_dequeue method - `bool try_dequeue(T &item)`");
コンパイラーがこのLoggerクラスの型定義のセマンティック分析に入ると、static_assert()の内容が評価されて、次の3点がチェックされる:
- 要件を満たすフィールド
value_typeを持っているか（detail::has_value_type_v()） - 要件を満たす関数
try_enqueue()を持っているか（detail::has_try_enqueue_v()） - 要件を満たす関数
try_dequeue()を持っているか（detail::has_try_dequeue_v()）
これらの定義は先に引用したdetail名前空間のほうにある（今回はtry_enqueue()の内容だけでもすでに長すぎたので、それしか引用していない）。detail内の定義そのものを読むより、これらのstatic_assert()のエラーメッセージの内容を読んだほうが、意味がわかりやすいだろう（rtlog-cppの開発者がそのようにコードを書いている）:
-
has_int_constructor_v()は、QType型にint型のメッセージサイズを受け取るコンストラクターが存在することを確認する -
has_value_type_v()は、QType型にvalue_typeフィールドが存在することを確認する -
has_try_enqueue_v()は、QType型にtry_enqueue(T &&)関数またはtry_enqueue(const T &)関数が存在することを確認する -
has_try_dequeue_v()は、QType型にtry_dequeue(T &)が存在することを確認する
型情報のチェックに関しては、日本語でも詳しい記事がいくつかあるので、そちらを参考にされたい:
try_enqueue()やtry_dequeue()といった関数名になっているのは、最初の実装で使われていたreaderwriterqueueがそうなっていたからなので、その他のライブラリを使いたければ簡単なラッパー関数を作る必要がある。たとえばfarbotではpushとpopだったので、try_enqueue()やtry_dequeue()としてこれらを呼び出すラッパーが使われている（筆者がfarbot実装として開発者に送ったコードがほぼこれだ）。未確認だけど、concurrentqueueを使いたければ、readerwriterqueueと同じでラッパーは不要だろう（これもtry_enqueue()とtry_dequeue()を持っている）。
ただ、世にある多くのFIFO実装は、特にMPSCのユースケースではロックフリー・ウェイトフリーにはなっていないので注意が必要だ。たとえばTracktion/chocに含まれるFIFO実装はこの用途では使えない。
まとめ
rtlog-cppはリアルタイムセーフなログのしくみを提供してくれる便利なライブラリで、これまではsingle producer single consumerのシナリオでしか使えなかったのだけど、multi producer single consumerのマルチスレッドなシナリオでも使えるようになったし、制約を満たせるなら任意のFIFOキュー実装を使えるようにもなって、活用できる幅が広がったので、多分いま手元にリアルタイムオーディオアプリケーションがあってログの仕組みがおろそかになっていたら、ぜひ使ってみるといいと思う。
自分の利用例も一応あるので、参考までにリンクしておこう: https://github.com/atsushieno/uapmd/blob/main/src/remidy/Logger.cpp
Discussion