Apacheでmod_dumpioを使い、POSTデータをロギングする方法について

はじめに

こんにちは、ディーネットの山田です。

AWSネタではないですが、Apacheのmod_dumpioをどうしても検証してみたかったのでブログにしてみました。

POSTで転送されるデータは、GETとは異なりURLの引数で転送されないので、通常はWebサーバのログから追うことができません。（アプリケーションで出力していれば別です）
追うことができないことで、一般的にID、パスワードなどの秘匿情報のやり取りにも使われます。
がしかし、秘匿であるが故に、POSTを悪用した攻撃などは、追うことができず泣き寝入りのような状態になることも多々あります。

そこで、泣き寝入りとならないように何とかして、POSTの内容をログに記録できないか調べていたところ、Apacheにmod_dumpioというモジュールが存在しているので、
これを使ってどういった内容が記録されるのか見ていこうと思います。

動作検証環境について

CentOS7系に標準でインストール可能なApache2.4から、mod_dumpioモジュールが標準インストールされてくるので、その環境を使います。

バージョンについて

OS: CentOS Linux release 7.9.2009 (Core)
Apache/2.4.6 (CentOS) ※yumコマンドでインストールされる最新版

設定方法について

mod_dumpioモジュールがロードされているか確認する

httpd -M 2>&1 | grep -i "dumpio"
 dumpio_module (shared)

dumpio_module が表示されれば、標準で利用可能な状態になっていることがわかります。

設定ファイルを記述します

vi /etc/httpd/conf.d/dumoio.conf
# Apacheに対して入力された内容をダンプする設定
DumpIOInput On      # See: https://httpd.apache.org/docs/2.4/ja/mod/mod_dumpio.html#dumpioinput
# Apacheから出力された内容をダンプする設定
DumpIOOutput Off    # See: https://httpd.apache.org/docs/2.4/ja/mod/mod_dumpio.html#dumpiooutput
# エラーログに記録する設定
LogLevel debug dumpio:trace7

文法チェックを行います

httpd -t
Syntax OK

Syntax OK が表示されれば、設定ファイルの記述内容に文法エラーはありません。

Apacheを再起動します

systemctl restart httpd

動作確認について

テストコンテンツを使って、実際にPOSTデータを発生させます

<?php
    if (!empty($_POST)) {
        echo "POSTが送信されました<br>\n";
        if (isset($_POST['name'])) {
            $name = $_POST['name'];
            echo $name . "さん、こんにちは<br>\n";
        } else {
            $name = null;
        }
        if (isset($_POST['mail'])) {
            $mail = $_POST['mail'];
            echo $mail . "がメールアドレスですね<br>\n";
        } else {
            $mail = null;
        }
    }
?>
<!DOCTYPE html>
<html lang="ja">
    <head>
        <title>POSTテスト</title>
        <meta http-equiv="content-type" content="text/html; charset=utf-8">
        <meta http-equiv="pragma" content="no-cache">
        <meta http-equiv="cache-control" content="no-cache">
        <meta http-equiv="expires" content="0">
    </head>
    <body>
        <form method="post">
            <label for="namelabel">名前</label>
            <input type="text" name="name" id="namelabel" placeholder="例) 山田 太郎">
            <br>
            <label for="maillabel">メールアドレス</label>
            <input type="text" name="mail" id="maillabel" placeholder="例) taro@example.com">
            <br>
            <input type="submit" value="送信する">
        </form>
    </body>
</html>

エラーログに以下のようなログが流れます

[Thu Feb 09 11:25:07.190041 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190138 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 17 bytes
[Thu Feb 09 11:25:07.190145 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): POST / HTTP/1.1\r\n
[Thu Feb 09 11:25:07.190161 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190165 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 22 bytes
[Thu Feb 09 11:25:07.190168 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Host: YY.YY.YY.YY\r\n
[Thu Feb 09 11:25:07.190173 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190176 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 24 bytes
[Thu Feb 09 11:25:07.190179 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Connection: keep-alive\r\n
[Thu Feb 09 11:25:07.190184 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190187 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 20 bytes
[Thu Feb 09 11:25:07.190194 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Content-Length: 47\r\n
[Thu Feb 09 11:25:07.190210 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190215 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 26 bytes
[Thu Feb 09 11:25:07.190218 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Cache-Control: max-age=0\r\n
[Thu Feb 09 11:25:07.190222 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190226 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 30 bytes
[Thu Feb 09 11:25:07.190229 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Upgrade-Insecure-Requests: 1\r\n
[Thu Feb 09 11:25:07.190233 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190246 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 31 bytes
[Thu Feb 09 11:25:07.190249 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Origin: http://YY.YY.YY.YY\r\n
[Thu Feb 09 11:25:07.190253 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190257 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 49 bytes
[Thu Feb 09 11:25:07.190260 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Content-Type: application/x-www-form-urlencoded\r\n
[Thu Feb 09 11:25:07.190464 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190470 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 125 bytes
[Thu Feb 09 11:25:07.190474 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/109.0.0.0 Safari/537.36\r\n
[Thu Feb 09 11:25:07.190479 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190482 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 145 bytes
[Thu Feb 09 11:25:07.190485 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9\r\n
[Thu Feb 09 11:25:07.190490 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190493 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 33 bytes
[Thu Feb 09 11:25:07.190496 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Referer: http://YY.YY.YY.YY/\r\n
[Thu Feb 09 11:25:07.190500 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190503 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 32 bytes
[Thu Feb 09 11:25:07.190524 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Accept-Encoding: gzip, deflate\r\n
[Thu Feb 09 11:25:07.190528 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190532 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 42 bytes
[Thu Feb 09 11:25:07.190540 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): Accept-Language: ja,en-US;q=0.9,en;q=0.8\r\n
[Thu Feb 09 11:25:07.190545 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes
[Thu Feb 09 11:25:07.190549 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 2 bytes
[Thu Feb 09 11:25:07.190552 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): \r\n
[Thu Feb 09 11:25:07.191533 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [readbytes-blocking] 47 readbytes
[Thu Feb 09 11:25:07.191560 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(63): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): 47 bytes
[Thu Feb 09 11:25:07.191564 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): name=%E5%A4%AA%E9%83%8E&mail=ziro%40example.com
[Thu Feb 09 11:25:07.192081 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [speculative-nonblocking] 1 readbytes
[Thu Feb 09 11:25:07.192158 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(140): [client XXX.XXX.XXX.XXX:60268] mod_dumpio: dumpio_in [getline-blocking] 0 readbytes

当社のIPアドレスや、検証に使用したIPアドレスが記載されている欄は伏せておりますが、クライアントからリクエストされたHTTPヘッダ情報がログに記録されます。

今回の例ですと、以下のみが最低限欲しい情報になります

[Thu Feb 09 11:25:07.191564 2023] [dumpio:trace7] [pid 20642] mod_dumpio.c(103): [client XXX.XXX.XXX.XXX:60268] mod_dumpio:  dumpio_in (data-HEAP): name=%E5%A4%AA%E9%83%8E&mail=ziro%40example.com

HTMLデコーダーなどを使い、デコードすると実際に入力された内容がわかります。

name=太郎&mail=ziro@example.com

まとめ

mod_dumpioモジュールを使い、POSTデータの中身をログに記録することができました。
POSTデータの中身は、秘匿な情報が含まれる場合もありますので、有効化する際は秘匿情報が収集される可能性があることを念頭に置いて有効化しましょう。
通常時に有効化すると、膨大なログが記録されてしまうので、目的のPOSTデータを確認できたら無効化するようにしましょう。

参考サイト

https://httpd.apache.org/docs/2.4/ja/mod/mod_dumpio.html

yamada

プロフィール
テクニカルサポートは卒業して、フロントサイドでお客様環境の構築をさせていただいております。
たまに、テクニカルサポートでご対応させていただくことがあるかもしれませんが、その際はよろしくお願いいたします。
インフラ系のエンジニアですが、時々休日プログラマー（Python、PHP）をやっております。

LINK
クラウドベリージャム：プロフィールページ