App Log 1.2: 本家とコピーの乖離を解消し、監査ログの土台として使えるようにする

[pm-hiroshi]

背景

wp10-sql-runner の監査ログ（caitsith2022-main#1748）を実装する過程で、App Log 側に 2 種類の問題が見つかりました。

1. 本家と各 PJT のコピーが双方向に乖離している（しかもバージョン番号が同じ）
2. 監査ログの土台として使うには機能が足りない

SQL Runner の監査ログを「監査ログです」と顧客に申告すると、その時点で顧客側の保持ルールの対象になります。その前提として App Log 側の対応が要る、というのがこの Issue の動機です。

バージョンは 1.2 とします。

---

1. 本家と caitsith のコピーが乖離している

caitsith2022-main の src/wp-content/plugins/app-log/ と、このリポジトリの内容を比較しました。どちらも Version: 1.1.4 を名乗っていますが、中身が違います。

本家にあって、caitsith のコピーに無いもの

項目	場所
app_log_log_lifetime フィルタ（保持期間を上書きできる）	admin/aplg-settings.php
app_log_date_format フィルタ（ログファイル名の日付書式）	classes/class-aplg-logger.php
format_date_by_wp_version()（WP 5.3 以降は wp_date() を使う）	classes/class-aplg-logger.php

caitsith のコピーにあって、本家に無いもの

項目	内容
書き込みが file_put_contents( $log_file, $message, FILE_APPEND | LOCK_EX )	本家は fopen/fwrite/fclose

なぜ問題か

• 保持期間を変えられないのはコピー側だけでした。本家には既にフィルタがあります。つまり「保持期間を変更できるようにする」は新規開発ではなく同期の問題です
• バージョン番号でコピーを識別できません。 両方 1.1.4 なので、どの PJT がどの実装を持っているかは差分を取らないと分かりません
• 各 PJT が個別に直した改善（上記の書き込み方式）が本家に還らないため、次に vendoring した PJT がまた同じ問題を踏みます

やること

• 本家 ⇄ caitsith の双方向マージ（本家を正とし、コピー側の改善を取り込む）
• 他の PJT にも vendoring されたコピーが無いか棚卸しし、同様に差分を取る
• バージョンを 1.2 に上げる。 以後、コピーを配る時はバージョンを上げてから配る運用にする

---

2. 監査ログの土台として足りないもの（本家にも無い）

2-1. 書き込みの成否が分からない

Aplg_Logger::log() は void で、書き込み結果を呼び出し側に返しません。加えて、記録が黙って落ちる経路が 3 つあります。

$pre = apply_filters( 'pre_applog_write', null, ... );
if ( ! is_null( $pre ) ) {
    return;                      // ① フィルタで握り潰せる（戻り値は呼び出し側に伝わらない）
}

$message = apply_filters( 'app_log_write_log_before', $message, ... );
if ( false === $message ) {
    return;                      // ② 同上
}

$fp = fopen( $log_file, 'a' );   // ③ 失敗しても検知されない（後述）
fwrite( $fp, $message );
fclose( $fp );

監査ログの用途では「書けたつもりで書けていない」が最悪の失敗です。呼び出し側が applog_info() を呼んで正常に戻ってきた以上、記録は残っていると考えます。

• log() が成否を返す（bool、あるいは失敗理由つき）
• 書き込み関数の戻り値を確認する
• フィルタで抑止された場合と、書き込みに失敗した場合を区別できるようにする

2-2. 書き込み失敗で Fatal になりうる

上記③について。fopen() が失敗すると false を返し、PHP 8 では fwrite( false, ... ) が TypeError になります。ディスクフルや権限変更でログ出力が原因のホワイトスクリーンが起きえます。

caitsith のコピーは file_put_contents() を使っており、この経路では落ちません。取り込む価値があるのはこの性質です。

• 書き込み方式を統一し、失敗しても Fatal にしない

LOCK_EX については判断が要ります（未測定）

「本家はロックが無いから危険」という単純な話ではありません。

• FILE_APPEND も fopen($f,'a') も O_APPEND で開くため、1 回の write に収まる大きさなら、どちらも行が混ざりません
• ただし O_APPEND の不可分性は書き込みサイズに依存します。実運用のログには 462KB の 1 行が存在する実績があります（kingsman#4469 の AppLog Viewer 実装時に実測）。この規模では分割されうるので、巨大な行に対しては LOCK_EX だけが効きます
• 一方でコストがあります。caitsith の出力先は uploads = EFS マウントで、LOCK_EX はログ 1 行ごとにネットワーク越しのロックになります

どちらが最適かは測定していません。 現時点の提案は「LOCK_EX を採る（巨大行の実績がある以上、外す根拠が無い）／ただしフィルタで外せるようにし、EFS で遅いと分かったら切れる状態にしておく」です。

• LOCK_EX の有無をフィルタで切り替えられるようにする
• 高頻度書き込み環境での実測（別途）

2-3. 行頭に前置しない出力（raw / JSON モード）が無い

log() は必ず [日時] [LEVEL] (PID: N) を前置します。構造化ログを 1 行 JSON で出したい場合、JSON Lines として読めなくなります（[...] {...} になる）。

参考として、kingsman の pm_log()（mu-plugin 版）には既にこの口があります。

function pm_log( mixed $message, string $dirname = '/log/', string $format = 'text', bool $include_msec = false ): void

$format = 'json' で {timestamp, process_id, message} の 1 行 JSON、$include_msec でミリ秒まで出せます。後継である App Log に、前身の分家が持っている機能が無い状態です。

• 前置しない出力モードを追加する（applog_raw() のような別関数か、$format 引数か）
• kingsman の pm_log() の $format / $include_msec を取り込む

2-4. 自動削除の glob が末尾スラッシュに依存している

$files = glob( $log_dir . '*' );

$log_dir が / で終わらない呼ばれ方をすると、ディレクトリ内のファイルではなく兄弟パスに当たります。log() 側は realpath( $log_dir ) . '/' . $filename と明示的に / を足しているのに、log_auto_delete() に渡すのは正規化前の生パスで、非対称です。

• $log_dir を正規化してから glob する

（delta-lint finding dl-6c702523）

2-5. delete_log() が書き込み先と別のディレクトリを見る

log() は第 2 引数 $dirname でサブディレクトリへ書けますが、delete_log() は get_path_to_log_dir() を引数なしで呼ぶため、常にルートのログディレクトリしか参照しません。書き込み先と削除・閲覧の探索先が一致しません。

• delete_log() / ダッシュボードが $dirname を扱えるようにする

（delta-lint finding dl-3a3bfc83）

---

進め方

同期 → 機能追加 → 書き込み方式の統一の順で進めます。

1. 同期（1 章）— 本家を正としてコピー側の差分を取り込み、バージョンを 1.2 に。ここで保持期間のフィルタが各 PJT に届く
2. 機能追加（2-1 / 2-3 / 2-4 / 2-5）— 成否の返却、raw モード、glob、delete_log()
3. 書き込み方式の統一（2-2）— LOCK_EX の判断を含む。測定が要るので最後

1 が終わった時点で、SQL Runner の監査ログを 210 日保持に乗せられます。

影響範囲

• App Log を使っているすべての PJT
• 保持期間のフィルタが届くことで、これまで 90 日で消えていたログが消えなくなる環境が出ます。容量の見積もりが要ります
• log() の戻り値変更は後方互換（void → bool）

関連

• caitsith2022-main#1748 / #1749 — SQL Runner の監査ログ。この Issue の動機
• kingsman#4469 — AppLog Viewer。462KB の行はここで実測

[pm-hiroshi]

$dirname が効かない場合がある（初版からの仕様の食い違い）

applog( $msg, $dirname ) / applog_info( $msg, $dirname ) に渡した $dirname は、環境によっては黙って無視されます。 呼び出し側にはエラーも警告も出ません。

どうなっているか

出力先は Aplg_Settings::get_path_to_log_dir() が決めていて、その中で順番に 3 回上書きされます。

public static function get_path_to_log_dir( string $dirname = App_Log::LOG_DIR ): string {
	$path_to_log_dir = $app->get_plugin_root_path() . $dirname;   // 渡した dirname が使われるのはここだけ

	// If log directory option is set, use it instead of LOG_DIR
	$options         = get_option( App_Log::OPTION_KEY );
	$path_to_log_dir = ( $options && '' !== $options['log_directory'] )
		? (string) $options['log_directory']                      // 丸ごと置き換え（dirname が消える）
		: $path_to_log_dir;

	$path_to_log_dir = (string) apply_filters( 'app_log_path_to_log_dir', $path_to_log_dir );  // 丸ごと置き換え

	return $path_to_log_dir;
}

**後ろの 2 つは「基点の後ろに足す」のではなく「全体を置き換える」**ため、そこを通った時点で $dirname は消えます。

その環境の状態	applog_info( $msg, 'app/foo' ) の行き先
設定もフィルタも無い	plugins/app-log/app/foo/ — 効く
設定画面で出力先を変えてある	その設定値のディレクトリ — app/foo は消える
フィルタが登録されている	フィルタの戻り値

コメントと実装が食い違っています

// If log directory option is set, use it instead of LOG_DIR

コメントは「LOG_DIR の代わりに使う」と書いています。LOG_DIR は既定の基点を指す定数（/logs/）なので、**意図は「基点を差し替える」**はずです。

しかし実装が置き換えているのは $path_to_log_dir、すなわち プラグインのディレクトリ + $dirname の全体です。基点だけのつもりが $dirname ごと消しています。設計判断ではなく食い違いだと考えています。

そして、本番で必要な設定がこれを踏みます

既定の基点は app-log プラグイン自身のディレクトリです（const LOG_DIR = '/logs/'）。

• コンテナで readonlyRootFilesystem を使っている環境ではそもそも書けません（mkdir に失敗して wp_die() します）
• 書けたとしても、プラグインを入れ替えると消えます

つまり本番で使うなら設定画面で出力先を変えるのが当たり前の運用で、その当たり前をやった瞬間に、全ての呼び出し側の $dirname が黙って無効になります。

実際に踏みました

caitsith で applog_info( $line, 'app/sql-runner' ) と書いた監査ログが、app/sql-runner/ ではなく共通のログディレクトリに落ちました（あちらはフィルタ経由なので上の 3 番目のケースです）。呼び出し側は「専用のディレクトリに出している」つもりで、実際は別の場所に混ざっていました。

その場所がたまたま、サイトの .htaccess が .log の遮断から除外しているディレクトリだったため、SQL 本文を含む行が web から取得できる状態になっていました。$dirname が効かないこと自体は保護の話ではありませんが、「置いたつもりの場所と実際の場所が違う」ので、置き場所に紐づく保護の想定が崩れます。

直し方の案

設定とフィルタは「基点」だけを決めることにして、$dirname は必ずその後ろに付ける。

$base = $app->get_plugin_root_path();
$base = ( $options && '' !== $options['log_directory'] ) ? $options['log_directory'] : $base;
$base = (string) apply_filters( 'app_log_path_to_log_dir_base', $base );

return rtrim( $base, '/' ) . '/' . ltrim( $dirname, '/' );

移行の注意

これは初版（2020-07-31）からの挙動で、その後どのコミットも触っていません。 つまりデグレではなく、直すと既存環境の出力先が変わります。

• 影響を受けるのは「$dirname を渡していて、かつ設定またはフィルタで出力先を変えている」環境だけです。どちらか一方しか無い環境は変わりません
• 変わる場合、ログはいままで 1 か所に混ざっていたものが $dirname ごとに分かれます。過去のファイルは移動しないので、しばらくは新旧が別の場所に並びます
• 既存のフィルタは app_log_path_to_log_dir という名前で「最終パス」を返す前提で書かれているので、基点を返す前提に変えるならフックの名前も変える必要があります（上の案では _base を付けています）。旧フックを残して非推奨にする形も考えられます

参考: 履歴

2020-07-31  rpaldo    Initial commit          ← この時点で既にこの形
2020-08-03  rpaldo    Added data sanitizing & escaping
2020-10-09  rpaldo    パスワードリセット時の Warning の対応
2023-03-22  hiroshi   add more filters and mini refactoring   ← フィルタを追加、上書きの行はそのまま
2024-01-23  TamG5S3   v1.1.4 / update code format / add php doc  ← 書式のみ

[pm-hiroshi]

追記: これは公開プラグインのバグです（1.1.2 で確認）

上のコメントは社内で使っている版を見て書きましたが、wordpress.org で配布している App Log の 1.1.2 でも同じでした。zip を落として確認しています。

// app-log/admin/aplg-settings.php:124  （公開版 1.1.2）
public static function get_path_to_logdir( $dirname = '' ) {
	$dirname         = ( $dirname != '' ) ? $dirname : self::APLG_LOG_DIR;
	$path_to_log_dir = dirname( __DIR__ ) . $dirname;

	// If log directory option is set, use it instead of APLG_LOG_DIR
	$options         = get_option( 'aplg_settings' );
	$path_to_log_dir = ( $options && $options['log_directory'] != '' ) ? $options['log_directory'] : $path_to_log_dir;

	return $path_to_log_dir;
}

設定で $dirname ごと置き換わる部分は、初版のまま公開版に入っています。

公開版の方が回避しにくいです

公開版 1.1.2 にあるフィルタは app_log_file_ext と pre_applog_write の 2 つだけで、app_log_path_to_log_dir はありません（あれは 2023-03-22 の追加なので 1.1.4 系のみ）。

つまり公開版の利用者は、

• 設定画面で出力先を変えると $dirname が効かなくなる
• 既定の置き場はプラグイン自身のディレクトリなので、本番で使うなら設定変更はほぼ必須
• フィルタで回避することもできない

という状態です。エラーも警告も出ないので、applog( $msg, 'foo/bar' ) と書いた人は効いていると思ったままになります。

直すには wordpress.org へのリリースが要ります

そして公開版と社内で使っている版がかなり離れています。

ファイル	公開版 1.1.2	社内版
app-log.php	89 行	115 行
classes/class-aplg-logger.php	137 行	201 行
admin/aplg-settings.php	147 行	160 行
app-log-functions.php	107 行	107 行

この Issue の元の主題（本家とコピーの乖離）と同じ問題にぶつかります。修正そのものは小さいので、どちらを直してどう合わせるかを先に決める話になりそうです。

参考: この部分の履歴

get_path_to_logdir() の中身は 2020-07-31 の初版から誰も触っていません。

2020-07-31  rpaldo          Initial commit                    ← この時点で既にこの形
2020-08-03  rpaldo          Added data sanitizing & escaping
2020-10-09  rpaldo          パスワードリセット時の Warning の対応
2021-01-12  anahara         ログを外部に書き出すためのフックを追加
2023-03-22  hiroshi         add more filters and mini refactoring   ← フィルタ追加、上書きの行はそのまま
2024-01-23  TamG5S3         v1.1.4 / code format / add php doc      ← 書式のみ

デグレではなく、最初からこの形です。直すと既存環境の出力先が変わりうるので、上のコメントに書いた移行の注意がそのまま当てはまります。