Como interpretar logs de postfix no Ubuntu

1

Acabei de instalar o postfix no meu servidor que executa o Ubuntu 14.04.1 LTS. Estou um pouco confuso sobre como devo interpretar os logs do postfix localizados em /var/log/mail.log .

Em primeiro lugar, uma das razões pelas quais eu instalei o postfix foi que meus trabalhos cron poderiam enviar um e-mail contendo erros ou saída. Quando isso acontece, parece que o Gmail está bloqueando a mensagem porque acha que é um e-mail não solicitado.

Para testar isso, eu configurei um cronjob que simplesmente ecoa a palavra test . Este é o meu arquivo cron:

[email protected]
44 13 * * * echo test

Quando isso é executado, aqui está o que eu vejo nos logs do postfix:

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=<[email protected]>
Feb  7 13:44:01 prod postfix/qmgr[3539]: AE4271627DB: from=<[email protected]>, 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=<[email protected]>, 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=<[email protected]>
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=<[email protected]>, 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

Depois disso, NÃO recebo o e-mail na minha conta do Gmail e vejo uma nova mensagem de e-mail no meu servidor em /var/mail/root :

From MAILER-DAEMON  Sat Feb  7 13:44:02 2015
Return-Path: <>
X-Original-To: [email protected]
Delivered-To: [email protected]
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: [email protected] (Mail Delivery System)
Subject: Undelivered Mail Returned to Sender
To: [email protected]
Auto-Submitted: auto-replied
MIME-Version: 1.0
Content-Type: multipart/report; report-type=delivery-status;
    boundary="AE4271627DB.1423334642/server.hostname.01"
Message-Id: <[email protected]>

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

<[email protected]>: 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; [email protected]
Arrival-Date: Sat,  7 Feb 2015 13:44:01 -0500 (EST)

Final-Recipient: rfc822; [email protected]
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: <[email protected]>
Received: by server.hostname.01 (Postfix, from userid 0)
    id AE4271627DB; Sat,  7 Feb 2015 13:44:01 -0500 (EST)
From: [email protected] (Cron Daemon)
To: [email protected]
Subject: Cron <root@server> echo test
Content-Type: text/plain; charset=ANSI_X3.4-1968
X-Cron-Env: <[email protected]>
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: <[email protected]>
Date: Sat,  7 Feb 2015 13:44:01 -0500 (EST)

test

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

Eu também tenho o fail2ban instalado no servidor. Quando o fail2ban bloqueia e o endereço IP da tentativa de login no meu servidor, ele me envia um email para me avisar. Estes são alguns dos cabeçalhos da mensagem de email:

Received: by server.hostname.01 (Postfix, from userid 0)
From: Fail2Ban <[email protected]>
To: [email protected]
Message-Id: <[email protected]>

Quando procuro esse ID de mensagem nos meus registros de e-mail, vejo o seguinte:

Feb  7 11:05:36 server postfix/cleanup[22079]: 6BBAB1627DB: message-id=<[email protected]>
Feb  7 11:05:36 server postfix/qmgr[3539]: 6BBAB1627DB: from=<[email protected]>, 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=<[email protected]>, 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=<[email protected]>
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=<[email protected]>, 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

Isso parece implicar que a mensagem foi bloqueada, assim como a enviada como resultado dos trabalhos agendados, no entanto, esta mensagem aparece na minha caixa de entrada do Gmail.

Eu esperava que alguém pudesse explicar por que o fail2ban é capaz de enviar mensagens de e-mail para o Gmail com sucesso, mas minhas tarefas no cron não são. Eu também esperava que alguém pudesse me ajudar a entender exatamente o que significa essa saída de log para que eu possa entender melhor o que está acontecendo. Talvez eu tenha algo configurado errado com o postfix?

UPDATE

De acordo com os comentários, aqui está o cabeçalho completo da mensagem de uma das mensagens do fail2ban que chegou à minha caixa de entrada, mas mostra como sendo bloqueada no postfix registrado. Esta não é a mesma mensagem que foi discutida na parte anterior desta questão, mas mostra exatamente o mesmo comportamento:

Delivered-To: [email protected]
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: <[email protected]>
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 <[email protected]>;
        Sun, 08 Feb 2015 16:18:31 -0800 (PST)
Received-SPF: none (google.com: [email protected] does not designate permitted sender hosts) client-ip=104.236.71.114;
Authentication-Results: mx.google.com;
       spf=none (google.com: [email protected] does not designate permitted sender hosts) [email protected]
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 <[email protected]>
To: [email protected]
Message-Id: <[email protected]>

Aqui estão as entradas do log do postfix para a mesma mensagem:

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=<[email protected]>
Feb  8 19:18:30 prod postfix/qmgr[3539]: 103C01627EF: from=<[email protected]>, size=2156, nrcpt=1 (queue active)
Feb  8 19:18:31 prod postfix/smtp[3154]: 103C01627EF: to=<[email protected]>, 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
    
por flyingL123 07.02.2015 / 20:15

1 resposta

3

Obrigado pelo cabeçalho completo do email recebido com o ID da fila 103C01627EF e seu maillog relevante.

Este log nos informou que o Gmail rejeitou o e-mail. Em teoria, nada apareceria na sua caixa de entrada do Gmail. Mas, na realidade, o gmail pode ter aceito a mensagem e enviá-la para sua caixa de correio. A prova foi o cabeçalho completo postado acima.

O que eu quero dizer é que, às vezes, o servidor de e-mail estava se comportando mal (devido a bug, política de descarte ou outros fatores).

  • Eles podem rejeitá-lo depois do estágio DATA, mas, na verdade, aceitam o e-mail e o entregam ao destinatário apropriado. Seu caso foi o exemplo.
  • Eles podem aceitar o e-mail primeiro. Depois de digitalizá-lo com um daemon antivírus, o e-mail contém vírus. Então, eles soltam isso.

Agora, a verdadeira questão é por que o Gmail rejeita seu e-mail. Parece que o endereço do remetente [email protected] não estava corretamente no formato FQDN. Então, é normal que o Gmail rejeite seu e-mail.

    
por 09.02.2015 / 05:46