あなたの知らないCampaignバウンスの世界(2)〜inMailログに見るバウンスメール取得の動き

[前回](https://qiita.com/JJSlider/items/5d7f9b21c75cec3f9cdc "あなたの知らないCampaignバウンスの世界(1)〜同期バウンスと非同期バウンス")はAdobe Campaign(以下「Campaign」)における「同期」バウンスと「非同期」バウンスについて説明しました。その際inMailプロセスの冗長ログ例をお見せしましたが、内容に踏み込む余裕がなかった、無念…というわけで今回はリベンジです。ログを行単位で追うことで、inMailがバウンスメールを処理する動きを読み解いていきたいと思います。

まずそのinMailログを再掲しますね:

``` inMail.log
17:24:10 >   Connection opened for user 'POP3アカウント名' on server 'POP3サーバー名'
17:24:10 >   POP3 Server: '+OK  <1d5f.8adf3e.61f79caa.TIMG4aqizhSXNKDMbz+mdA==@mail02-md>'
17:24:10 >   POP3 Client: 'USER POP3アカウント名'
17:24:10 >   POP3 Server: '+OK'
17:24:10 >   POP3 Client: 'PASS *******'
17:24:10 >   POP3 Server: '+OK Logged in.'
17:24:10 >   POP3 Client: 'STAT'
17:24:11 >   POP3 Server: '+OK 1 110220'
17:24:11 >   1 message(s) (107.6 kB) for user 'POP3アカウント名' on server 'POP3サーバー名'.
17:24:11 >   POP3 Client: 'RETR 1'
17:24:11 >   MSG 1, 1429 byte(s) received (1.2965 %).
17:24:11 >   MSG 1, 2877 byte(s) received (2.61023 %).
17:24:11 >   MSG 1, 4325 byte(s) received (3.92397 %).
…中略…
17:24:12 >   MSG 1, 107133 byte(s) received (97.1992 %).
17:24:12 >   MSG 1, 108581 byte(s) received (98.513 %).
17:24:12 >   MSG 1, 110220 byte(s) received (100 %).
17:24:12 >   Receiving first message for user 'POP3アカウント名' on server 'POP3サーバー名'.
17:24:12 >   Receiving last message for user 'POP3アカウント名' on server 'POP3サーバー名'.
17:24:12 >   「送信者アドレス」からのメッセージ : ルール「User_unknown」が一致しました。メッセージは削除されました。
17:24:12 >   「送信者アドレス」からのメッセージ : ルール「User_unknown」が一致しました。メッセージは削除されました。
17:24:13 >   POP3 Client: 'DELE 1'
17:24:13 >   POP3 Server: '+OK Marked to be deleted.'
17:24:14 >   POP3 Client: 'QUIT'
17:24:14 >   POP3 Server: '+OK Logging out, messages deleted.'
17:24:24 >   Connection closed for user 'POP3アカウント名' on server 'POP3サーバー名'
```

これはログレベルを最大にした冗長ログで、オンプレミス環境のserverConf.xmlに以下のような設定変更をして取得したものです(args="-verbose"):
![args-verbose.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2516149/be381760-ba58-0291-2419-869febeab200.png)

::: note
冗長ログ設定を行うと、本稿のように得られる情報量は多くなりますが、その分ファイルがやたらでかくなっちゃいます…今回は説明のため例外的にやってますが、決してお勧めするものではありません。そこはご注意くださいね。
:::

では、そのログを、いくつかのブロックに分けたうえでそれぞれ何をやっているか見ていきましょう。

## POP3サーバーへ接続

``` inMail.log
17:24:10 >   Connection opened for user 'POP3アカウント名' on server 'POP3サーバー名'
17:24:10 >   POP3 Server: '+OK  <1d5f.8adf3e.61f79caa.TIMG4aqizhSXNKDMbz+mdA==@mail02-md>'
17:24:10 >   POP3 Client: 'USER POP3アカウント名'
17:24:10 >   POP3 Server: '+OK'
17:24:10 >   POP3 Client: 'PASS *******'
17:24:10 >   POP3 Server: '+OK Logged in.'
```

まず最初は、バウンスメールを取得するために、inMailがPOP3サーバーに接続します。上掲ログの「POP3アカウント名」「POP3サーバー名」は秘匿のために筆者が手で書き換えたもので、実際はCampaignのデプロイウィザードで設定した接続情報が平文で入ってます:
![2022-02-02_10-00-24.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2516149/95e7ea10-cae8-08b5-95d5-0ffd4d06a15c.png)


POP3パスワードも、上掲画面とログではいちおう見えなくなってますが、ポート110デフォルトだと通信経路上は平文で流れます。昔ながらの素のPOP3ってことですね。本稿執筆時点(2022年2月)ではPOP3が唯一サポートされているバウンスメール受信プロトコルです。

## メールボックスをチェック

接続成功したら、inMailはPOP3「STAT」コマンドを送信してメールボックスの状況を確認します:

``` inMail.log
17:24:10 >   POP3 Client: 'STAT'
17:24:11 >   POP3 Server: '+OK 1 110220'
17:24:11 >   1 message(s) (107.6 kB) for user 'POP3アカウント名' on server 'POP3サーバー名'.
```

POP3サーバーが「+OK 1 110220」と応答しました。するとこの場合、メールボックスに１通のメールが溜まっており、そのサイズ総計は110220バイトだということがわかります。

## バウンスメールを取得

``` inMail.log
17:24:11 >   POP3 Client: 'RETR 1'
17:24:11 >   MSG 1, 1429 byte(s) received (1.2965 %).
17:24:11 >   MSG 1, 2877 byte(s) received (2.61023 %).
17:24:11 >   MSG 1, 4325 byte(s) received (3.92397 %).
…中略…
17:24:12 >   MSG 1, 107133 byte(s) received (97.1992 %).
17:24:12 >   MSG 1, 108581 byte(s) received (98.513 %).
17:24:12 >   MSG 1, 110220 byte(s) received (100 %).
17:24:12 >   Receiving first message for user 'POP3アカウント名' on server 'POP3サーバー名'.
17:24:12 >   Receiving last message for user 'POP3アカウント名' on server 'POP3サーバー名'.
```

inMailがPOP3「RETR」コマンドを発行して実際のバウンスメール取得を始めます。「中略」の部分はダウンロード進行状況がえんえん続いてます。景色としては悪くないんですが、本稿ではスペースの無駄なのではしょりました。

::: note info
この例では１通だけだからよかったものの、これが何通もあるとこのログががーっと流れてけっこうすごいことになります。冒頭で触れたように冗長設定をしたために出力される部分です。トラブルシューティングなどで冗長設定をされる場合はくれぐれもご注意を。
:::

メールダウンロードの所要時間がまるわかりなので、inMail設置環境の通信状況などパフォーマンス評価なんかに役立ちます。検証環境なんかでいちど見てみるとおもしろいと思いますよ。

## バウンス判定

さあ、ここがいちばんのポイントです! 試験に出すぞ!!

``` inMail.log
17:24:12 >   「送信者アドレス」からのメッセージ : ルール「User_unknown」が一致しました。メッセージは削除されました。
```

この行が何をやってるかというと、取得したバウンスメールの中身を見ているのです。どの配信の、どの宛先が、どんな理由で弾き返されてきたのか。inMailがメールの内容を走査して、それらを特定します。このときに用いられる判定ルールが「メール処理ルール」。クライアントコンソールで見てみましょう。管理>キャンペーン管理>配信不能件数の管理>メールルールセット と進んでください:
![2022-02-02_16-20-57.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2516149/c15d1a70-5d70-d8a2-2741-fd039e619c41.png)
上掲ログ行を見るとルール「User_unknown」って言ってましたよね。中身を見たいので「User_unknown」を選択し「詳細」をクリックしてください:
![2022-02-02_16-28-49.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2516149/1250910a-c9a5-3ebb-8feb-6ef1759e30c5.png)
内容は立ち入りませんが、バウンスメールかどうか題名などから調べるロジックがJavaScriptで記述されています。上掲ログ行は、取得されたメールがこの「User_unknown」ルールにマッチしたためバウンスと判定されたといっているわけです。

ルールにマッチしてバウンス判定すると、inMailはCampaignデータベースで該当する配信・宛先のステータスを更新します。前回の記事で非同期バウンスの結果としてお見せしたとおりです:
![2022-01-31_17-44-25.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2516149/f4555062-815f-b69f-f8d7-5eab5ffad939.png)

でもここでふと思うのです…あなたの私用メアドにも、おまえがPC見ながらやってることの録画を公開されたくなかったらビットコイン支払え、ってメールが１日５通くらい来てませんか。あれってマルウェアが宛先アドレスをランダム生成してるので、ACバウンス受信専用アドレスにも来る可能性ありますよね。そういう、バウンスじゃないメールが来たらどうなるでしょう――ご安心あれ、ルールにマッチしないのでバウンスじゃないと判定し、捨てちゃいます。ログで見るとこんな感じ:

``` inMail.log
15:55:33 >   「送信者アドレス」からのメッセージ : 適用するルールがありません。メッセージは削除されました。
```

スパムとかの無関係なメールだとルールにマッチしないので「適用するルールがありません」となるわけです。ただ、マッチするルールがあろうがあるまいが「メッセージは削除されました」はけっきょくいっしょですね。ログの続きをさらに見てみると…

## メールの削除

``` inMail.log
17:24:13 >   POP3 Client: 'DELE 1'
17:24:13 >   POP3 Server: '+OK Marked to be deleted.'
17:24:14 >   POP3 Client: 'QUIT'
17:24:14 >   POP3 Server: '+OK Logging out, messages deleted.'
17:24:24 >   Connection closed for user 'POP3アカウント名' on server 'POP3サーバー名'
```

inMailが「DELE」コマンドを発行し、POP3メールボックス内のメールを削除しました。先述のように、バウンスだろうがなかろうが、inMailは設定されたメールボックスのメールを**すべて**受信し、**削除**するのです。

::: note alert
大事なことなので２回言いますよ。inMailは設定されたメールボックスのメールをすべて受信し、削除します。問答無用です。なので、デプロイウィザードで設定するPOP3アカウントは、絶対に、この目的専用にしてください。メアド流用してメール消されて泣いても知らないよ！
:::

メールを削除できたら、あとはinMailがログアウトしておしまいです。お疲れさまでした！

この一連の処理を、inMailは300秒ごとに繰り返しています。この300秒のインターバルはオンプレミス環境ではserverConf.logで設定変更できます(popMailPeriodSec="300"):
![2022-02-02_at_17.04.35_.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/2516149/352841d0-756d-1723-b4bd-158c4198b8cb.png)
…いかがでしたか。あーバウンス返ってきちゃったー、でいままで済ましてたことの背景では、こんな大層な動きがあったのでした。

バウンスってなにげに、Campaignメール機能の勘所のひとつだと思います。バウンスを制するものAdobe Campaignを制す！　と声を大にして言いたい跡部官辺がお送りしました。

::: note warn
本稿の内容は筆者のオンプレミス型デモ環境(Adobe Campaign Classic 9032@3a9dc9c・レガシーMTA)上で実施した検証に基づきます。別環境における同様の動作を保証するものではありません。またデータは架空のものであり、既存の配信や実在の組織とはいっさい関係がありません。
:::