Updated Dovecot 2.3.0 now getting 2 strange log errors
tony
tony at kode.email
Sat Dec 30 04:35:09 EET 2017
I did some more digging around and found this is reproducible on
multiple hosts running the same version of Dovecot/Pigeonhole/Postfix.
The problem resurfaces on any host to an account with enabled
Vacation/OOO response. The Vacation/OOO reply filter was created in
Roundcubemail, but has been fine for years. One thing to note is in
Dovecot 2.3.0 I did enable UTF8, but even if I disable UTF8 the issue
remains. What I have discovered after digging around is..
* After a fresh postfix restart all expected processes are running
without any postdrop process.
postgrey 13080 0.0 0.2 73036 21108 ? Ss 17:23 0:00
postgrey --inet=127.0.0.1:10030 --pidfile=/run/postgrey/postgrey.pid
--group=postgrey --user=postgrey --daemonize --greylist-text=Greylisted
for %s seconds --auto-whitelist-clients
root 13107 0.0 0.0 385700 108 ? Ssl 17:23 0:00
/usr/local/bin/pwhois_milter -i /run/pwhois_milter/pwhois_milter.pid -l
/var/log/mail/mail.log -u postfix -g postfix -w global.pwhois.org
root 13192 0.0 0.0 122536 5856 ? Ss 17:23 0:00
/usr/lib/postfix/bin/master -w
postfix 13193 0.0 0.1 138524 8996 ? S 17:23 0:00 pickup
-l -t unix -u
postfix 13194 0.0 0.1 138572 9088 ? S 17:23 0:00 qmgr -l
-t unix -u
postfix 13320 0.0 0.1 163908 9832 ? S 17:24 0:00
proxymap -t unix -u
postfix 13321 0.0 0.1 142756 9632 ? S 17:24 0:00 tlsmgr
-l -t unix -u
postfix 13322 0.0 0.1 138524 9280 ? S 17:24 0:00 anvil
-l -t unix -u
postfix 13352 0.0 0.1 168896 13520 ? S 17:24 0:00 smtpd
-n smtp -t inet -u -o stress= -s 2 -o content_filter=spamassassin
postfix 13539 0.0 0.1 163920 10156 ? S 17:24 0:00
trivial-rewrite -n rewrite -t unix -u
postfix 14369 0.0 0.1 164300 10340 ? S 17:26 0:00 cleanup
-z -t unix -u
postfix 14370 0.0 0.1 124180 8844 ? S 17:26 0:00 pipe -n
spamassassin -t unix user=spamd argv=/usr/bin/vendor_perl/spamc -f -e
/usr/sbin/sendmail -oi -f ${sender} ${recipient}
postfix 14375 0.0 0.1 142856 9344 ? S 17:26 0:00 lmtp -t
unix -u
vmail 14446 0.0 0.0 44008 7496 ? S 17:26 0:00
dovecot/quota-status -p postfix
* During the problem where the logs are complaining about permission
denied and sendmail exiting with signal 15 (caused by inbound email to
an address with enabled Vacation notice filter) there is a running
postdrop process and several expected processes are not running.
postgrey 13080 0.0 0.2 73036 21132 ? Ss 17:23 0:00
postgrey --inet=127.0.0.1:10030 --pidfile=/run/postgrey/postgrey.pid
--group=postgrey --user=postgrey --daemonize --greylist-text=Greylisted
for %s seconds --auto-whitelist-clients
root 13107 0.0 0.0 461572 408 ? Ssl 17:23 0:00
/usr/local/bin/pwhois_milter -i /run/pwhois_milter/pwhois_milter.pid -l
/var/log/mail/mail.log -u postfix -g postfix -w global.pwhois.org
root 13192 0.0 0.0 122536 5856 ? Ss 17:23 0:00
/usr/lib/postfix/bin/master -w
postfix 13193 0.0 0.1 138524 8996 ? S 17:23 0:00 pickup
-l -t unix -u
postfix 13194 0.0 0.1 138644 9128 ? S 17:23 0:00 qmgr -l
-t unix -u
postfix 13321 0.0 0.1 142756 9632 ? S 17:24 0:00 tlsmgr
-l -t unix -u
postfix 20793 0.0 0.1 138524 9092 ? S 17:39 0:00 anvil
-l -t unix -u
vmail 25340 0.0 0.0 44108 7664 ? S 17:46 0:00
dovecot/quota-status -p postfix
vmail 26298 0.0 0.1 122088 8536 ? S 17:49 0:00
/usr/bin/postdrop -r
——
* When the issue is not present, an email TO any address with a disabled
Vacation/OOO response filter is processed with no issues and stored in
the respective folder moved by an existing filter not related to
Vacation/OOO. Expected processes are still running (no postdrop process
which when running seems to be causing the problem)
* When the issue is not present, an email TO an address with a enabled
Vacation/OOO response filter is processed and stored in the Inbox, but
an auto-response fails to send. The result are these errors with the
permission denied being repeated every ~minute.
Dec 29 17:49:58
lmtp(jsomeone at domain.email)<26296><qbe8H6jwRlq4ZgAAUXb6+w>: Error:
sieve:
msgid=<CAE2c3QaGTiFDt5rdHEy2YeoSe+XBcB9Q5SGeOtknWKf2wgXZhQ at mail.gmail.com>:
failed to send vacation response to someone at gmail.com: <Failed to
execute sendmail> (temporary error)
Dec 29 17:50:08 lmtp: Error: postdrop: warning: mail_queue_enter: create
file maildrop/569031.26298: Permission denied
* After the problem starts again with the errors shown in the logs a
postdrop process stays running in the background. After a short while
the number of postfix processes decreases.
* If I kill the postdrop process then the logged errors stop and the
expected processes all show up again.
I am running out of ideas on why this has suddenly surfaced.
-
TC
More information about the dovecot
mailing list