Не приходят входящие письма в Zimbra

Добрый день уважаемые читатели блога pyatilistnik.org, сегодня хочу рассказать, очередной случай из своей повседневной жизни. Есть у меня почтовый сервер Zimbra, он работает как часы и никаких нареканий на него нет. В какой-то момент обращается ко мне сотрудник, с такой вот проблемой, у него есть почтовый ящик, с него получается отправлять письма, но не получается их принимать, и его почтовый клиент Microsoft Outlook не выдавал ошибок при отправке и получении почты. Давайте разбираться по какой причине, не приходят входящие письма в Zimbra.

Первым делом, я создал тестовое сообщение на yandex почте и отправил его сотруднику, письмо не пришло. Прежде чем заморачиваться с почтовыми логами я быстро рестартанул Zimbra. Эффекта это не дало. Далее я проверил, что у других сотрудников, почта работает, как нужно, это дало возможность сузить проблему до одного конкретного ящика.

Теперь чтобы понять что произошло нужно смотреть почтовые логи, по умолчанию они находятся в папке /var/log/maillog и zimbra.log

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

Либо вот такой командой:

Я увидел, что письма доставлены, так как имеют статус 250 2.1.5 Delivery OK, но так же я обратил внимание на статус 250 2.6.0 Ok, message saved у почты, не входящий в этот домен.

Nov 21 09:45:24 mail zmconfigd[25932]: All configs fetched in 0.09 seconds
Nov 21 09:45:25 mail zmconfigd[25932]: Watchdog: service antivirus status is OK.
Nov 21 09:45:25 mail zmconfigd[25932]: All rewrite threads completed in 0.00 sec
Nov 21 09:45:25 mail zmconfigd[25932]: All restarts completed in 0.00 sec
Nov 21 09:45:26 mail postfix/smtpd[30656]: connect from forward106p.mail.yandex.net[77.88.28.109]
Nov 21 09:45:26 mail postfix/smtpd[30656]: Anonymous TLS connection established from forward106p.mail.yandex.net[77.88.28.109]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Nov 21 09:45:26 mail postfix/smtpd[30656]: A33AC101BACA8: client=forward106p.mail.yandex.net[77.88.28.109]
Nov 21 09:45:26 mail postfix/cleanup[28564]: A33AC101BACA8: message-id=<860671511247044@web12g.yandex.ru>
Nov 21 09:45:26 mail postfix/qmgr[28292]: A33AC101BACA8: from=<microsoftexam@yandex.ru>, size=1523, nrcpt=1 (queue active)
Nov 21 09:45:26 mail postfix/dkimmilter/smtpd[29661]: connect from localhost[127.0.0.1]
Nov 21 09:45:26 mail postfix/smtpd[30656]: disconnect from forward106p.mail.yandex.net[77.88.28.109]
Nov 21 09:45:26 mail postfix/dkimmilter/smtpd[29661]: Anonymous TLS connection established from localhost[127.0.0.1]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Nov 21 09:45:26 mail postfix/dkimmilter/smtpd[29661]: A5D0B101BACAD: client=localhost[127.0.0.1]
Nov 21 09:45:26 mail postfix/cleanup[31985]: A5D0B101BACAD: message-id=<860671511247044@web12g.yandex.ru>
Nov 21 09:45:26 mail opendkim[28019]: A5D0B101BACAD: no signing table match for 'microsoftexam@yandex.ru'
Nov 21 09:45:26 mail postfix/qmgr[28292]: A5D0B101BACAD: from=<microsoftexam@yandex.ru>, size=1736, nrcpt=1 (queue active)
Nov 21 09:45:26 mail postfix/smtp[29660]: A33AC101BACA8: to=<partner@pyatilistnik.org>, relay=127.0.0.1[127.0.0.1]:10030, delay=0.06, delays=0.01/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as A5D0B101BACAD)
Nov 21 09:45:26 mail postfix/qmgr[28292]: A33AC101BACA8: removed
Nov 21 09:45:26 mail postfix/dkimmilter/smtpd[29661]: disconnect from localhost[127.0.0.1]
Nov 21 09:45:26 mail amavis[27959]: (27959-03) ESMTP:[127.0.0.1]:10032 /opt/zimbra/data/amavisd/tmp/amavis-20171121T094357-27959-cI4VXxL3: <microsoftexam@yandex.ru> -> <partner@pyatilistnik.org> Received: from mail.pyatilistnik.org ([127.0.0.1]) by localhost (mail.pyatilistnik.org [127.0.0.1]) (amavisd-new, port 10032) with ESMTP for <partner@pyatilistnik.org>; Tue, 21 Nov 2017 09:45:26 +0300 (MSK)
Nov 21 09:45:26 mail amavis[27959]: (27959-03) Checking: P9OMZ8E9b4jL ORIGINATING_POST/MYNETS [127.0.0.1] <microsoftexam@yandex.ru> -> <partner@pyatilistnik.org>
Nov 21 09:45:27 mail postfix/amavisd/smtpd[29665]: 2AD6B101BACA8: client=localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/cleanup[28564]: 2AD6B101BACA8: message-id=<860671511247044@web12g.yandex.ru>
Nov 21 09:45:27 mail postfix/qmgr[28292]: 2AD6B101BACA8: from=<microsoftexam@yandex.ru>, size=2447, nrcpt=1 (queue active)
Nov 21 09:45:27 mail postfix/amavisd/smtpd[29665]: disconnect from localhost[127.0.0.1]
Nov 21 09:45:27 mail amavis[27959]: (27959-03) P9OMZ8E9b4jL FWD from <microsoftexam@yandex.ru> -> <partner@pyatilistnik.org>, BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 2AD6B101BACA8
Nov 21 09:45:27 mail amavis[27959]: (27959-03) Passed CLEAN {RelayedInternal}, ORIGINATING_POST/MYNETS LOCAL [127.0.0.1]:50906 [2a02:6b8:0:1402::22] <microsoftexam@yandex.ru> -> <partner@pyatilistnik.org>, Queue-ID: A5D0B101BACAD, Message-ID: <860671511247044@web12g.yandex.ru>, mail_id: P9OMZ8E9b4jL, Hits: -2, size: 1699, queued_as: 2AD6B101BACA8, dkim_sd=mail:yandex.ru, 460 ms
Nov 21 09:45:27 mail postfix/smtp[29663]: A5D0B101BACAD: to=<partner@pyatilistnik.org>, relay=127.0.0.1[127.0.0.1]:10032, delay=0.51, delays=0.04/0/0/0.46, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 2AD6B101BACA8)
Nov 21 09:45:27 mail postfix/qmgr[28292]: A5D0B101BACAD: removed
Nov 21 09:45:27 mail postfix/smtpd[28950]: connect from mail.pyatilistnik.org[193.106.95.105]
Nov 21 09:45:27 mail postfix/smtpd[28950]: 4F6BB101BACAD: client=mail.pyatilistnik.org[193.106.95.105]
Nov 21 09:45:27 mail postfix/cleanup[31985]: 4F6BB101BACAD: message-id=<860671511247044@web12g.yandex.ru>
Nov 21 09:45:27 mail postfix/qmgr[28292]: 4F6BB101BACAD: from=<partner@pyatilistnik.org>, size=2806, nrcpt=1 (queue active)
Nov 21 09:45:27 mail postfix/smtpd[28950]: disconnect from mail.pyatilistnik.org[193.106.95.105]
Nov 21 09:45:27 mail postfix/dkimmilter/smtpd[29661]: connect from localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/lmtp[29746]: 2AD6B101BACA8: to=<partner@pyatilistnik.org>, relay=mail.pyatilistnik.org[193.106.95.105]:7025, delay=0.16, delays=0/0/0.09/0.06, dsn=2.1.5, status=sent (250 2.1.5 Delivery OK)
Nov 21 09:45:27 mail postfix/qmgr[28292]: 2AD6B101BACA8: removed
Nov 21 09:45:27 mail postfix/dkimmilter/smtpd[29661]: Anonymous TLS connection established from localhost[127.0.0.1]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Nov 21 09:45:27 mail postfix/dkimmilter/smtpd[29661]: 5197F101BACA8: client=localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/cleanup[28564]: 5197F101BACA8: message-id=<860671511247044@web12g.yandex.ru>
Nov 21 09:45:27 mail opendkim[28019]: 5197F101BACA8: no signing table match for 'microsoftexam@yandex.ru'
Nov 21 09:45:27 mail postfix/qmgr[28292]: 5197F101BACA8: from=<partner@pyatilistnik.org>, size=3023, nrcpt=1 (queue active)
Nov 21 09:45:27 mail postfix/smtp[29660]: 4F6BB101BACAD: to=<semenov.a@pyatilistnik.info>, relay=127.0.0.1[127.0.0.1]:10030, delay=0.05, delays=0/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 5197F101BACA8)
Nov 21 09:45:27 mail postfix/dkimmilter/smtpd[29661]: disconnect from localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/qmgr[28292]: 4F6BB101BACAD: removed
Nov 21 09:45:27 mail amavis[27964]: (27964-03) ESMTP:[127.0.0.1]:10032 /opt/zimbra/data/amavisd/tmp/amavis-20171121T094355-27964-bem0MQso: <partner@pyatilistnik.org> -> <semenov.a@pyatilistnik.info> Received: from mail.pyatilistnik.org ([127.0.0.1]) by localhost (mail.pyatilistnik.org [127.0.0.1]) (amavisd-new, port 10032) with ESMTP for <semenov.a@pyatilistnik.info>; Tue, 21 Nov 2017 09:45:27 +0300 (MSK)
Nov 21 09:45:27 mail amavis[27964]: (27964-03) Checking: 0BKfkQciq2gk ORIGINATING_POST/MYNETS [127.0.0.1] <partner@pyatilistnik.org> -> <semenov.a@pyatilistnik.info>
Nov 21 09:45:27 mail postfix/amavisd/smtpd[30666]: connect from localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/amavisd/smtpd[30666]: DD7AA101BACAD: client=localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/cleanup[31985]: DD7AA101BACAD: message-id=<860671511247044@web12g.yandex.ru>
Nov 21 09:45:27 mail amavis[27964]: (27964-03) 0BKfkQciq2gk FWD from <partner@pyatilistnik.org> -> <semenov.a@pyatilistnik.info>, BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DD7AA101BACAD
Nov 21 09:45:27 mail postfix/amavisd/smtpd[30666]: disconnect from localhost[127.0.0.1]
Nov 21 09:45:27 mail postfix/qmgr[28292]: DD7AA101BACAD: from=<partner@pyatilistnik.org>, size=2991, nrcpt=1 (queue active)
Nov 21 09:45:27 mail amavis[27964]: (27964-03) Passed CLEAN {RelayedOutbound}, ORIGINATING_POST/MYNETS LOCAL [127.0.0.1]:50916 [2a02:6b8:0:1402::22] <partner@apyatilistnik.org> -> <semenov.a@pyatilistnik.info>, Queue-ID: 5197F101BACA8, Message-ID: <860671511247044@web12g.yandex.ru>, mail_id: 0BKfkQciq2gk, Hits: -2.006, size: 2983, queued_as: DD7AA101BACAD, dkim_sd=mail:yandex.ru, 534 ms
Nov 21 09:45:27 mail postfix/smtp[29663]: 5197F101BACA8: to=<semenov.a@pyatilistnik.info>, relay=127.0.0.1[127.0.0.1]:10032, delay=0.58, delays=0.04/0/0/0.53, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DD7AA101BACAD)
Nov 21 09:45:27 mail postfix/qmgr[28292]: 5197F101BACA8: removed
Nov 21 09:45:28 mail postfix/smtp[31982]: DD7AA101BACAD: to=<semenov.a@pyatilistnik.info>, relay=relay.pyatilistnik.info[138.201.59.220]:25, delay=0.8, delays=0/0.01/0.32/0.47, dsn=2.6.0, status=sent (250 2.6.0 Ok, message saved <Message-ID: <860671511247044@web12g.yandex.ru>>)
Nov 21 09:45:28 mail postfix/qmgr[28292]: DD7AA101BACAD: removed

Статус 250 2.6.0 Ok, message saved натолкнул меня на то, что та непонятная почта выступает в роли почты для перенаправления, я решил в этом убедиться и посмотреть логи в каталоге /opt/zimbra/log/mailbox.log, где я обнаружил строчку:

Теперь все стало на свои места. Заходим в веб-интерфейс нужного почтового ящика Zimbra, куда не приходят входящие письма. Переходим в "Настройки - Фильтры". Тут то и была проблема, у сотрудника был активный фильтр, который я отключил.

Фильтр был вот такого содержания и делался для переадресации на другой почтовый ящик. Фильтр, как оказалось был настроен не правильно. Как делать правильную переадресацию в Zimbra, читайте по ссылке слева.

После отключения фильтра все прекрасно заработало и входящие письма стали ходить.