10.4.4 Update #29 broke Qmail

[Freddie Bleiweiss]

OS Linux 2.6.32-220.13.1.el6.x86_64

The auto update to 10.4.4 Update #29 broke Qmail. The server now rejects all incoming SMTP email (from numerous domains) with the following message:

Remote host said: 554 mail server permanently rejected message (#5.3.0) [BODY]

From the maillog:

May 6 00:11:26 web2 qmail-queue-handlers[28110]: handlers_stderr: Mail handler call failed. Error occured during execv(/usr/local/psa/handlers/hooks/check-quota):#012P
ermission denied.
May 6 00:11:26 web2 qmail-queue-handlers[28111]: Error during 'check-quota' handler
May 6 00:11:26 web2 spf filter[28112]: Starting spf filter...
May 6 00:11:26 web2 spf filter[28112]: Error code: (26) DNS lookup failure
May 6 00:11:26 web2 spf filter[28112]: Failed to query MAIL-FROM: Temporary DNS failure for 'yahoo.com'.
May 6 00:11:26 web2 spf filter[28112]: SPF result: tempfail
May 6 00:11:26 web2 qmail-queue-handlers[28111]: handlers_stderr: DEFER
May 6 00:11:26 web2 qmail-queue-handlers[28111]: DEFER during call 'spf' handler
May 6 00:11:26 web2 qmail-queue-handlers[28110]: _mh_fork(): unrecognized status code '61'
May 6 00:11:26 web2 qmail-queue-handlers[28110]: Error during 'check-quota' handler
May 6 00:11:26 web2 qmail-queue-handlers[28110]: System error (/usr/local/psa/handlers/spool/messageecE5n3): No such file or directory
May 6 00:11:26 web2 qmail-queue-handlers[28110]: files: cannot open file /usr/local/psa/handlers/spool/messageecE5n3 with message - No such file or directory
May 6 00:11:26 web2 qmail-queue-handlers[28110]: mailsend: cannot write message from file to submitter /var/qmail/bin/qmail-queue.moved
May 6 00:11:26 web2 qmail-queue-handlers[28110]: starter: submitter[28113] exited normally
May 6 00:11:26 web2 qmail-queue-handlers[28110]: cannot reinject message to mail system

May 6 00:40:50 web2 qmail-queue-handlers[29117]: Error during 'check-quota' handler
May 6 00:40:50 web2 qmail-queue-handlers[29116]: handlers_stderr: Mail handler call failed. Error occured during execv(/usr/local/psa/handlers/hooks/check-quota):#012P
ermission denied.
May 6 00:40:50 web2 spf filter[29118]: Starting spf filter...
May 6 00:40:50 web2 spf filter[29118]: Error code: (26) DNS lookup failure
May 6 00:40:50 web2 spf filter[29118]: Failed to query MAIL-FROM: Temporary DNS failure for 'yahoo.com'.
May 6 00:40:50 web2 spf filter[29118]: SPF result: tempfail
May 6 00:40:50 web2 qmail-queue-handlers[29117]: handlers_stderr: DEFER
May 6 00:40:50 web2 qmail-queue-handlers[29117]: DEFER during call 'spf' handler
May 6 00:40:50 web2 qmail-queue-handlers[29116]: _mh_fork(): unrecognized status code '61'
May 6 00:40:50 web2 qmail-queue-handlers[29116]: Error during 'check-quota' handler
May 6 00:40:50 web2 qmail-queue-handlers[29116]: System error (/usr/local/psa/handlers/spool/messageNLBJA5): No such file or directory
May 6 00:40:50 web2 qmail-queue-handlers[29116]: files: cannot open file /usr/local/psa/handlers/spool/messageNLBJA5 with message - No such file or directory
May 6 00:40:50 web2 qmail-queue-handlers[29116]: mailsend: cannot write message from file to submitter /var/qmail/bin/qmail-queue.moved
May 6 00:40:50 web2 qmail-queue-handlers[29116]: starter: submitter[29119] exited normally
May 6 00:40:50 web2 qmail-queue-handlers[29116]: cannot reinject message to mail system

Any ideas?

 

[SBCTEC]

I am experiecing the same problem..


May 7 08:21:19 plsk0 /var/qmail/bin/relaylock[29875]: /var/qmail/bin/relaylock: mail from xxx.xxx.xxx.xxx:53807 (xxx-xxx-xxx-xxx-newengland.hfc.comcastbusiness.net)
May 7 08:21:19 plsk0 smtp_auth: SMTP connect from xxx-xxx-xxx-xxx-newengland.hfc.comcastbusiness.net [xxx.xxx.xxx.xxx]
May 7 08:21:19 plsk0 smtp_auth: SMTP user [email protected] : logged in from xxx.xxx.xxx.xxx-newengland.hfc.comcastbusiness.net [xxx.xxx.xxx.xxx]
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: Handlers Filter before-queue for qmail started ...
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: [email protected]
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: [email protected]
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: handlers_stderr: Mail handler call failed. Error occured during execv(/usr/local/psa/handlers/hooks/check-quota):#012Permission denied
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: handlers_stderr: .
May 7 08:21:19 plsk0 qmail-queue-handlers[29879]: Error during 'check-quota' handler
May 7 08:21:19 plsk0 spf filter[29880]: Starting spf filter...
May 7 08:21:19 plsk0 qmail-queue-handlers[29879]: handlers_stderr: SKIP
May 7 08:21:19 plsk0 qmail-queue-handlers[29879]: SKIP during call 'spf' handler
May 7 08:21:19 plsk0 qmail-queue-handlers[29879]: starter: submitter[29881] exited normally
May 7 08:21:19 plsk0 qmail: 1336393279.735835 new msg 2492318
May 7 08:21:19 plsk0 qmail: 1336393279.736085 info msg 2492318: bytes 4552 from <[email protected]> qp 29881 uid 2020
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: PASS during call 'check-quota' handler
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: Unable to rename '/usr/local/psa/handlers/spool/messageGRGVF7' file: No such file or directory
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: System error (/usr/local/psa/handlers/spool/messageGRGVF7): No such file or directory
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: files: cannot open file /usr/local/psa/handlers/spool/messageGRGVF7 with message - No such file or directory
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: mailsend: cannot write message from file to submitter /var/qmail/bin/qmail-queue.moved
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: starter: submitter[29882] exited normally
May 7 08:21:19 plsk0 qmail-queue-handlers[29878]: cannot reinject message to mail system
May 7 08:21:19 plsk0 qmail: 1336393279.777224 starting delivery 1: msg 2492318 to local [email protected]
May 7 08:21:19 plsk0 qmail: 1336393279.777265 status: local 1/10 remote 0/20
May 7 08:21:19 plsk0 qmail-local-handlers[29883]: Handlers Filter before-local for qmail started ...
May 7 08:21:19 plsk0 qmail-local-handlers[29883]: [email protected]
May 7 08:21:19 plsk0 qmail-local-handlers[29883]: [email protected]
May 7 08:21:19 plsk0 qmail-local-handlers[29883]: mailbox: /var/qmail/mailnames/other.com/to
May 7 08:21:19 plsk0 spamd[19551]: spamd: got connection over /tmp/spamd_full.sock
May 7 08:21:19 plsk0 spamd[19551]: spamd: using default config for [email protected]: /var/qmail/mailnames/other.com/to/.spamassassin/user_prefs
May 7 08:21:19 plsk0 spamd[19551]: spamd: processing message <[email protected]> for [email protected]:110
May 7 08:21:20 plsk0 spamd[19551]: spamd: clean message (-2.9/4.0) for [email protected]:110 in 0.5 seconds, 4552 bytes.
May 7 08:21:20 plsk0 spamd[19551]: spamd: result: . -2 - ALL_TRUSTED,BAYES_00,HTML_MESSAGE scantime=0.5,size=4552,[email protected],uid=110,required_score=4.0,rhost=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<[email protected]>,bayes=0.000000,autolearn=ham

 

[rescarcega]

Same problem incoming and outgoing emails rejected

I'm having the same problem after update #29.

---------------------------------------------------------------
PRODUCT, VERSION, OPERATING SYSTEM, ARCHITECTURE
Plesk 10.4.4, Microupdate #29, Linux Centos 2.6.32-71.el6.x86_64

PROBLEM DESCRIPTION
After updating last microupdate #29 (updated automatically), qmail started rejecting sending and receiving emails with the following message:
Remote host said: 554 mail server permanently rejected message (#5.3.0)

The email is been sent and received but the sender receives the message above.

STEPS TO REPRODUCE

You can email to [email protected] and you'll get the error message

ACTUAL RESULT

EXPECTED RESULT




ANY ADDITIONAL INFORMATION
--------------------------------------------------------------




This is the mail log file:


May 7 13:00:14 server6 qmail-queue-handlers[18461]: [email protected]
May 7 13:00:14 server6 qmail-queue-handlers[18461]: [email protected]
May 7 13:00:14 server6 qmail-queue-handlers[18461]: [email protected]
May 7 13:00:14 server6 qmail-queue-handlers[18461]: handlers_stderr: Mail handler call failed. Error occured during execv(/usr/local/psa/handlers/hooks/check-quota):#012Permission denied
May 7 13:00:14 server6 qmail-queue-handlers[18461]: handlers_stderr: .
May 7 13:00:14 server6 qmail-queue-handlers[18660]: Error during 'check-quota' handler
May 7 13:00:14 server6 qmail-queue-handlers[18660]: handlers_stderr: Mail handler call failed. Error occured during execv(/usr/local/psa/handlers/hooks/check-quota):#012Permission denied
May 7 13:00:14 server6 qmail-queue-handlers[18661]: Error during 'check-quota' handler
May 7 13:00:14 server6 qmail-queue-handlers[18660]: handlers_stderr: .
May 7 13:00:14 server6 qmail-queue-handlers[18661]: starter: submitter[18662] exited normally
May 7 13:00:14 server6 qmail-queue-handlers[18660]: PASS during call 'check-quota' handler
May 7 13:00:14 server6 qmail-queue-handlers[18660]: Unable to rename '/usr/local/psa/handlers/spool/messageuzhE2M' file: No such file or directory
May 7 13:00:14 server6 qmail-queue-handlers[18660]: files: cannot open file /usr/local/psa/handlers/spool/messageuzhE2M with message - No such file or directory
May 7 13:00:14 server6 qmail-queue-handlers[18660]: mailsend: cannot write message from file to submitter /var/qmail/bin/qmail-queue.moved
May 7 13:00:14 server6 qmail-queue-handlers[18660]: starter: submitter[18663] exited normally
May 7 13:00:14 server6 qmail-queue-handlers[18660]: cannot reinject message to mail system



I've tried running mchk, checking permissions.

This are the permissions in /var/qmail/bin/qmail-queue*:

ls -la /var/qmail/bin/qmail-queue*
-r-x--s--x. 1 mhandlers-user popuser 49080 Nov 2 2011 /var/qmail/bin/qmail-queue
-r-s--x--x. 1 qmailq qmail 19256 Nov 1 2011 /var/qmail/bin/qmail-queue.moved

 

[rescarcega]

Changing qmail to postfix solved the problem. Going back to qmail, the problem persists. So I stayed with postfix.

I would like Parallels to issue a fix soon.

 

[BarendH]

Problem after update #29.

1. qmail refuses to handle incoming mail
- will accept mail from other smtp-servers
- refuses to deliver to local users

2. qmail refuses to handle outgoing mail;
- mail that originates on the server (e.g. from an PHP script)
- all bounce messages as a result of 1.


from log:
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: Handlers Filter before-queue for qmail started ...
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: [email protected]
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: [email protected]
May 9 20:18:37 wdxs2 greylisting filter[9335]: Starting greylisting filter...
May 9 20:18:37 wdxs2 greylisting filter[9335]: list type: white, from: [email protected], match string: .*@xxxxxxxxxx\.nl
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: handlers_stderr: SKIP
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: SKIP during call 'grey' handler
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: handlers_stderr: SKIP
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: SKIP during call 'check-quota' handler
May 9 20:18:37 wdxs2 spf filter[9337]: Starting spf filter...
May 9 20:18:37 wdxs2 spf filter[9337]: SPF result: neutral
May 9 20:18:37 wdxs2 spf filter[9337]: SPF status: PASS
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: handlers_stderr: PASS
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: PASS during call 'spf' handler
May 9 20:18:37 wdxs2 qmail-queue-handlers[9333]: starter: submitter[9338] exited normally
May 9 20:18:37 wdxs2 qmail: 1336587517.947014 new msg 31035317
May 9 20:18:37 wdxs2 qmail: 1336587517.947067 info msg 31035317: bytes 7786 from <[email protected]> qp 9338 uid 2020
May 9 20:18:37 wdxs2 qmail: 1336587517.949673 starting delivery 2: msg 31035317 to local [email protected]
May 9 20:18:37 wdxs2 qmail: 1336587517.949709 status: local 1/10 remote 0/20
May 9 20:18:37 wdxs2 qmail-local-handlers[9339]: Handlers Filter before-local for qmail started ...
May 9 20:18:37 wdxs2 qmail-local-handlers[9339]: cannot create temporary file - (13) Permission denied
May 9 20:18:37 wdxs2 qmail-local-handlers[9339]: cannot read message from stdin
May 9 20:18:37 wdxs2 qmail: 1336587517.951675 delivery 2: failure:
May 9 20:18:37 wdxs2 qmail: 1336587517.951984 status: local 0/10 remote 0/20
May 9 20:18:37 wdxs2 qmail-queue-handlers[9340]: Handlers Filter before-queue for qmail started ...
May 9 20:18:37 wdxs2 qmail-queue-handlers[9340]: cannot create temporary file - (13) Permission denied
May 9 20:18:37 wdxs2 qmail-queue-handlers[9340]: cannot read message from stdin
May 9 20:18:37 wdxs2 qmail: 1336587517.953683 warning: trouble injecting bounce message, will try later


Solution that seems to works is changing some permissions;

Before:

root@wdxs2:/usr/local/psa/handlers>ls -lah
drwxrwx--- 8 root root 4.0K Jan 26 05:36 .
drwxr-xr-x 17 root root 4.0K May 7 13:26 ..
drwxr-xr-x 3 root root 60 Jan 26 05:36 before-local
drwxr-xr-x 4 root root 80 Jan 26 05:36 before-queue
drwxr-xr-x 3 root root 60 Jan 26 05:36 before-remote
drwxr-x--- 2 root root 4.0K May 9 04:07 hooks
drwxr-xr-x 1061 root root 21K Jan 26 05:36 info
drwxrwx--- 2 popuser popuser 60 May 9 20:03 spool

After:

drwxr-xr-x 8 root root 4.0K May 9 20:04 .
drwxr-xr-x 17 root root 4.0K May 7 13:26 ..
drwxr-xr-x 3 root root 60 Jan 26 05:36 before-local
drwxr-xr-x 4 root root 80 Jan 26 05:36 before-queue
drwxr-xr-x 3 root root 60 Jan 26 05:36 before-remote
drwxr-xr-x 2 root root 4.0K May 9 04:07 hooks
drwxr-xr-x 1061 root root 21K Jan 26 05:36 info
drwxrwx--- 2 popuser popuser 60 May 10 00:06 spool

 

[IgorG]

Permissions are set properly. However, permission denied error originates not from conventional UNIX file permissiosns but from SELinux. You can find corresponding error messages in /var/log/audit/audit.log
For fixing this problem try to run command:

restorecon /usr/local/psa/handlers/hooks/check-quota

I hope it will help.

 

[BarendH]

Igor,

We're running CentOS 5 2.6.18-274.12.1.el5

As far as I can tell SELinux is not configured...

/etc/selinux/config;
SELINUX=disabled

> getenforce
Disabled

 

[JurgenN]

I had the same situation. I first read somewhere that disabling Selinux would solve the problem. I tried that and it worked. Then I read the fix by IgorG, so I tried that and enabled Selinux again. Problem is still gone, so I guess Igors solution did the trick.

It cost me about 10 hours to try to solve the mailproblem until I found this simple solution, only becasue I searched for the line "554 mail server permanently rejected message (#5.3.0)"....

So I'm both irritated that the last update had this bug, and glad that it seems to be solved now.

 

[DeaneM]

None of the fixes were working for me either, until I also made sure that the handlers directory (under /usr/local/psa/) was 755 (and the hooks directory below it).

BUT.... aliases still don't work. I can send to the actual mail address, but I try to send to an alias of that account and it dies.

 

[______FK]

Any news

Are there any news to get the problem fixed ?

 

[DanijelD]

This happened to me too after applying a few fixes to my Plesk 11.0.9 yesterday.

I had to change permissions to "handlers" and "hooks" folders to 755. Now it works.

If you have this in your maillog file then you can try the same solution:

Error during 'check-quota' handler
Nov 12 15:55:39 MyDomain qmail-queue-handlers[9334]: handlers_stderr: Mail handler call failed. Error occured during execv(/usr/local/psa/handlers/hooks/check-quota): Permission denied.

Why isn't this fixed by Plesk updates in the meantime? I lost whole day fixing it... let me just mention that I received 20.000 email bounces because of this.