理想未来ってなんやねん

娘可愛い。お父さん頑張る。

メールを高速に配信する方法

メールを高速に配信する方法について調べてみました。
今回、MAILER DAEMONpostfixで、サンプルプログラムはPHPで記述しています。

■サンプルプログラム

以下に今回の実験で使用する配信テストの為のサンプルプログラムを示します。
1000通送信して終了するだけの単純なプログラムです。

mailsend.php

まずメール送信部分です。

<?php
require_once "Mail.php";

$params = array(
  'host' => '127.0.0.1',
  'port' => '25',
  'auth' => false,
  'username' => '',
  'password' => '',
  'persist' => TRUE, // TRUEにすると配信毎に接続を切らない。
);

$from = 'xxxxxxxxx@example.com';
$recipients = 'yyyyyyyy@foo.bar.com';

$headers['From']        = $from;
$headers['Return-Path'] = $from;
$headers['To']      = $recipients;
$headers['Subject'] = 'Test';

$body = "Test\n";

$objMail = Mail::factory('mail', '-f'.$from);
// $objMail = Mail::factory('smtp', $params);

for($i = 0; $i < 1000; $i++)
{
	$objMail->send($recipients, $headers, $body);
}
mailmgr.php

次に上記の送信プログラムを複数起動し、終了するまで待つプログラムです。
全ての子プロセスが終了するまで待ちますので、全送信プロセスの終了時間が分かります。

<?php

$max_clients = 5; // プロセス数
$client_pids = array();
for($i = 0; $i < $max_clients; $i++)
{
	$pid = pcntl_fork();
	if ($pid) 
	{
		echo 'Start Process pid=' . $pid . PHP_EOL;
		$client_pids[] = $pid;
	} 
	else 
	{
		unset($client_pids);
		require_once './mailsend.php';
		exit();
	}
}

$client_pids = array_flip($client_pids);
$status = NULL;
$wait_options = WUNTRACED;
for(;;)
{
	$pid = pcntl_wait($status, $wait_options);
	if ($pid > 0)
	{
		echo 'Exit Process pid=' . $pid . PHP_EOL;
		unset($client_pids[$pid]);
		if (count($client_pids) == 0)
			break;
	}
}
exit();

■テスト

実際に配信テストを行って掛かった時間を計測してみます。

mailの場合

まずバックエンドにphpのmail関数を使用して送信してみます。
mailsend.phpのMail::factoryメソッドの第1引数を書き換えてmailを指定します。

$objMail = Mail::factory('mail', '-f'.$from);
// $objMail = Mail::factory('smtp', $params);

実際に実行した結果です。

$ $ time php mailmgr.php 
Start Process pid=31714
Start Process pid=31715
Start Process pid=31716
Start Process pid=31717
Start Process pid=31718
Exit Process pid=31717
Exit Process pid=31716
Exit Process pid=31714
Exit Process pid=31718
Exit Process pid=31715

real	0m19.868s
user	0m31.553s
sys	0m35.228s

終了まで19.868秒掛かりました。


実行した直後のmailqを見てみます。

$ mailq
F2350770878      219 Sun Sep  5 15:30:34  xxxxxxxxx@example.com
                                         yyyyyyyy@foo.bar.com

87EBF7710F8      219 Sun Sep  5 15:30:34  xxxxxxxxx@example.com
                                         yyyyyyyy@foo.bar.com

〜〜〜〜〜〜〜〜中略〜〜〜〜〜〜〜〜

136FF7704FC      218 Sun Sep  5 15:30:54  xxxxxxxxx@example.com
                                         yyyyyyyy@foo.bar.com

4C0427710BB      219 Sun Sep  5 15:30:54  xxxxxxxxx@example.com
                                         yyyyyyyy@foo.bar.com

8D634770733      219 Sun Sep  5 15:30:54  xxxxxxxxx@example.com
                                         yyyyyyyy@foo.bar.com

-- 1156 Kbytes in 4026 Requests.

キューにメールが溜まっている事が確認できます。


ログを確認してみます。

# tail -f /var/log/maillog
〜〜〜〜〜〜〜〜中略〜〜〜〜〜〜〜〜
Sep  5 15:30:54 prmail postfix/pickup[21881]: A4108770070: uid=500 from=<xxxxxxxxx@example.com>
Sep  5 15:30:54 prmail postfix/cleanup[31224]: A4108770070: message-id=<20100905063054.A4108770070@example.com>
Sep  5 15:30:54 prmail postfix/qmgr[27225]: A4108770070: from=<xxxxxxxxx@example.com>, size=336, nrcpt=1 (queue active)
Sep  5 15:30:54 prmail postfix/smtp[31435]: A4108770070: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=230, delays=230/0/0/0, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B0ABE2EB8048)
Sep  5 15:30:54 prmail postfix/qmgr[27225]: A4108770070: removed

上記ログの下から2行目のpostfix/smtpの行のを見ると、delay=230となっており、230秒掛かっていることが分かります。
プログラム実行時間の19.868秒と合わせて、約250秒掛かりました。

smtpの場合

次にsmtpで送信してみます。
mailsend.phpのMail::factoryメソッドの第1引数をsmtpを指定して試してみます。

// $objMail = Mail::factory('mail', '-f'.$from);
$objMail = Mail::factory('smtp', $params);

実際に実行した結果です。

$ time php mailmgr.php 
Start Process pid=18648
Start Process pid=18649
Start Process pid=18650
Start Process pid=18651
Start Process pid=18652
Exit Process pid=18650
Exit Process pid=18649
Exit Process pid=18651
Exit Process pid=18648
Exit Process pid=18652

real	1m3.253s
user	0m19.131s
sys	0m2.166s

終了まで1分3.253秒(3.253秒)掛かりました。


キューの中身を確認してみます。

$ mailq
Mail queue is empty

空っぽでした。

# tail -f /var/log/maillog
Sep  5 15:46:57 prmail postfix/smtpd[28294]: B030C77005F: client=xxxxxx[127.0.0.1]
Sep  5 15:46:57 prmail postfix/cleanup[28701]: B030C77005F: message-id=<20100905064657.B030C77005F@example.com>
Sep  5 15:46:57 prmail postfix/qmgr[27225]: B030C77005F: from=<xxxxxxxxx@example.com>, size=403, nrcpt=1 (queue active)
Sep  5 15:46:57 prmail postfix/smtp[28144]: B030C77005F: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.07, delays=0.06/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as BEB1A2EB8048)
Sep  5 15:46:57 prmail postfix/qmgr[27225]: B030C77005F: removed

上記ログの下から2行目のpostfix/smtpの行のを見ると、delay=0.07となっており、遅延がほぼ無いことが分かります。
プログラム実行時間の63.253秒と合わせて約63秒が配信に掛かった時間です。

■結果

上記の実験の結果、以下の通りになりました。

backend 実行時間
mail 249.868s
smtp 63.323s

■なぜか?

なぜ、このような結果になるのか見てみたいと思います。
もう一度ログを良く見て下さい。

バックエンドにmailを指定した場合では、pickup、cleanup、qmgr、smtpの順に実行されています。
バックエンドにsmtpを指定した場合では、smtpd、cleanup、qmgr、smtpの順に実行されています。

違いが分かりにくいので、以前描いたInternal Postfix block diagramを元に見てみたいと思います。

バックエンドがmailの場合

以下の図がバックエンドにmailを指定した場合のフローです。
phpのmail関数を使用した場合、unix系のOSではsendmailコマンドが処理します。

送信されたメールは、まずsendmailコマンドを通してmaildropキューに置かれます。
そこからpickupプロセスが1通1通メールを取り出し、cleanupに渡します。
pickupはローカルメールの配送を担当していますが、このプロセスはシングルプロセスです。


マルチプロセスにできないの?と思うかもしれません。


実際にmaster.cfをいじって複数起動させてみました。
/etc/postfix/master.cfのpickupの行にある、maxprocを1から - に変更してみます。

# ==========================================================================
# service type  private unpriv  chroot  wakeup  maxproc command + args
#               (yes)   (yes)   (yes)   (never) (100)
# ==========================================================================
〜〜〜〜〜〜〜〜〜〜中略〜〜〜〜〜〜〜〜〜〜
#pickup    fifo  n       -       n       5       1       pickup
pickup    fifo  n       -       n       5       -       pickup
#maxprocを1から制限なし(=100)に変更             ↑

変更を反映させる為にreloadします。

# postfix reload
postfix/postfix-script: refreshing the Postfix mail system

すると、

# tail -f /var/log/maillog
Sep  5 20:16:19 prmail postfix/pickup[24040]: fatal: service pickup requires a process limit of 1
Sep  5 20:16:20 prmail postfix/master[27222]: warning: process /usr/libexec/postfix/pickup pid 24040 exit status 1
Sep  5 20:16:20 prmail postfix/master[27222]: warning: /usr/libexec/postfix/pickup: bad command startup -- throttling

とmaillogに記録されて怒られ、pickupが起動しません。
pickupはシングルプロセスでしか起動する事ができません。


mailでメールを送信した場合は、pickupがボトルネックになります。
その後、cleanupからqmgrへ、qmgrからsmtpへと渡っていきますが、シングルまたはデュアルプロセスで処理されます。


以下にmaillogから送信を行った直後のsmtpデーモンのログだけを抜き出してみました。
[]で囲まれたプロセスIDを良く見て下さい。

# grep 'Sep  5 15:30:54 prmail postfix/smtp\[' /var/log/maillog
Sep  5 15:30:54 prmail postfix/smtp[31435]: 51C1D770072: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=237, delays=237/0/0/0, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5E4DE2EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: 5D980770070: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=237, delays=237/0/0/0, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 69EA82EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: 692D7770072: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=230, delays=230/0/0/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 758EA2EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: 74EC0770070: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=239, delays=239/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 8161D2EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: 80AB0770072: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=233, delays=233/0/0/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 8D30C2EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: 8C65E770070: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=229, delays=229/0/0/0, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 98C1A2EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: 9810F770072: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=224, delays=224/0/0/0.03, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as A4B782EB8048)
Sep  5 15:30:54 prmail postfix/smtp[31435]: A4108770070: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=230, delays=230/0/0/0, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B0ABE2EB8048)

プロセスIDが31435のみしか記録されておらず、他サーバーへの配信もシングルプロセスで処理されていることが分かります。

バックエンドがsmtpの場合

以下の図がバックエンドにsmtpを指定した場合のフローです。

送信されたメールは、まずsmtpdが受け取り、cleanupに渡します。
smtpd、cleanup、qmgr、smtpは、それぞれマルチプロセスですので、何もない場合はそのままマルチプロセスで送られます。


詰まることが考えられる部分としては、smtpが外部のメールサーバーの制限を受けてdeferに渡し、deferからqmgrに通知してqmgrはdeferredキューに差し戻します。
またqmgrがincomingキューから受け取りきれない場合、incomingキューが詰まります。

これらのキューが詰まる場合は、ある意味、配信速度の上限とも言えます。


実際に配信を行った直後のsmtpデーモンのログを見てみます。
[]で囲まれたプロセスIDを良く見て下さい。

# grep 'Sep  5 15:46:57 prmail postfix/smtp\[' /var/log/maillog
Sep  5 15:46:57 prmail postfix/smtp[28745]: 8E7BE77005D: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.07, delays=0.06/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 9C9022EB8048)
Sep  5 15:46:57 prmail postfix/smtp[28788]: 90FA9770060: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.08, delays=0.05/0/0/0.02, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 9F3472EB804B)
Sep  5 15:46:57 prmail postfix/smtp[28763]: 91164770063: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.08, delays=0.05/0/0/0.02, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 9F2012EB8048)
Sep  5 15:46:57 prmail postfix/smtp[28144]: 9D31B77005F: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.06, delays=0.05/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as A99452EB8048)
Sep  5 15:46:57 prmail postfix/smtp[28745]: A0049770061: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.08, delays=0.06/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as AFF042EB8048)
Sep  5 15:46:57 prmail postfix/smtp[28688]: 9FE5377005D: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.08, delays=0.07/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B01732EB804B)
Sep  5 15:46:57 prmail postfix/smtp[28788]: A9FB1770060: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.06, delays=0.05/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B79E62EB8048)
Sep  5 15:46:57 prmail postfix/smtp[28144]: B030C77005F: to=<yyyyyyyy@foo.bar.com>, relay=foo.bar.com[XXX.XXX.XXX.XXX]:25, delay=0.07, delays=0.06/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as BEB1A2EB8048)

28745、28763 、28144、28688、28788の5プロセスで処理されていることが分かります。

■結論

大量のメールを高速に配信する場合はsmtpで送信しましょう。
phpの場合は、PEAR::Mailを使用すると簡単に送信できます。マゾな人はソケットで送信して下さい。


ちなみに携帯電話向けの大量配信はキャリアブロックによる制限があるため上記だけでは不十分です。
生半可に手を出すとIPの永久ブロックも有り得るので、ご注意下さい。
手っ取り早い方法としてはこの辺のソリューションを使うのが良いかと思います。


以上、何かのお役に立てれば幸いです。