Назад | Перейти на главную страницу

Как интерпретировать журналы postfix в Ubuntu

Я только что установил postfix на свой сервер, на котором работает Ubuntu 14.04.1 LTS. Я немного смущен тем, как мне интерпретировать журналы постфиксов, расположенные в /var/log/mail.log.

Во-первых, одна из причин, по которой я установил postfix, заключалась в том, что мои задания cron могли отправлять мне электронные письма с любыми ошибками или выводами. В этом случае создается впечатление, что Gmail блокирует сообщение, поскольку считает, что это нежелательная электронная почта.

Чтобы проверить это, я создал задание cron, которое просто повторяет слово test. Это мой файл cron:

MAILTO=example@gmail.com
44 13 * * * echo test

Когда это выполняется, вот что я вижу в журналах постфиксов:

Feb  7 13:44:01 prod postfix/pickup[22580]: AE4271627DB: uid=0 from=<root>
Feb  7 13:44:01 prod postfix/cleanup[23434]: AE4271627DB: message-id=<20150207184401.AE4271627DB@server.hostname.01>
Feb  7 13:44:01 prod postfix/qmgr[3539]: AE4271627DB: from=<root@server.hostname.01>, size=565, nrcpt=1 (queue active)
Feb  7 13:44:01 prod postfix/smtp[23436]: connect to gmail-smtp-in.l.google.com[2607:f8b0:400d:c03::1b]:25: Network is unreachable
Feb  7 13:44:02 prod postfix/smtp[23436]: AE4271627DB: to=<example@gmail.com>, relay=gmail-smtp-in.l.google.com[64.233.171.27]:25, delay=1.2, delays=0.02/0.01/0.56/0.65, dsn=5.7.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.171.27] said: 550-5.7.1 [104.236.71.114      12] Our system has detected that this message is 550-5.7.1 likely unsolicited mail. To reduce the amount of spam sent to Gmail, 550-5.7.1 this message has been blocked. Please visit 550-5.7.1 http://support.google.com/mail/bin/answer.py?hl=en&answer=188131 for 550 5.7.1 more information. a3si7533488qas.19 - gsmtp (in reply to end of DATA command))
Feb  7 13:44:02 prod postfix/cleanup[23434]: E62521627DC: message-id=<20150207184402.E62521627DC@server.hostname.01>
Feb  7 13:44:02 prod postfix/qmgr[3539]: E62521627DC: from=<>, size=3228, nrcpt=1 (queue active)
Feb  7 13:44:02 prod postfix/bounce[23437]: AE4271627DB: sender non-delivery notification: E62521627DC
Feb  7 13:44:02 prod postfix/qmgr[3539]: AE4271627DB: removed
Feb  7 13:44:02 prod postfix/local[23439]: E62521627DC: to=<root@server.hostname.01>, relay=local, delay=0.01, delays=0/0.01/0/0, dsn=2.0.0, status=sent (delivered to mailbox)
Feb  7 13:44:02 prod postfix/qmgr[3539]: E62521627DC: removed

После этого я НЕ получаю электронное письмо в своей учетной записи Gmail, и я вижу новое сообщение электронной почты на своем сервере по адресу /var/mail/root:

From MAILER-DAEMON  Sat Feb  7 13:44:02 2015
Return-Path: <>
X-Original-To: root@server.hostname.01
Delivered-To: root@server.hostname.01
Received: by server.hostname.01 (Postfix)
    id E62521627DC; Sat,  7 Feb 2015 13:44:02 -0500 (EST)
Date: Sat,  7 Feb 2015 13:44:02 -0500 (EST)
From: MAILER-DAEMON@server.hostname.01 (Mail Delivery System)
Subject: Undelivered Mail Returned to Sender
To: root@server.hostname.01
Auto-Submitted: auto-replied
MIME-Version: 1.0
Content-Type: multipart/report; report-type=delivery-status;
    boundary="AE4271627DB.1423334642/server.hostname.01"
Message-Id: <20150207184402.E62521627DC@server.hostname.01>

This is a MIME-encapsulated message.

--AE4271627DB.1423334642/server.hostname.01
Content-Description: Notification
Content-Type: text/plain; charset=us-ascii

This is the mail system at host server.hostname.01.

I'm sorry to have to inform you that your message could not
be delivered to one or more recipients. It's attached below.

For further assistance, please send mail to postmaster.

If you do so, please include this problem report. You can
delete your own text from the attached returned message.

                   The mail system

<example@gmail.com>: host gmail-smtp-in.l.google.com[64.233.171.27] said:
    550-5.7.1 [104.236.71.114      12] Our system has detected that this
    message is 550-5.7.1 likely unsolicited mail. To reduce the amount of spam
    sent to Gmail, 550-5.7.1 this message has been blocked. Please visit
    550-5.7.1 http://support.google.com/mail/bin/answer.py?hl=en&answer=188131
    for 550 5.7.1 more information. a3si7533488qas.19 - gsmtp (in reply to end
    of DATA command)

--AE4271627DB.1423334642/server.hostname.01
Content-Description: Delivery report
Content-Type: message/delivery-status

Reporting-MTA: dns; server.hostname.01
X-Postfix-Queue-ID: AE4271627DB
X-Postfix-Sender: rfc822; root@server.hostname.01
Arrival-Date: Sat,  7 Feb 2015 13:44:01 -0500 (EST)

Final-Recipient: rfc822; example@gmail.com
Action: failed
Status: 5.7.1
Remote-MTA: dns; gmail-smtp-in.l.google.com
Diagnostic-Code: smtp; 550-5.7.1 [104.236.71.114      12] Our system has
    detected that this message is 550-5.7.1 likely unsolicited mail. To reduce
    the amount of spam sent to Gmail, 550-5.7.1 this message has been blocked.
    Please visit 550-5.7.1
    http://support.google.com/mail/bin/answer.py?hl=en&answer=188131 for 550
    5.7.1 more information. a3si7533488qas.19 - gsmtp

--AE4271627DB.1423334642/server.hostname.01
Content-Description: Undelivered Message
Content-Type: message/rfc822

Return-Path: <root@server.hostname.01>
Received: by server.hostname.01 (Postfix, from userid 0)
    id AE4271627DB; Sat,  7 Feb 2015 13:44:01 -0500 (EST)
From: root@server.hostname.01 (Cron Daemon)
To: example@gmail.com
Subject: Cron <root@server> echo test
Content-Type: text/plain; charset=ANSI_X3.4-1968
X-Cron-Env: <MAILTO=example@gmail.com>
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=root>
Message-Id: <20150207184401.AE4271627DB@server.hostname.01>
Date: Sat,  7 Feb 2015 13:44:01 -0500 (EST)

test

--AE4271627DB.1423334642/server.hostname.01--

У меня на сервере также установлен fail2ban. Когда fail2ban блокирует и IP-адрес от попытки входа на мой сервер, он отправляет мне электронное письмо, чтобы сообщить мне об этом. Вот некоторые из заголовков электронного сообщения:

Received: by server.hostname.01 (Postfix, from userid 0)
From: Fail2Ban <fail2ban@server.hostname.01>
To: example@gmail.com
Message-Id: <20150207160536.6BBAB1627DB@server.hostname.01>

Когда я ищу этот идентификатор сообщения в своих почтовых журналах, я вижу следующее:

Feb  7 11:05:36 server postfix/cleanup[22079]: 6BBAB1627DB: message-id=<20150207160536.6BBAB1627DB@server.spirecollective.01>
Feb  7 11:05:36 server postfix/qmgr[3539]: 6BBAB1627DB: from=<fail2ban@server.spirecollective.01>, size=1951, nrcpt=1 (queue active)
Feb  7 11:05:36 server postfix/smtp[22081]: connect to gmail-smtp-in.l.google.com[2607:f8b0:400d:c03::1b]:25: Network is unreachable
Feb  7 11:05:37 server postfix/smtp[22081]: 6BBAB1627DB: to=<example@gmail.com>, relay=gmail-smtp-in.l.google.com[64.233.171.26]:25, delay=1.7, delays=0.2/0/0.55/0.95, dsn=5.7.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.171.26] said: 550-5.7.1 [104.236.71.114      11] Our system has detected that this message is 550-5.7.1 not RFC 2822 compliant. To reduce the amount of spam sent to Gmail, 550-5.7.1 this message has been blocked. Please review 550 5.7.1 RFC 2822 specifications for more information. z1si7039105qar.33 - gsmtp (in reply to end of DATA command))
Feb  7 11:05:37 server postfix/cleanup[22079]: EC2971627DC: message-id=<20150207160537.EC2971627DC@server.spirecollective.01>
Feb  7 11:05:37 server postfix/qmgr[3539]: EC2971627DC: from=<>, size=4514, nrcpt=1 (queue active)
Feb  7 11:05:37 server postfix/bounce[22082]: 6BBAB1627DB: sender non-delivery notification: EC2971627DC
Feb  7 11:05:37 server postfix/qmgr[3539]: 6BBAB1627DB: removed
Feb  7 11:05:37 server postfix/local[22084]: EC2971627DC: to=<fail2ban@server.spirecollective.01>, relay=local, delay=0.01, delays=0/0.01/0/0, dsn=5.1.1, status=bounced (unknown user: "fail2ban")
Feb  7 11:05:37 server postfix/qmgr[3539]: EC2971627DC: removed

Похоже, это означает, что сообщение было заблокировано, как и сообщение, отправленное в результате заданий cron, однако это сообщение ДЕЙСТВИТЕЛЬНО появляется в моем почтовом ящике Gmail.

Я надеялся, что кто-нибудь сможет объяснить, почему fail2ban может успешно отправлять сообщения электронной почты в Gmail, но мои задания cron - нет. Я также надеялся, что кто-нибудь поможет мне понять, что именно означает этот вывод журнала, чтобы я мог лучше понять, что происходит. Может у меня что-то не так настроено с postfix?

ОБНОВИТЬ

Согласно комментариям, вот полный заголовок одного из сообщений fail2ban, которые попали в мой почтовый ящик, но отображаются как заблокированные в зарегистрированном постфиксе. Это не то же сообщение, что обсуждалось в предыдущей части этого вопроса, но оно показывает точно такое же поведение:

Delivered-To: example@gmail.com
Received: by 10.25.23.137 with SMTP id 9csp1267799lfx;
        Sun, 8 Feb 2015 16:18:32 -0800 (PST)
X-Received: by 10.224.96.196 with SMTP id i4mr22411932qan.44.1423441111367;
        Sun, 08 Feb 2015 16:18:31 -0800 (PST)
Return-Path: <fail2ban@prod.spirecollective.01>
Received: from prod.spirecollective.01 ([104.236.71.114])
        by mx.google.com with ESMTP id 33si12196322qgi.19.2015.02.08.16.18.30
        for <example@gmail.com>;
        Sun, 08 Feb 2015 16:18:31 -0800 (PST)
Received-SPF: none (google.com: fail2ban@prod.spirecollective.01 does not designate permitted sender hosts) client-ip=104.236.71.114;
Authentication-Results: mx.google.com;
       spf=none (google.com: fail2ban@prod.spirecollective.01 does not designate permitted sender hosts) smtp.mail=fail2ban@prod.spirecollective.01
Received: by prod.spirecollective.01 (Postfix, from userid 0)
    id 103C01627EF; Sun,  8 Feb 2015 19:18:30 -0500 (EST)
Subject: [Fail2Ban] ssh: banned 124.205.135.225 from prod.spirecollective.01
Date: Mon, 09 Feb 2015 00:18:29 +0000
From: Fail2Ban <fail2ban@prod.spirecollective.01>
To: example@gmail.com
Message-Id: <20150209001830.103C01627EF@prod.spirecollective.01>

Вот записи из журнала постфиксов для того же сообщения:

Feb  8 19:18:30 prod postfix/pickup[2360]: 103C01627EF: uid=0 from=<fail2ban>
Feb  8 19:18:30 prod postfix/cleanup[3152]: 103C01627EF: message-id=<20150209001830.103C01627EF@prod.spirecollective.01>
Feb  8 19:18:30 prod postfix/qmgr[3539]: 103C01627EF: from=<fail2ban@prod.spirecollective.01>, size=2156, nrcpt=1 (queue active)
Feb  8 19:18:31 prod postfix/smtp[3154]: 103C01627EF: to=<example@gmail.com>, relay=gmail-smtp-in.l.google.com[64.233.171.26]:25, delay=1.5, delays=0.16/0/0.55/0.77, dsn=5.7.1, status=bounced (host gmail-smtp-in.l.google.com[64.233.171.26] said: 550-5.7.1 [104.236.71.114      11] Our system has detected that this message is 550-5.7.1 not RFC 2822 compliant. To reduce the amount of spam sent to Gmail, 550-5.7.1 this message has been blocked. Please review 550 5.7.1 RFC 2822 specifications for more information. 33si12196322qgi.19 - gsmtp (in reply to end of DATA command))
Feb  8 19:18:31 prod postfix/bounce[3155]: 103C01627EF: sender non-delivery notification: 633B4162817
Feb  8 19:18:31 prod postfix/qmgr[3539]: 103C01627EF: removed

Спасибо за полный заголовок полученного письма с идентификатором очереди 103C01627EF и соответствующий почтовый журнал.

Этот журнал сообщил нам, что Gmail отклонил письмо. Теоретически ничего не будет отображаться в вашем почтовом ящике Gmail. Но на самом деле Gmail может принимать сообщение и доставьте его в свой почтовый ящик. Доказательством послужил полный заголовок, размещенный выше.

Я хочу сказать, что иногда почтовый сервер работал неправильно (из-за ошибки, политики отмены или других факторов).

  • Они могут отклонить вас после этапа ДАННЫЕ, но на самом деле они принимают электронное письмо и доставляют его соответствующему получателю. Ваш случай был примером.
  • Они могут сначала принять электронное письмо. После того, как они просканируют его с помощью антивирусного демона, оказывается, что письмо содержит вирус. Итак, они бросают это.

Теперь настоящий вопрос в том, почему Gmail отклоняет вашу электронную почту. Похоже на адрес отправителя fail2ban@prod.spirecollective.01 неправильный формат FQDN. Так что это нормально, что Gmail отклонит вашу электронную почту.