Esse documento explica como ler os arquivos log do IceWarp Server e como reconhecer alguns dos problemas mais comuns.

Ele abrange:

1. Transferência de Serviços e Mensagens
2. Efetuando login no Merak Mail Server
3. Arquivo Log SMTP do IceWarp Mail Server
4. Logs POP3/IMAP
5. Outros logs

1. Transfêrencia de Serviços e Mensagens

O envio de mensagens está relacionado ao serviço SMTP, usado para transferir mensagens destinadas ao servidor de mail. Atingido seu destino, o servidor de mail armazena todas as mensagens até que o destinatário acesse sua caixa postal e efetue o download das mensagens a ele enviadas (servidor POP3 ou IMAP).

As mensagens são, normalmente, enviadas através de duas sessões de SMTP - primeiro o seu IceWarp Server recebe a mensagem e em seguida retransmite (faz relay) para o servidor remoto. A primeira etapa, na qual seu cliente envia até o IceWarp Server, é denominada a Server session. A segunda etapa, na qual o IceWarp Server faz a entrega da mensagem para o destino é denominada Client session. Antes de ocorrer a Client session, o servidor de mail IceWarp separa o domínio do remetente, isto é, a parte do endereço que vem após o caracter "@", e utiliza os DNSs informados no IceWarp Server (em Sistema/Conexão) para identificar o MX do destino, ou seja, aonde o domínio de destino recebe emails.

O servidor de destino aguarda, então, pela solicitação do destinatário para ler novas mensagens, usando POP3 ou IMAP.

Na figura acima, a mensagem é enviada a partir do Outlook Express  por um usuário do domínio demo.com. O destino é uma conta do domínio icewarp.com. Após receber a mensagem enviada pelo usuário cadastrado no IceWarp, é realizada query de DNS e determinado que o MX do servidor de destino, onde está icewarp.com, aponta para o IP 193.179.195.74. Logo, seu IceWarp Server se conectará a este endereço a fim de entregar a mensagem.

Vale ressaltar que o cenário detalhado é referente ao envio de um email de usuário IceWarp para um servidor externo, quando ocorre Server session (IceWarp recebe a mensagem) e Client session (IceWarp encontra MX do destino e faz relay, conectando-se ao servidor remoto para fazer a entrega). Há, ainda, dois outros cenários possíveis.

Se o usuário do IceWarp Server envia mensagem para outro usuário do mesmo servidor, não há necessidade de se realizar relay, portanto, ocorre apenas uma Server Session.

Finalmente, quando um sistema remoto (como Gmail) envia uma mensagem para usuário do seu IceWarp, ocorre também apenas uma Server session, só que dessa vez, "de fora para dentro", ou seja, um sistema remoto conecta ao seu IceWarp Server e faz a entrada. Logicamente que, o processo de query no DNS para achar MX do destino foi feito por este servidor remoto, ou seja, trata-se de uma Client session para o servidor remoto (pois o usuário precisa ter autorização para fazer relay/enviar a mensagem para domínio externo) e de uma Server session para o seu servidor, que apenas recebe a mensagem.

Em Status/Estatísticas, temos detalhamento de conexões e pico para server (entrada) e client (saída) sessions. Tendo em vista que em Sistema/Serviços, você tem apenas o total de conexões atuais e pico, porém misturando conexões de entrada e saída, sendo o default de cada uma 256 conexões. Portanto, obter detalhamento em Status/Estatísticas pode ajudar a entender se você está tendo pico na entrada (pasta temp definido em Sistema/Armazenamento ou pasta mail/_incoming, caso use MDA) ou saida (pasta mail/_outgoing).

2. Efetuando logging no IceWarp Server

O IceWarp Server possui 4 níveis de logging para cada serviço: SMTP, POP3/IMAP e Controle. Esses níveis apresentam detalhes diferentes sobre o processo de troca de mensagens, do ponto de vista do servidor. O login pode ser configurado no console do IceWarp em Sistema/Logging/Serviços:

• Sem logging (Checkboxes desmarcados)
• Modo Depurado (debug), traz comandos dos protocolos, códigos de status
• Modo Resumido (summary), informa apenas quando serviço foi iniciado, parado, atualizado e resumo de envios/recebimentos
• Depurado & Resumido, ambos anteriores (recomendado para SMTP, Control e Anti-Spam)

O nome do arquivo log consiste de um prefixo com os caracteres c (control), s (SMTP), p (POP3), m (IMAP) e números indicando a data (aaaammdd) com a extensão '.log' . Os logs ficam na pasta icewarp/logs e podem ser vistos também através do console, em Status/Logs. No caso de visualizar logs extensos através do console, recomendamos determinar um horário de início e fim, para evitar necessitar carregar um log grande no console, o que pode não ocorrer com sucesso.

Por exemplo: o arquivo s20020829.log é um arquivo log que contém eventos SMTP que ocorreram durante o dia 29 de Agosto de 2002. Os arquivos log são armazenados por x dias definidos em Sistema/Logging/Geral/Excluir arquivos log mais antigos que (dias).

Veja também FAQ sobre o módulo Analisador de logs (MLA), que ajuda bastante nas análises: https://suporte.icewarp.com.br/index.php?_m=knowledgebase&_a=viewarticle&kbarticleid=397

A seguir detalhamos o log SMTP em modo debug.

3. IceWarp Mail Server - Arquivo log SMTP

Quando um programa cliente de email (Outlook Express) envia uma mensagem, a conexão com a porta SMTP é estabelecida e uma série de comandos SMTP enviados, incluindo o header e corpo da mensagem. Todos esses comandos e result codes (códigos de resultado) podem ser vistos quando seu log SMTP está em modo depurado (debug). Isto é uma server session (sessão de servidor).

12.111.55.227 [FF07AB7B] Thu, 19 Sep 2002 00:07:36 -0400 <<< EHLO w0brcon1.warnaco.com

Da esquerda para a direita, após o IP do computador conectado, temos:

indicador único de sessão (thread) - Ex: [FF07AB7B]
horário local do servidor
Fuso horário GMT (Greenwich)
direção do comando SMTP (<<< enviado pelo client, >>> enviado pelo servidor)
comando SMTP ou resposta a um comando SMTP (código de resultado)

Códigos de resultado:

Códigos de resultados normalmente possuem três dígitos, como por exemplo 220. Segue explicação referente a tais códigos, de acordo com o primeiro número apresentado:

2xx - OK, prossiga

3xx - Aguardando o próximo comando

4xx - Erro temporário

5xx – Erro permanente

Conheça a ordem dos comandos SMTP:

HELO/EHLO (que seria a saudação entre email client e servidor ou entre servidores)
MAIL FROM: <email do remetente>
MAIL FROM: <email do destinatário>
DATA/BDAT (corpo da mensagem a anexos)
QUIT

Modo depurado de logging:

192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 Connected
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 220 mail.demo.com ESMTP Merak 5.0.1; Thu, 19 Sep 2002 12:37:24 -0400
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 <<< HELO porsche
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 250 mail.demo.com Hello porsche [192.168.0.9], pleased to meet you.
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 <<< MAIL FROM: <admin@demo.com>
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 250 2.1.0 <admin@demo.com>... Sender ok
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 <<< RCPT TO: <picv@icewarp.com>
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 250 2.1.5 <picv@icewarp.com>... Recipient ok; will forward
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 <<< DATA
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 354 Enter mail, end with "." on a line by itself
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 *** <admin@demo.com> <picv@icewarp.com> 1 439 00:00:00 OK
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 250 2.6.0 439 bytes received in 00:00:00; Message id LWJ12503 accepted for delivery
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 <<< QUIT
192.168.0.9 [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 >>> 221 2.0.0 mail.demo.com closing connection
SYSTEM [FFF6A555] Thu, 19 Sep 2002 12:37:24 -0400 Disconnected

O modo depurado é importante para se ter uma compreensão completa nos logs SMTP. Note no caso acima que a Server session é quando o IceWarp recebe a sua mensagem e verifica se você está autorizado a enviar mensagens (fazer relay).

SYSTEM [FFF6A139] Thu, 19 Sep 2002 12:37:24 -0400 16:04:04 Client session Message id LWJ12503 item 200803051604040005.tm$
SYSTEM [FFF6A139] Thu, 19 Sep 2002 12:37:24 -0400 Client session DNS server 147.32.96.3 issuing MX query for "icewarp.com"
SYSTEM [FFF6A139] Thu, 19 Sep 2002 12:37:24 -0400 Client session DNS server responded with 0 (OK) [1] - 2
SYSTEM [FFF6A139] Thu, 19 Sep 2002 12:37:24 -0400 Client session Connecting to "mail.icewarp.com"
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:24 -0400 Client session Connected
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:25 -0400 Client session <<< 220 mail.icewarp.com ESMTP Merak 5.1.2; Thu, 19 Sep 2002 12:45:26 -0400
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:25 -0400 Client session >>> EHLO mail.demo.com
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:25 -0400 Client session <<< 250 HELP
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:25 -0400 Client session >>> STARTTLS
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:25 -0400 Client session <<< 220 2.0.0 Ready to start TLS
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:25 -0400 Client session >>> EHLO mail.demo.com
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session <<< 250 HELP
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session >>> MAIL From:<admin@demo.com> SIZE=593 TRANSID=<200209191237240002@demo.com>
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session <<< 250 2.1.0 <admin@demo.com>... Sender ok
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session >>> RCPT To:<picv@icewarp.com>
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session <<< 250 2.1.5 <picv@icewarp.com>... Recipient ok
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session >>> BDAT 593 LAST
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session <<< 250 2.6.0 593 bytes received in 00:00:00;
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session *** <admin@demo.com> <picv@icewarp.com> 1 593 00:00:00 OK
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session >>> QUIT
193.179.195.74 [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session <<< 221 2.0.0 mail.icewarp.com closing connection
SYSTEM [FFF6A139] Thu, 19 Sep 2002 12:37:26 -0400 Client session Disconnected

Caso positivo, ocorre a Client session (acima), na qual o IceWarp verifica pelo MX do destino e conecta ao mesmo para entregar a mensagem. Note que o código (thread) entre colchetes muda nessas 2 sessões, entretanto, há um elo que é o message ID, neste caso, id LWJ12503.

Note também que ao realizar a query MX, o IceWarp informa:

Client session DNS server responded with 0 (OK) [1] - 2

O zero significa que a query foi bem sucedida (OK), o número 1 entre colchetes indica que um MX foi encontrado e o -2 indica que foi usado o segundo servidor DNS dentre os especificados no Merak para realizar queries de MX, em Sistema/Conexão Internet/Servidores DNS (onde você pode especificar vários servidores DNS que permitem realizar queries recursivas, separados por ponto e vírgula).

Caso tenha problemas com seu DNS (por exemplo, caso o seu DNS server não consiga achar o MX do destino ou ocorra algum erro), é sempre possível usar os 2 servidores de DNS gratuitos citados em http://www.opendns.com (208.67.222.222;208.67.220.220).

Também oferecemos ferramenta gratuita, inclusa com o IceWarp, denominada Ferramenta de DNS, em Sistema/Conexão/botão Ferramenta DNS. Com essa ferramenta você pode especificar o domínio de destino, o servidor de DNS usado e o tipo de registro, como MX, para saber se o DNS server em questão consegue detectar o MX de um domínio de destino.

Caso receba o erro Could not connect, significa que há problemas de conexão com sistemas remotos na porta 25. Veja se ocorre com todos destinos, tente por exemplo mx.uol.com.br e mail.icewarp.com.br, com o seguinte comando no DOS ou SSH:

telnet mx.uol.com.br 25

Veja se ocorre conexão e se aparece o banner de saudação. Caso negativo e tenha certeza que seu firewall não bloqueia porta 25 na saída, bem como não seja problema de rota (use o traceroute), entre em contato com o administrador do sistema remoto (obtenha dados no http://registro.br ou, para domínios internacionais, http:/www.internic.net), enviando também cópia para a conta postmaster@ do domínio de destino.

Caso necessário, simule o problema via telnet: https://suporte.icewarp.com.br/index.php?/Knowledgebase/Article/View/94/0/como-simular-envio-de-email-via-telnet

Ainda, lembre-se que você pode redirecionar e-mails via outro servidor SMTP, até conseguir contatar responsável pelo sistema remoto com as evidências: https://suporte.icewarp.com.br/index.php?/Knowledgebase/Article/View/47/0/relay-se-entrega-direta-falhar-redirecionando-emails-para-determinados-destinos-via-outro-servidor-smtp-routing

O erro abaixo, que mostra o número 0 separado por pontos, indica que seu IceWarp não consegue resolver o IP do host, referente ao MX encontrado para realizar a entrega de uma mensagem. Verifique os servidores de DNS usados em Ferramentas/Conexão e faça um teste de ping.

SYSTEM [0248] 09:04:31 Client session Could not connect to 'aspmx.l.google.com(0.0.0.0)'

4. Logs POP3/IMAP

POP3 é um protocolo antigo para recebimento de mensagens do servidor de mail. Todas as mensagens que entram aguardam no servidor até que elas sejam solicitadas pelo cliente, e recebidas no computador local do cliente. As mensagens normalmente são excluídas do servidor POP3 logo após o recebimento. Alguns programas cliente possuem a opção de manter mensagens no servidor, o que auxilia ler e-mails de locais distintos, entretanto nesse caso o programa cliente mantém um índice das mensagens lidas e já vimos problemas de corrompimento de índice ocorrerem, portanto caso precise ler mensagens em sincronia a partir de locais diferentes, recomendamos usar o protocolo IMAP.

O IMAP é um protocolo mais recente, no qual as mensagens e pastas ficam armazenadas no servidor e são sincronizadas com o programa cliente de e-mail.

Exemplo de POP3 - depurado:

Usuário user obtém 4 mensagens do servidor mail.demo.com.

127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 Connected
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK mail.demo.com Merak 5.0.1 POP3 Thu, 19 Sep 2002 13:59:16 +0200 <20020919135916@mail.demo.com>
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< USER user
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK user
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< PASS ****
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 4 messages 2371 octets
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< STAT
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 4 2371
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< LIST
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 4 messages 2371 octets
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< RETR 1
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 589 octets
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< RETR 2
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 596 octets
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< RETR 3
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 593 octets
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< RETR 4
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK 593 octets
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< DELE 1
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK Message deleted
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< DELE 2
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK Message deleted
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< DELE 3
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK Message deleted
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< DELE 4
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK Message deleted
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 <<< QUIT
127.0.0.1 [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 >>> +OK mail.demo.com closing connection
SYSTEM [FFF49979] Thu, 19 Sep 2002 13:59:16 +0200 Disconnected

Note que, após cada email recebido, há um comando DELE, que faz a exclusão do mesmo. É necessário, entretanto, receber todos emails da sua caixa postal com sucesso, para que eles sejam em seguida apagados do servidor, caso negativo o programa cliente tenta baixar tudo novamente.

4. Outros logs

Há diversos outros logs no IceWarp Server. Atenção especial aos seguintes:

- icewarp/logs/e-data.log - Log de erro, traz detalhamento referente a possíveis erros do sistema, incluindo problemas de conectividade a bancos de dados.
- icewarp/logs/phperror.log - Possíveis erros do PHP (na versão Linux, reside na pasta /merak/logs/php, veka merak/php/php.ini para achar local exato)
- icewarp/logs/maintenance/data.log - Precisa ser ativado em Sistema/Logging/aba Serviços/opção Logs de Manutenção (em versões antigas, fica em Domínios e Contas/Configurações Globais/Contas/opção Manutenção de contas). Traz detalhes a respeito de todas contas criadas, excluídas e editadas, quando um serviço é iniciado/parado, falhas de login, etc).

Tais logs podem ser vistos também em Status/Logs.

Há diversos outros logs para cada recurso, como pode ser visto no help (F1) do IceWarp, no capítulo Logging/General. Vale ressaltar que alguns logs, como antispam, antivírus, manutenção e SMS, possuem sub-pastas próprias em icewarp/logs.

Não perca também FAQ, que ao final, detalha sobre como ler logs do Anti-Spam.