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