ロギングとエンコーディング

Claudia

ゴーストの足跡を書き残すロギングと、文字化けから守るエンコーディング――どちらも地味で、つい見過ごされがちですの……。

Anthony

ログがゴーストごとのファイルへ書き分けられるのも、その地味なお働きのおかげでございますね。

Claudia

そのとおり、欠かせない裏方ですわ！ 振り分けの規則から OS 別の文字コード変換まで、働きぶりをとくとご覧あそばせ！

この章では、ランタイムのロギングとエンコーディングを扱う。利用者から見た @pasta_log と @enc の使い方は @pasta_log と @enc が、[logging] の設定は pasta.toml リファレンス が正である。

目的と責務

ロギングは、Rust 側の tracing のイベントと Lua 側の @pasta_log の呼び出しを、ゴーストごとのログファイルへ書き出す。エンコーディングは、UTF-8 とシステムのコードページの間の文字列変換を提供する。

この章が責務を持つのは次の事項である。

• tracing の購読者（subscriber）の初期化と、ログフィルタの決め方・差し替え
• インスタンスロガー（PastaLogger）の作成と、ログファイルの場所・書き込み方
• グローバルなロガーの登録簿（GlobalLoggerRegistry）と、スレッドごとの設置パスによるログの振り分け
• @pasta_log の実装（値の文字列化・呼び出し元の取得・イベントの発行）
• crates/pasta_lua/src/encoding/ の OS 別の変換の実装と、@enc の実装
• SHIORI 境界で受け渡す文字列の文字コードの一覧

次の事項は他の章が権威を持ち、この章では再記述しない。

• ローダの段階構成の中での段階 1.5 の位置と、失敗を継続扱いにする規則は ローダ自己展開とモジュール解決 で扱う。
• @pasta_log・@enc を package.loaded に登録する順序は ランタイム実行モデル で扱う。
• loadu・load・request の各入口で文字列をどう読み、失敗をどう応答にするかは SHIORI 層 で扱う。

構成要素

ロギング

ロガーを作って登録する側は、crates/pasta_shiori/src/shiori.rs の PastaShiori::load（段階 1）と crates/pasta_lua/src/loader/mod.rs の PastaLoader::create_and_register_logger（段階 1.5）である。

tracing のイベント（Rust の info! など、@pasta_log の呼び出し）
   │
   ▼
Registry（プロセスに 1 つ）
 └ fmt レイヤ（ANSI 色なし・target とレベルを出力）
     │  レイヤ単位のフィルタ: RegistryFilter（文脈で選んだ項目の EnvFilter で判定）
     ▼
GlobalLoggerRegistry::make_writer（イベントごと）
     │  CURRENT_LOAD_DIR（スレッドローカル）で文脈（設置パス）を得る
     │  resolve: Mutex<HashMap<設置パス, 項目>> を引く（振り分けの 3 規則）
     ▼
RoutingWriter ── 決まった → PastaLogger::write → RollingFileAppender → ログファイル
               └ 無い     → 何もせず書いたことにする（捨てる）

エンコーディング

どちらの OS の実装を使うかは #[cfg(windows)] でビルド時に決まる。Encoder と Encoding はクレートのルートから再エクスポートされる。Encoding::OEM（CP_OEMCP）を使うのはテストだけである。

pasta_shiori は FFI の文字列を読むための変換を、crates/pasta_shiori/src/util/hglobal/ に別に持つ（enc.rs と windows_api.rs）。crates/pasta_lua/src/encoding/windows.rs と同じく local-encoding-rs に由来する実装で、crates/pasta_lua/src/encoding/ は使わない。

処理とデータの流れ

ロガーの 2 段階の初期化

SHIORI として読み込まれるとき、ロガーは 2 段階で用意される。段階の番号はコードのコメントとログに合わせている。

段階 1（PastaShiori::load。PastaLoader を呼ぶ前）
 1. 再読み込みなら、前の設置パスのロガーの登録を外す
 2. PastaLogger::new(設置パス, None)      … 既定の file_path で作る。失敗しても続行
    成功 → GlobalLoggerRegistry に 設置パス → ロガー で登録
 3. init_tracing()
      購読者の設置は try_init。プロセスで最初の 1 回だけ成功する。量の設定は持たない
 4. LoadDirGuard::new(設置パス)            … 以後このスレッドのログは設置パスのロガーへ

段階 1.5（PastaLoader::load_with_config。pasta.toml を読んだ直後）
 5. config.logging()                       … [logging] が無い・型が合わない → None
    update_tracing_filter(設置パス, [logging] または既定) でその項目の量の設定を作り直す
 6. PastaLogger::new(設置パス, [logging] または既定)
    成功 → 同じ設置パスで登録し直す（段階 1 のロガーを置き換える）
    失敗 → PastaLogger::new(設置パス, None) で既定のログファイルのロガーを作り直す
           成功 → 同じ設置パスで登録し、その後で warn を 1 件出す
                  （不正と判断した file_path・切り替え先 profile/pasta/logs/pasta.log・失敗の理由）
           失敗 → warn「logging disabled」を出し、ロガー無しで続行（登録は変えない）
 7. 登録したロガーの Arc を PastaLuaRuntime へ渡す（段階 6 で構造体に保持）

• 段階 1 は、段階 1.5 より前（設定の読み込みを含む）のログもファイルに残すためにある。段階 1 のロガーは常に既定の場所 profile/pasta/logs/pasta.log に作られるため、file_path を変えたゴーストでも、段階 1.5 までのログはこのファイルに書かれる。
• 段階 1.5 で登録を置き換えると、段階 1 のロガーへの参照は登録簿から消え、最後の参照が落ちた時点で破棄される（破棄時にフラッシュする）。置き換えられたロガーの破棄は、登録簿のロックを放してから行う。
• 6 の切り替えは、file_path が判定（後述の validate_path）で不正なときも、ディレクトリを作れないなど別の理由で失敗したときも、理由を区別せずに行う。起動は続き、level・filter は 5 で反映済みである。warn は既定のロガーを登録した後に出すため、SHIORI 経由でも PastaLoader を直接使う組み込みでも、同じ文言で既定のログファイルに書かれる。SHIORI 経由では、段階 1 の既定のロガーを同じファイルの新しい既定のロガーで置き換えることになる。file_path を直して再読み込みすれば、段階 1.5 が直したパスのロガーに置き換える。
• PastaLoader を SHIORI 以外から直接呼ぶ場合（テストなど）は段階 1 が無い。購読者を設置するかどうかは呼び出し側が決める。

ロガーの登録を外すのは PastaShiori の release_runtime（Drop と再読み込みの分岐から呼ばれる）で、ランタイムを破棄した後の最後の手順である。PastaLuaRuntime も同じロガーの Arc を持つが、ランタイムを先に破棄するため、登録を外した時点で最後の参照が落ち、フラッシュしてログファイルが閉じる。ランタイムの破棄（永続化データの保存）で出たログは、閉じる前のファイルに書かれる（SHIORI 層）。

ログフィルタ

フィルタは tracing-subscriber の EnvFilter で、build_filter が次の順に作る。

1. 環境変数 PASTA_LOG が設定されていて解釈できれば、それを使う（未設定と解釈できない値は次へ進む）。
2. LoggingConfig::to_filter_directive の文字列（filter があればそれ、無ければ level。level の既定は "info"）を解釈できれば、それを使う。
3. どちらも使えなければ、標準エラーに警告を出して "info" にする。

フィルタは登録簿の項目（設置パス）ごとに 1 つある。項目を作ったときは既定の設定でこの順をたどり、段階 1.5 は毎回、[logging] の設定（無ければ既定の設定）で作り直したフィルタをその項目に入れる。再読み込みで [logging] を消すと、フィルタは既定に戻る。あるゴーストの [logging] は、そのゴーストのログだけに効く。

購読者のフィルタ RegistryFilter は、イベントごとに下の振り分けの規則と同じ決まりで項目を選び、その項目のフィルタで判定する。選べなければ出さない。判定の決まりの詳細と、スパンの中身で絞る指定が効かないことは SHIORI 層 が書く。

ログ 1 件がファイルに届くまで

1. イベントがフィルタを通ると、fmt レイヤが 1 行に整形する（時刻・レベル・target・メッセージ・フィールド。ANSI の色付けはしない）。
2. fmt レイヤはイベントごとに GlobalLoggerRegistry::make_writer を呼ぶ。make_writer はそのスレッドの CURRENT_LOAD_DIR を読み、resolve で書き込み先のロガーを決めて（下の 3 規則）、RoutingWriter を返す。
3. RoutingWriter は、ロガーがあれば PastaLogger::write へ渡し、無ければ書いたバイト数を返して捨てる。捨てるときもエラーや panic は起こさない。
4. PastaLogger::write は、ミューテックスで守った RollingFileAppender に、呼び出したスレッドのまま書く。書き込み用のスレッドは作らない（下の「ログファイル」）。

振り分けの規則

resolve は、スレッドの文脈（CURRENT_LOAD_DIR の設置パス）と登録簿から、次の 3 規則で書き込み先を決める。

1. 文脈がある → その設置パスのロガーへ書く。その設置パスに登録が無ければ捨てる（他のロガーへは流さない）。
2. 文脈が無く、登録されたロガーがちょうど 1 つ → そのロガーへ書く。
3. それ以外（文脈が無く、登録が 0 個または 2 個以上）→ 捨てる。

規則 1 で他のロガーへ流さないのは、あるゴーストのログを別のゴーストのログファイルに書かないためである。規則 3 で 2 個以上のときに捨てるのも、どのゴーストに属するかを決められないためである。登録簿のミューテックスを持つのは、表を引いて Arc を複製する間だけである。register が置き換えた古いロガーと unregister が外したロガーの破棄（フラッシュ）は、ロックを放してから行う。

CURRENT_LOAD_DIR を設定するのは LoadDirGuard で、ガードの破棄で元の値に戻す（入れ子にできる）。文脈を張るのは次の箇所である。

文脈を持たないのは、ホストのスレッド（旧来の入口の request・unload・load_entry、DllMain の detach の後始末）と、デバッグバックエンドのスレッドである。これらのログは規則 2 で届く。

残るログと捨てるログ

旧来の入口だけを使うホスト（SSP）では、登録簿のロガーは 0 個か 1 個である。そのため、ロガーが登録されている間に出たログは、どのスレッドで出たものでもログファイルに残る。捨てるのはロガーが登録されていないときのログだけである。版 3 のインスタンスが並ぶと、文脈の無いログは規則 3 で捨てる。

ログを残すために、SHIORI の応答・応答までの待ち時間の上限・unload の戻り値は変えない。FFI 入口のスレッドが登録簿のミューテックスを取るのは、ログのイベントが全部の項目の量の最大（max_level_hint）を通って、量の判定と書き込み先を引くときだけで、mailbox の送信の経路には触れない。

ログファイル

PastaLogger::new(基準ディレクトリ, 設定) は次の順に進む。

1. 基準ディレクトリ.join(file_path) をログファイルのパスにする（file_path の既定は "profile/pasta/logs/pasta.log"）。

2. validate_path で検査する。満たさなければ PermissionDenied のエラーにする（段階 1.5 はこのエラーで既定のログファイルへ切り替える）。条件は次のすべてである。

   • パスが基準ディレクトリの下にある（strip_prefix で外れるもの、たとえば絶対パスはここで不正になる）。
   • 基準ディレクトリからの相対パスの最初の要素（Path::components の最初）が、ちょうど profile である（大文字小文字を区別する）。
   • profile の後に 1 つ以上の要素が続く。
   • 相対パスが文字列として .. を含まない。

   profile/pasta/logs/pasta.log・profile/x.log は正しい。profile.log・profiles/x.log のように文字列として profile で始まっても profile/ ディレクトリの下にないもの、profile だけのもの、../x.log・profile/../x.log・logs/x.log は不正である。

3. 親ディレクトリを作る（create_dir_all）。

4. RollingFileAppender を Rotation::NEVER とファイル名そのものを接頭辞にして作る。日付の接尾辞は付かず、ファイル名は file_path のとおりになる。既存のファイルには追記する。

5. RollingFileAppender をミューテックスで包んで PastaLogger が保持する。

PastaLogger の Drop はフラッシュする。tracing_appender::non_blocking のワーカースレッドは使わない。ワーカースレッドは WorkerGuard を破棄しても join されないので、ホストが unload の直後に pasta.dll を解放すると、外れたコードの上で動き続けて落ちる。ログファイルは日付で分けず、古いファイルの削除もしない。

@pasta_log の呼び出し

register は _VERSION・_DESCRIPTION と、trace・debug・info・warn・error の 5 関数を持つ表を作る。5 関数はマクロ log_fn! が生成し、呼ぶ tracing のマクロ（レベル）だけが違う。1 回の呼び出しは次のとおりに進む。

log.info(値)
 1. value_to_string(値)
      nil → ""、真偽値・整数・数値 → 文字列化、文字列 → そのまま（不正な UTF-8 は置換文字）
      表   → table_to_string（下記）
      その他（関数・ユーザーデータ・コルーチン） → Lua の tostring
 2. get_caller_info: inspect_stack(1) で直接の呼び出し元の
      short_src・現在行（取れなければ 0）・関数名（取れなければ ""）を得る
 3. tracing::info!(lua_source, lua_line, lua_fn, "{}", 文字列)
      target は Rust のモジュールパス pasta_lua::runtime::log

table_to_string は、表を次の順に扱う。

1. pairs で数えたキーと値の組が 1000（MAX_TABLE_ELEMENTS）を超えたら <table: 要素数 elements> を返す。
2. セーブと共有の変換 persistence::lua_value_to_toml_strict で toml::Value にする。深さの上限は 10（MAX_NESTING_DEPTH。根の表を 1 段目と数える）で、変換はたどっている祖先の表の列で循環参照を見つける。上限を超える表、循環参照、TOML で書けない値（関数・配列の要素と名前のキーが混ざった表・文字列でないキーなど）が 1 つでもあれば変換は失敗し、tostring の結果を返す。tostring も失敗したら "<unconvertible value>" を返す。変換は上限の段で止まる再帰なので、深く入れ子にした表や循環参照のある表でもホストのスタックは溢れない。
3. 変換できた値を write_inline で 1 行に書く。キーのある表は { k1 = v1, k2 = v2 }（キーの昇順）、配列は [v1, v2]、空の表は {}、空の配列は [] にする。キーは A-Za-z0-9_- だけでできた空でないものはそのまま、それ以外は基本文字列にする。文字列はいつも 1 行の基本文字列 "…" で書き、\・"・\b・\t・\n・\f・\r をエスケープし、そのほかの制御文字（U+0000〜U+001F・U+007F）を \uXXXX にする。toml の Display は改行を含む文字列を複数行の文字列にするため、文字列だけ自前で書く。整数・浮動小数点数・真偽値は toml::Value の Display（1.0・nan・inf など）に任せる。

呼び出し元の段数 1 は、crates/pasta_lua/tests/log/stack_level_test.rs で確かめている（段数 0 は Rust の関数自身になる）。レベル関数は値の変換で Lua のエラーを出さず、常に何も返さずに戻る。

@enc の変換

どちらも成功時は (結果, nil) を、失敗時は (nil, メッセージ) を返し、失敗時は warn ログを出す。Lua の文字列を作れないなど mlua 自体のエラーだけが Lua のエラーになる。

OS 別の変換の実装

Windows の実装は、Encoding を GetACP（ANSI）か GetOEMCP（OEM）が返す実際のコードページに対応させる。コードページはシステムのロケール設定で決まる。

• to_string（コードページ → UTF-8）: MultiByteToWideChar を MB_ERR_INVALID_CHARS 付きで呼び、UTF-16 を String::from_utf16 で UTF-8 にする。コードページとして不正なバイト列はエラーになる。
• to_bytes（UTF-8 → コードページ）: 文字列を UTF-16 にしてから WideCharToMultiByte を WC_COMPOSITECHECK 付きで呼ぶ。代替文字を指定せず、代替文字を使ったかどうかを受け取り、使っていたら（コードページで表せない文字があったら）InvalidInput のエラーにする。ただし、コードページが UTF-8（65001）のときは API を呼ばずに UTF-8 のバイト列をそのまま返す（65001 では WC_COMPOSITECHECK と代替文字の受け取りが許されないため）。
• どちらの API も、1 回目で必要な長さを問い合わせ、確保したバッファに 2 回目で書かせる。入力の長さは buffer_len_to_i32 で i32 に収まるか確かめ、2 GiB 以上はエラーにする（as で変換すると負の値になり、API が入力を NUL 終端として読み進めるため）。空の入力は API を呼ばずに空を返す。

Windows 以外の実装は、to_bytes で UTF-8 のバイト列をそのまま返し、to_string で String::from_utf8 が通ればそのまま返す（不正な UTF-8 は InvalidData のエラー）。

SHIORI 境界での文字コード

ホストと pasta.dll の間で受け渡す文字列の文字コードは次のとおりである。読み方と失敗時の応答の詳細は SHIORI 層 で扱う。

VM の中の文字列（DSL から生成したコード、scripts/ の Lua ソース、リクエストの表）は UTF-8 である。ランタイムが Lua 側へ渡すファイルパスも UTF-8 のままで、Lua の標準入出力関数（io.open など）に ANSI のパスを渡す必要がある場合は、スクリプトが @enc で変換する。モジュールの検索はこの変換を要しない（ローダ自己展開とモジュール解決 の searcher）。

境界の受け渡し

不変条件と制約

• tracing の購読者はプロセスに 1 つで、最初の init_tracing だけが設置する。先に別の購読者が設置されていた場合、pasta の購読者は設置されず、update_tracing_filter は項目のフィルタを替えるだけで、出力には効かない。
• フィルタは登録簿の項目（設置パス）ごとに持ち、あるゴーストの [logging] はそのゴーストのログだけに効く。スパンの中身で絞る指定は効かず、tracing::enabled! はディレクトリごとの断りを映さない（SHIORI 層）。
• ログの振り分け先は、イベントを出したスレッドの CURRENT_LOAD_DIR と登録簿の中身だけで決まる（振り分けの 3 規則）。文脈のあるスレッドのログを別の設置パスのロガーへ書くことは無い。捨てるときもエラーにならない。
• 登録簿のキーは設置パスの PathBuf で、正規化せずに完全一致で比べる。段階 1 と段階 1.5 は同じ設置パスの値を使う。
• ログファイルのパスは、設置パスからの相対パスが profile/ ディレクトリの下にあり .. を含まないものに限られる。満たさない file_path は既定のログファイルに切り替わる。ファイルは追記で、ローテーションも切り詰めもしない。
• 書き込みは呼び出したスレッドで同期に行い、行を捨てない。ロガーはスレッドを持たないので、unload の後に pasta.dll のコードの上で動くロガーのスレッドは残らない。
• @pasta_log と @enc は、不正な入力で Lua のエラーを出さない。@pasta_log は必ず文字列にして記録し、@enc は (nil, メッセージ) を返す。
• 文字コードの変換をするのは Windows だけである。Windows 以外では Encoding の両方の種類が UTF-8 のまま通す。
• @enc の結果は、変換を呼んだ時点のシステムの ANSI コードページに依存する。

ソースの所在

• crates/pasta_lua/src/logging/
• crates/pasta_lua/src/encoding/
• crates/pasta_lua/src/runtime/log.rs
• crates/pasta_lua/src/runtime/enc.rs

テストは crates/pasta_lua/tests/log/・crates/pasta_lua/tests/runtime/encoding_test.rs にある。

本文で参照した、他の章の範囲にあるファイルは次のとおりである。[logging] の型は crates/pasta_lua/src/loader/config/sections.rs、段階 1.5 は crates/pasta_lua/src/loader/mod.rs、段階 1 とガード・release_runtime は crates/pasta_shiori/src/shiori.rs、アクタースレッドの入口のガードは crates/pasta_shiori/src/actor/thread.rs、load_impl のガードは crates/pasta_shiori/src/windows.rs、SHIORI 境界の変換は crates/pasta_shiori/src/util/hglobal/ にある。

経緯

• lua-logging — @pasta_log（Lua からのロギング）
• logger-configuration — [logging] によるフィルタの設定と差し替え
• load-error-logging — 段階 1 のロガーによる起動時のログの記録と、固定のファイル名
• pasta-toml-logging-consistency — 文脈の無いログを唯一のロガーへ書く振り分け、不正な file_path の既定ファイルへのフォールバック、rotation_days の撤去

Claudia

これで内部設計の旅はひとめぐり。あとはあなたの手で、pasta をもっと良くしてくださいまし。目立たぬ働きこそ、本当に大切なものですわ――わたくしのように、ね。

Anthony

……お嬢様が、目立たぬ側にお立ちになると？

Claudia

そこまで目を丸くすることはございませんでしょう！