Есть проект, который связан с коммерческой рассылкой. То есть люди платят, за то, чтобы получать эту рассылку.Рассылка генерируется php и с помощью библиотеки phpmailer через smtp подлючение передается posftix, который должен ее отправлять. Далее снова генерирует рассылку и снова в постфикс и так далее.
Все работало хорошо, но с недавнего времени пхп скрипт стал возращать SMTP -> ERROR: MAIL not accepted from server: 421 4.4.2 XXX.XXX Error: timeout exceeded.
ОШИБКА ВЫДАЕТСЯ НЕ СРАЗУ, А КОГДА НЕСКОЛЬКО ТЫСЯЧ ПИСЕМ БЛАГОПОЛУЧНО ОТРАВЛЕНО. Рассылка стартует в 00 часов. А ошибка появляется примерно через 2 с половиной минуты.
Полез в логи постфикса.
.........
Отправка последнего благополучного собщения
........
Jul 23 00:02:33 XXX postfix/smtpd[9915]: watchdog_pat: 0x7f317859e960
Jul 23 00:02:33 XXX postfix/smtpd[9915]: < localhost[127.0.0.1]: DATA
Jul 23 00:02:33 XXX postfix/smtpd[9915]: > localhost[127.0.0.1]: 354 End data with <CR><LF>.<CR><LF>
Потом идут другие процессы… НЕ 9915
Jul 23 00:02:34 XXX postfix/smtpd[9915]: public/cleanup socket: wanted attribute: status
Jul 23 00:02:34 XXX postfix/smtpd[9915]: input attribute name: status
Jul 23 00:02:34 XXX postfix/smtpd[9915]: input attribute value: 0
Jul 23 00:02:34 XXX postfix/smtpd[9915]: public/cleanup socket: wanted attribute: reason
Jul 23 00:02:34 XXX postfix/smtpd[9915]: input attribute name: reason
Jul 23 00:02:34 XXX postfix/smtpd[9915]: input attribute value: (end)
Jul 23 00:02:34 XXX postfix/smtpd[9915]: public/cleanup socket: wanted attribute: (list terminator)
Jul 23 00:02:34 XXX postfix/qmgr[7777]: EAEEBA028C: from=<system@XXX.XXX>, size=9759, nrcpt=1 (queue active)
Jul 23 00:02:34 XXX postfix/smtpd[9915]: input attribute name: (end)
Jul 23 00:02:34 XXX postfix/smtpd[9915]: > localhost[127.0.0.1]: 250 2.0.0 Ok: queued as EAEEBA028C
Jul 23 00:02:34 XXX postfix/smtpd[9915]: watchdog_pat: 0x7f317859e960
Потом идут другие процессы… НЕ 9915
Jul 23 00:07:34 XXX postfix/smtpd[9915]: > localhost[127.0.0.1]: 421 4.4.2 XXX.XXX Error: timeout exceeded
Jul 23 00:07:34 XXX postfix/smtpd[9915]: match_hostname: localhost ~? 127.0.0.0/8
Jul 23 00:07:34 XXX postfix/smtpd[9915]: match_hostaddr: 127.0.0.1 ~? 127.0.0.0/8
Jul 23 00:07:34 XXX postfix/smtpd[9915]: timeout after END-OF-MESSAGE from localhost[127.0.0.1]
Jul 23 00:07:34 XXX postfix/smtpd[9915]: disconnect from localhost[127.0.0.1]
Таким образом, мы видим, что разница ровно 5 минут (300 сек)
$postconf | grep -i timeout
connection_cache_protocol_timeout = 5s
daemon_timeout = 18000s
ipc_timeout = 3600s
lmtp_connect_timeout = 0s
lmtp_data_done_timeout = 600s
lmtp_data_init_timeout = 120s
lmtp_data_xfer_timeout = 180s
lmtp_lhlo_timeout = 300s
lmtp_mail_timeout = 300s
lmtp_quit_timeout = 300s
lmtp_rcpt_timeout = 300s
lmtp_rset_timeout = 20s
lmtp_starttls_timeout = 300s
lmtp_tls_session_cache_timeout = 3600s
lmtp_xforward_timeout = 300s
milter_command_timeout = 30s
milter_connect_timeout = 30s
milter_content_timeout = 300s
qmqpd_timeout = 300s
smtp_connect_timeout = 30s
smtp_data_done_timeout = 600s
smtp_data_init_timeout = 120s
smtp_data_xfer_timeout = 180s
smtp_helo_timeout = 300s
smtp_mail_timeout = 300s
smtp_quit_timeout = 300s
smtp_rcpt_timeout = 300s
smtp_rset_timeout = 20s
smtp_starttls_timeout = 300s
smtp_tls_session_cache_timeout = 3600s
smtp_xforward_timeout = 300s
smtpd_policy_service_timeout = 100s
smtpd_proxy_timeout = 100s
smtpd_starttls_timeout = 300s
smtpd_timeout = ${stress?10}${stress:300}s
smtpd_tls_session_cache_timeout = 3600s
trigger_timeout = 10s
Как я понимаю, после комманды Jul 23 00:02:34 XXX postfix/smtpd[9915]: > localhost[127.0.0.1]: 250 2.0.0 Ok: queued as EAEEBA028C когда письмо было добавлено очередь от клиента должна поступить команда MAIL FROM , однако все застревает после Jul 23 00:02:34 XXX postfix/smtpd[9915]: watchdog_pat: 0x7f317859e960.
Может быть увеличить smtp_mail_timeout ? Не уверен, что это реальная причина. Подскажите пожалуйста кто знает.
Вариант для распечатки
