qmail, mail got rejected, why ?

[devoogdt]

Hi,


This is the extract of the qmail log. What is going on ? I had this before and then I recreated the mailbox and the message did pass after that.
Spamd did reject it right ?
Is it that famous spamchecker bug ? If yes, how do I solve it ?
I am running version 9.2.1

Jan 26 07:17:09 warrior postfix/smtpd[3958]: connect from unknown[79.170.93.127]
Jan 26 07:17:09 warrior postfix/smtpd[3954]: connect from unknown[127.0.0.1]
Jan 26 07:17:09 warrior postfix/smtpd[3958]: NOQUEUE: client=unknown[79.170.93.127]
Jan 26 07:17:09 warrior postfix/smtpd[3954]: C4FB920D19: client=unknown[79.170.93.127]
Jan 26 08:17:09 warrior before-remote[4077]: check handlers for addr: [email protected]
Jan 26 08:17:09 warrior before-remote[4077]: check handlers for addr: [email protected]
Jan 26 08:17:09 warrior before-queue[4076]: check handlers for addr: [email protected]
Jan 26 08:17:09 warrior before-queue[4076]: check handlers for addr: [email protected]
Jan 26 08:17:09 warrior before-queue[4076]: Processing handlers...
Jan 26 08:17:09 warrior before-queue[4076]: hook_dir = '/usr/local/psa/handlers/before-queue'
Jan 26 08:17:09 warrior before-queue[4076]: recipient[3] = '[email protected]'
Jan 26 08:17:09 warrior before-queue[4076]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/[email protected]'
Jan 26 08:17:09 warrior before-queue[4076]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-v9ORsv/executable'
Jan 26 08:17:09 warrior qmail-queue[4078]: scan: the message(drweb.tmp.iYULVq) sent by [email protected] to [email protected] is passed
Jan 26 08:17:09 warrior before-queue[4076]: handlers_stderr: PASS
Jan 26 08:17:09 warrior before-queue[4076]: call_handlers: PASS during call '/usr/local/psa/handlers/info/20-drweb-v9ORsv/executable' handler
Jan 26 08:17:09 warrior postfix/cleanup[3956]: C4FB920D19: message-id=<[email protected]>
Jan 26 08:17:09 warrior postfix/qmgr[1272]: C4FB920D19: from=<[email protected]>, size=2778, nrcpt=1 (queue active)
Jan 26 08:17:09 warrior postfix-local[4081]: postfix-local: [email protected], [email protected], dirname=/var/qmail/mailnames
Jan 26 07:17:09 warrior postfix/smtpd[3958]: disconnect from unknown[79.170.93.127]
Jan 26 07:17:09 warrior postfix/smtpd[3954]: disconnect from unknown[127.0.0.1]
Jan 26 08:17:09 warrior postfix-local[4081]: hook_dir = '/usr/local/psa/handlers/before-local'
Jan 26 08:17:09 warrior postfix-local[4081]: recipient[3] = '[email protected]'
Jan 26 08:17:09 warrior postfix-local[4081]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/[email protected]'
Jan 26 08:17:09 warrior postfix-local[4081]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-lK0aR8/executable'
Jan 26 08:17:09 warrior spamd[1504]: spamd: got connection over /tmp/spamd_full.sock
Jan 26 08:17:09 warrior spamd[1504]: spamd: using default config for [email protected]: /var/qmail/mailnames/adriana.be/sensations/.spamassassin/user_prefs
Jan 26 08:17:09 warrior spamd[1504]: spamd: processing message <[email protected]> for [email protected]:110
Jan 26 08:17:13 warrior spamd[1504]: spamd: clean message (2.8/7.0) for [email protected]:110 in 3.5 seconds, 2809 bytes.
Jan 26 08:17:13 warrior spamd[1504]: spamd: result: . 2 - AWL,FH_DATE_PAST_20XX,RDNS_NONE scantime=3.5,size=2809,[email protected],uid=110,required_score=7.0,rhost
=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<[email protected]>,autolearn=no
Jan 26 08:17:13 warrior spamd[1497]: prefork: child states: II
Jan 26 08:17:13 warrior postfix-local[4081]: handlers_stderr: PASS
Jan 26 08:17:13 warrior postfix-local[4081]: call_handlers: PASS during call '/usr/local/psa/handlers/info/10-spam-lK0aR8/executable' handler
Jan 26 08:17:13 warrior postfix/pipe[3976]: C4FB920D19: to=<[email protected]>, relay=plesk_virtual, delay=3.7, delays=0.18/0/0/3.5, dsn=5.7.1, status=bounced (Message
can't be delivered )
Jan 26 08:17:13 warrior postfix/cleanup[3956]: 8281520D1B: message-id=<[email protected]>
Jan 26 08:17:13 warrior postfix/qmgr[1272]: 8281520D1B: from=<>, size=4608, nrcpt=1 (queue active)
Jan 26 08:17:13 warrior postfix/bounce[4070]: C4FB920D19: sender non-delivery notification: 8281520D1B
Jan 26 08:17:13 warrior postfix/qmgr[1272]: C4FB920D19: removed
Jan 26 08:17:13 warrior postfix/smtp[4051]: 8281520D1B: to=<[email protected]>, relay=zimbra.oliware.eu[79.170.93.127]:25, delay=0.17, delays=0/0/0.11/0.06, dsn=2.0.0, stat
us=sent (250 2.0.0 Ok: queued as 53570800E6)
Jan 26 08:17:13 warrior postfix/qmgr[1272]: 8281520D1B: removed

 

[IgorG]

Workaround.

 

[devoogdt]

Thanks, that solved that bug, however another error.
Spam messages should pass to the mailbox, but I can't found what is causing the bounce:

Jan 26 09:03:30 warrior postfix/smtpd[6917]: connect from unknown[74.125.78.25]
Jan 26 09:03:30 warrior postfix/smtpd[6923]: connect from unknown[127.0.0.1]
Jan 26 09:03:30 warrior postfix/smtpd[6917]: NOQUEUE: client=unknown[74.125.78.25]
Jan 26 09:03:30 warrior postfix/smtpd[6923]: 1757320D69: client=unknown[74.125.78.25]
Jan 26 10:03:30 warrior before-remote[6945]: check handlers for addr: [email protected]
Jan 26 10:03:30 warrior before-remote[6945]: check handlers for addr: [email protected]
Jan 26 10:03:30 warrior before-queue[6944]: check handlers for addr: [email protected]
Jan 26 10:03:30 warrior before-queue[6944]: check handlers for addr: [email protected]
Jan 26 10:03:30 warrior before-queue[6944]: Processing handlers...
Jan 26 10:03:30 warrior before-queue[6944]: hook_dir = '/usr/local/psa/handlers/before-queue'
Jan 26 10:03:30 warrior before-queue[6944]: recipient[3] = '[email protected]'
Jan 26 10:03:30 warrior before-queue[6944]: handlers dir = '/usr/local/psa/handlers/before-queue/recipient/[email protected]'
Jan 26 10:03:30 warrior before-queue[6944]: call_handlers: call executable = '/usr/local/psa/handlers/info/20-drweb-v9ORsv/executable'
Jan 26 10:03:30 warrior qmail-queue[6946]: scan: the message(drweb.tmp.OqO0B7) sent by [email protected] to [email protected] is passed
Jan 26 10:03:30 warrior before-queue[6944]: handlers_stderr: PASS
Jan 26 10:03:30 warrior before-queue[6944]: call_handlers: PASS during call '/usr/local/psa/handlers/info/20-drweb-v9ORsv/executable' handler
Jan 26 10:03:30 warrior postfix/cleanup[6924]: 1757320D69: message-id=<[email protected]>
Jan 26 10:03:30 warrior postfix/qmgr[5882]: 1757320D69: from=<[email protected]>, size=2079, nrcpt=1 (queue active)
Jan 26 09:03:30 warrior postfix/smtpd[6923]: disconnect from unknown[127.0.0.1]
Jan 26 10:03:30 warrior postfix-local[6947]: postfix-local: [email protected], [email protected], dirname=/var/qmail/mailnames
Jan 26 10:03:30 warrior postfix-local[6947]: hook_dir = '/usr/local/psa/handlers/before-local'
Jan 26 10:03:30 warrior postfix-local[6947]: recipient[3] = '[email protected]'
Jan 26 10:03:30 warrior postfix-local[6947]: handlers dir = '/usr/local/psa/handlers/before-local/recipient/[email protected]'
Jan 26 10:03:30 warrior postfix-local[6947]: call_handlers: call executable = '/usr/local/psa/handlers/info/10-spam-lK0aR8/executable'
Jan 26 10:03:30 warrior spamd[6405]: spamd: got connection over /tmp/spamd_full.sock
Jan 26 10:03:30 warrior spamd[6405]: spamd: using default config for [email protected]: /var/qmail/mailnames/adriana.be/sensations/.spamassassin/user_prefs
Jan 26 10:03:30 warrior spamd[6405]: spamd: processing message <[email protected]> for [email protected]:110
Jan 26 10:03:30 warrior spamd[6405]: spamd: clean message (0.1/7.0) for [email protected]:110 in 0.2 seconds, 2139 bytes.
Jan 26 10:03:30 warrior spamd[6405]: spamd: result: . 0 - HTML_MESSAGE,RDNS_NONE scantime=0.2,size=2139,[email protected],uid=110,required_score=7.0,rhost=localhost,raddr=127.0.0.1,rport=/tmp/spamd_full.sock,mid=<[email protected]>,autolearn=no
Jan 26 10:03:30 warrior postfix-local[6947]: handlers_stderr: PASS
Jan 26 10:03:30 warrior postfix-local[6947]: call_handlers: PASS during call '/usr/local/psa/handlers/info/10-spam-lK0aR8/executable' handler
Jan 26 10:03:30 warrior spamd[6404]: prefork: child states: II
Jan 26 10:03:30 warrior postfix/pipe[6925]: 1757320D69: to=<[email protected]>, relay=plesk_virtual, delay=0.32, delays=0.09/0/0/0.23, dsn=5.7.1, status=bounced (Message can't be delivered )
Jan 26 10:03:30 warrior postfix/cleanup[6924]: 659AE20D6D: message-id=<[email protected]>
Jan 26 10:03:30 warrior postfix/qmgr[5882]: 659AE20D6D: from=<>, size=3843, nrcpt=1 (queue active)
Jan 26 10:03:30 warrior postfix/bounce[6952]: 1757320D69: sender non-delivery notification: 659AE20D6D
Jan 26 10:03:30 warrior postfix/qmgr[5882]: 1757320D69: removed
Jan 26 10:03:31 warrior postfix/smtp[6954]: 659AE20D6D: to=<[email protected]>, relay=gmail-smtp-in.l.google.com[209.85.218.15]:25, delay=0.85, delays=0.01/0.01/0.05/0.78, dsn=2.0.0, status=sent (250 2.0.0 OK 1264496611 23si6878778bwz.78)
Jan 26 10:03:31 warrior postfix/qmgr[5882]: 659AE20D6D: removed

 

[GlennV]

I had the same error today, and it turned out that this mailbox was just full.

Might be worth checking that out =)