Intermittent Dovecot Failure

[_jman]

Howdy, All,

Running cPanel 62.0 (build 16), CentOS 7.3 x64, on a KVM VPS. 4 Cores and 10 Gigs memory, usually don't go above .25 load and three gigs memory in use. The system is not under heavy load.

Have ConfigServer's MailScanner installed (they did the installation).

Have a particular email address that's an alias to several users (around a dozen).

Have not made any config changes recently.

Every now and again a message to the alias will not be delivered.

Can see the inbound connection in /var/log/exim_mainlog, but don't see the delivery to each user.

In /var/log/maillog, normally as soon as Mailscanner logs to MailWatch SQL, I'll see dovecot "Connect from local", then an entry for each user in the group showing the message saved to their INBOX.

But when they fail, there's no record in maillog that dovecot connected and performed the actual delivery.

Am not sure exactly where to look, as the problem is intermittent. Everything seems to always work up to the point where MailScanner logs the message. Not sure why dovecot doesn't always kick in to deliver.

Since there's plenty of memory and cpu available, if it's a setting I should bump up it wouldn't be a problem.

Any ideas why this might be happening, and more importantly, how to fix it?

Thanks!

 

[cPanelMichael]

Am not sure exactly where to look, as the problem is intermittent. Everything seems to always work up to the point where MailScanner logs the message. Not sure why dovecot doesn't always kick in to deliver.

Hello,

Have you tried temporarily disabling the MailScanner application to see if the issue persists with it disabled?

Thank you.

 

[_jman]

Hello,

Have you tried temporarily disabling the MailScanner application to see if the issue persists with it disabled?

Thank you.

No, as the problem is intermittent. Just two occurrences (that we know of) in the last month or so. Don't want to disable MailScanner for any extended period, and am not sure that's even where the problem lies.

 

[cPanelMichael]

Did you review the full /var/log/exim_mainlog output at the time this happened, or just search the log using the exigrep command? You may way to review the entire output from /var/log/exim_mainlog during the time this happened if you have not yet done so, as you may see some output that's not part of the message ID. The /var/log/exim_paniclog log may also provide some helpful output.

Thank you.

 

[_jman]

Did you review the full /var/log/exim_mainlog output at the time this happened, or just search the log using the exigrep command? You may way to review the entire output from /var/log/exim_mainlog during the time this happened if you have not yet done so, as you may see some output that's not part of the message ID. The /var/log/exim_paniclog log may also provide some helpful output.

Thank you.

The full logs. exim_paniclog is empty.

Here are some entries from exim_mainlog and maillog. Have sanitized email and IP address and other personal info...

This is one where the message did get delivered:

EXIM_MAINLOG:
2017-03-12 05:23:48 [10112] 1cn0fE-0002d6-2p <= <FROM ADDRESS> H=(<SENDER FQDN>) [<SENDER IP>]:42794 I=[<RECEIVER IP>]:25 P=esmtps X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 CV=no S=205884 M8S=0 id=!&!AAAAAAAAAAAYAAAAAAAAAIvC1ZxIy[email protected]<DOMAIN> T="<EMAIL SUBJECT>" from <email sender> for <email alias 2>
2017-03-12 05:23:48 [10112] SMTP connection from (<FQDN>) [<SENDER IP>]:42794 I=[<RECIPIENT IP>]:25 closed by QUIT
2017-03-12 05:23:54 [10292] cwd=/var/spool/MailScanner/incoming 5 args: /usr/sbin/exim -C /etc/exim_outgoing.conf -Mc 1cn0fE-0002d6-2p
2017-03-12 05:23:54 [10292] 1cn0fE-0002d6-2p => <email user 1> (<email alias distribution list 1>) <email alias 1> F=<FROM ADDRESS> P=<FROM ADDRESS> R=virtual_user T=dovecot_virtual_delivery S=209453 C="250 2.0.0 <email alias 1> jbtaELohxVhOKAAAjpNgsA Saved" QT=6s DT=0s
2017-03-12 05:23:54 [10292] 1cn0fE-0002d6-2p -> <email user 2> (<email alias distribution list 2>) <email alias 2> F=<FROM ADDRESS> P=<FROM ADDRESS> R=virtual_user T=dovecot_virtual_delivery S=209453 C="250 2.0.0 <email user 2> jbtaELohxVhOKAAAjpNgsA:2 Saved" QT=6s DT=0s
2017-03-12 05:23:54 [10292] 1cn0fE-0002d6-2p -> <email user 3> (<email alias distribution list 2>) <email alias 2> F=<FROM ADDRESS> P=<FROM ADDRESS> R=virtual_user T=dovecot_virtual_delivery S=209453 C="250 2.0.0 <email user 3> jbtaELohxVhOKAAAjpNgsA:3 Saved" QT=6s DT=0s


MAILLOG:
Mar 12 05:23:48 vps MailScanner: New Batch: Scanning 1 messages, 208258 bytes
Mar 12 05:23:48 vps MailScanner: Virus and Content Scanning: Starting
Mar 12 05:23:54 vps MailScanner: Uninfected: Delivered 1 messages
Mar 12 05:23:54 vps MailScanner: Logging message 1cn0fE-0002d6-2p to SQL
Mar 12 05:23:54 vps MailScanner: 1cn0fE-0002d6-2p: Logged to MailWatch SQL
Mar 12 05:23:54 vps dovecot: lmtp(10318): Connect from local
Mar 12 05:23:54 vps dovecot: lmtp(<email alias 1>): jbtaELohxVhOKAAAjpNgsA: msgid=<!&!AAAAAAAAAAAYAAAAAAAAAIvC1ZxIy[email protected]<DOMAIN>>: saved mail to INBOX
Mar 12 05:23:54 vps dovecot: lmtp(<email alias 2>): jbtaELohxVhOKAAAjpNgsA:2: msgid=<!&!AAAAAAAAAAAYAAAAAAAAAIvC1ZxIy[email protected]<DOMAIN>>: saved mail to INBOX
Mar 12 05:23:54 vps dovecot: lmtp(<email alias 3>): jbtaELohxVhOKAAAjpNgsA:3: msgid=<!&!AAAAAAAAAAAYAAAAAAAAAIvC1ZxIy[email protected]<DOMAIN>>: saved mail to INBOX


This is one where the message did not get delivered:
EXIM_MAINLOG:
2017-03-14 09:38:43 [24290] 1cnnb0-0006Jm-Un <= <email from address> H=<FQDN> [<SENDER IP>]:36990 I=[<RECIPIENT IP>]:25 P=esmtps X=TLSv1.2:ECDHE-RSA-AES256-GCM-SHA384:256 CV=no S=43188 M8S=0 [email protected] T="EMAIL SUBJECT" from <email from address> for <email alias>
2017-03-14 09:39:43 [24290] SMTP connection from <FQDN> [<SENDER IP>]:36990 I=[<RECIPIENT IP>]:25 closed by QUIT


MAILLOG:
Mar 14 09:38:43 vps MailScanner: New Batch: Scanning 1 messages, 45625 bytes
Mar 14 09:38:43 vps MailScanner: Virus and Content Scanning: Starting
Mar 14 09:38:45 vps MailScanner: Spam Checks: Found 1 spam messages
Mar 14 09:38:45 vps MailScanner: Logging message 1cnnb0-0006Jm-Un to SQL
Mar 14 09:38:45 vps MailScanner: 1cnnb0-0006Jm-Un: Logged to MailWatch SQL
Mar 14 09:38:49 vps MailScanner: New Batch: Scanning 1 messages, 5078 bytes

I did find the message in Mailscanner. It was marked as low spam, but was not quarrantined (and no, it wasn't in junk). So, it *should* have been delivered. However, unlike the first section, this time dovecot doesn't kick in and perform the actual delivery.

The one odd thing I do see is that in the failed message, it was a full minute before the SMTP connection was closed. MailScanner still processes the message afterward, but then it seems to just disappear.

 

[cPanelMichael]

Hello,

This is likely related to the MailScanner software, however feel free to open a support ticket if you'd like us to take a closer look. You can post the ticket number here so we can update this thread with the outcome.

Thank you.

 

[_jman]

Hello,

This is likely related to the MailScanner software, however feel free to open a support ticket if you'd like us to take a closer look. You can post the ticket number here so we can update this thread with the outcome.

Thank you.

Thanks for the reply! Will reach out to ConfigServer first...