[qmailtoaster] Re: Where did the mail go?

Thu, 06 May 2010 22:35:29 -0700

I guess the answer to your question is, "back to the sender". Now why it was rejected is another question that I'm afraid might never be answered. As I said, that old of a version would reject messages with no log message explaining that the message was rejected or why.
That's a pretty old version you're running, and logging has improved a bit since that version. QTP has many improvements as well. I would strongly recommend upgrading. Which OS version are you running? 


If you're on COS4, I would install the qmailtoaster-plus.repo package 
(see http://qtp.qmailtoaster.com/), then

# yum update
then
# qtp-newmodel
That should bring you up to date on everything.


I'd also recommend installing spamdyke, which is as easy as running the 
qtp-install-spamdyke script (in more recent versions of QTP).


--
-Eric 'shubes'

Ulrik Kofod wrote:

In the complaint I got he said that his fathers mail was rejected and that his 
fathers mail client deleted his mail address from the address book. Not sure 
what mailclient he is using or if any mailclients cleanup address books on 
permanent errors?

 
The mail server has been running for 4-5 years now, and the only package I have updated recently is clamav because it started rejecting all mails. in that case there was log messages... a lot of log messages :)  


# rpm -qa | grep toaster | sort
autorespond-toaster-2.0.4-1.2.8
clamav-toaster-0.96.0-1.3.35
control-panel-toaster-0.5-1.2.8
courier-imap-toaster-3.0.8-1.2.9
daemontools-toaster-0.76-1.2.9
ezmlm-cgi-toaster-0.53.324-1.2.10
ezmlm-toaster-0.53.324-1.2.10
isoqlog-toaster-2.1-1.2.9
maildrop-toaster-1.8.1-1.2.10
maildrop-toaster-devel-1.8.1-1.2.10
qmailadmin-toaster-1.2.9-1.2.11
qmailmrtg-toaster-4.2-1.2.8
qmail-pop3d-toaster-1.03-1.2.10
qmail-toaster-1.03-1.2.10
qmailtoaster-plus-0.2.7-1.3.9
simscan-toaster-1.1-1.2.6
spamassassin-toaster-3.1.0-1.2.11
squirrelmail-toaster-1.4.5-1.2.13
ucspi-tcp-toaster-0.88-1.2.9
vpopmail-toaster-5.4.10-1.2.10
vqadmin-toaster-2.3.4-1.2.12

# cat /var/qmail/control/spfbehavior
1


regards

Den 07/05/2010 kl. 00.10 skrev Eric Shubert:


I must've missed that part about the sender getting an error. :(

That must've been a bounce then. I'm guessing that it was bounced from his smtp 
server, in which case it would have been rejected by QMT. Strange though that 
QMT doesn't show any sort of rejection in the smtp, spam or clam logs 
(especially the smtp log).

Another strange thing is that I'm not seeing any simscan messages in the smtp 
log. Do you have any simscan messages in your smtp log at all?

I do seem to recall that earlier versions of QMT (like up to '07 or so) would 
not log certain rejections, including SPF rejections. What versions of QMT 
packages are you running?
# rpm -qa | grep toaster | sort

Just for yuks, what's in your /var/qmail/control/spfbehavior file?

--
-Eric 'shubes'


Ulrik Kofod wrote:

no, that was the first thing I did check with a "qmailctl queue".
# qmHandle -l
Messages in local queue: 0
Messages in remote queue: 0
I also checked the maildrop log and cron log to see if something was running at 
the time, but found nothing unusual.
I'll try an see if I can get the error message from the sender, that he says he 
got.
regards
Den 06/05/2010 kl. 22.39 skrev Eric Shubert:

Are they in the queue?
# qmHandle -l
I'm guessing so.

Sometimes the queue(s) can be corrupted such that delivery doesn't get 
triggered. Running
# qmailctl stop
# queue_repair.py --repair
# qmailctl start
usually fixes that up.

qmHandle and queue_repair.py are included with the qmailtoaster-plus package 
(http://qtp.qmailtoaster.com/).

Ulrik Kofod wrote:

Sorry. Here is everything unmodified that happened between 00:59:59 and 
01:59:59 May 5th. And as you can see it isn't caused by heavy load on qmail.
It is the two mails that is seen in the smtp, clamd and spamd log at 01:04:05 
and 01:08:50 that is missing in the send log?
Any suggestions on where I can find out what happened to the two mails? # cat current 
|tai64nlocal| grep "2010-05-05 01"  2010-05-05 01:04:03.684116500 tcpserver: 
status: 1/100
2010-05-05 01:04:03.687184500 tcpserver: pid 1088 from 213.173.243.250
2010-05-05 01:04:03.687193500 tcpserver: ok 1088 
rock.cybersite.dk:10.5.1.111:25 :213.173.243.250::59055
2010-05-05 01:04:05.201492500 CHKUSER accepted rcpt: from <[email protected]::> remote 
<parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt <[email protected]> : found 
existing recipient
2010-05-05 01:04:06.583890500 tcpserver: end 1088 status 0
2010-05-05 01:04:06.583900500 tcpserver: status: 0/100
2010-05-05 01:08:48.515885500 tcpserver: status: 1/100
2010-05-05 01:08:48.515893500 tcpserver: pid 1247 from 213.173.243.250
2010-05-05 01:08:48.515898500 tcpserver: ok 1247 
rock.cybersite.dk:10.5.1.111:25 :213.173.243.250::51063
2010-05-05 01:08:49.524959500 CHKUSER accepted rcpt: from <[email protected]::> remote 
<parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt <[email protected]> : found 
existing recipient
2010-05-05 01:08:50.829484500 tcpserver: end 1247 status 0
2010-05-05 01:08:50.829494500 tcpserver: status: 0/100
2010-05-05 01:46:21.772888500 tcpserver: status: 1/100
2010-05-05 01:46:21.773304500 tcpserver: pid 2392 from 213.173.243.250
2010-05-05 01:46:21.773341500 tcpserver: ok 2392 
rock.cybersite.dk:10.5.1.111:25 :213.173.243.250::59489
2010-05-05 01:46:22.732213500 CHKUSER accepted rcpt: from <[email protected]::> 
remote <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt <[email protected]> 
: found existing recipient
2010-05-05 01:46:24.651675500 tcpserver: end 2392 status 0
2010-05-05 01:46:24.651684500 tcpserver: status: 0/100
2010-05-05 01:50:00.548076500 tcpserver: status: 1/100
2010-05-05 01:50:00.548084500 tcpserver: pid 2480 from 213.173.243.250
2010-05-05 01:50:00.548089500 tcpserver: ok 2480 
rock.cybersite.dk:10.5.1.111:25 :213.173.243.250::50607
2010-05-05 01:50:01.061112500 CHKUSER accepted rcpt: from 
<[email protected]::> remote 
<parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt <[email protected]> : 
found existing recipient
2010-05-05 01:50:02.204316500 tcpserver: end 2480 status 0
2010-05-05 01:50:02.204325500 tcpserver: status: 0/100
# cat /var/log/qmail/clamd/current |tai64nlocal| grep "2010-05-05 01"  
2010-05-05 01:01:30.131725500 SelfCheck: Database status OK.
2010-05-05 01:04:05.830571500 
/var/qmail/simscan/1273014245.202707.1091/msg.1273014245.202707.1091: OK
2010-05-05 01:08:50.065474500 
/var/qmail/simscan/1273014529.526208.1249/msg.1273014529.526208.1249: OK
2010-05-05 01:18:49.904600500 SelfCheck: Database status OK.
2010-05-05 01:28:49.814407500 SelfCheck: Database status OK.
2010-05-05 01:38:49.724193500 SelfCheck: Database status OK.
2010-05-05 01:46:22.841242500 
/var/qmail/simscan/1273016782.733385.2394/msg.1273016782.733385.2394: OK
2010-05-05 01:46:22.841678500 
/var/qmail/simscan/1273016782.733385.2394/addr.1273016782.733385.2394: OK
2010-05-05 01:50:01.247525500 SelfCheck: Database status OK.
2010-05-05 01:50:01.328281500 
/var/qmail/simscan/1273017001.63281.2482/msg.1273017001.63281.2482: OK
2010-05-05 01:50:01.328651500 
/var/qmail/simscan/1273017001.63281.2482/addr.1273017001.63281.2482: OK
# cat /var/log/qmail/spamd/current |tai64nlocal| grep "2010-05-05 01"  
2010-05-05 01:04:05.840515500 [7017] info: spamd: connection from localhost.localdomain 
[127.0.0.1] at port 34516
2010-05-05 01:04:05.953081500 [7017] info: spamd: processing message 
<[email protected]> for clamav:89
2010-05-05 01:04:06.456367500 [7017] info: spamd: clean message (-2.0/5.0) for 
clamav:89 in 0.6 seconds, 253639 bytes.
2010-05-05 01:04:06.456866500 [7017] info: spamd: result: . -2 - AWL,BAYES_00 
scantime=0.6,size=253639,user=clamav,uid=89,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=34516,mid=<[email protected]>,bayes=1.11022302462516e-16,autolearn=ham
2010-05-05 01:04:06.670380500 [3578] info: prefork: child states: II
2010-05-05 01:08:50.077026500 [7017] info: spamd: connection from 
localhost.localdomain [127.0.0.1] at port 34606
2010-05-05 01:08:50.187527500 [7017] info: spamd: processing message 
<[email protected]> for clamav:89
2010-05-05 01:08:50.688944500 [7017] info: spamd: clean message (-2.0/5.0) for 
clamav:89 in 0.6 seconds, 254865 bytes.
2010-05-05 01:08:50.689354500 [7017] info: spamd: result: . -1 - 
AWL,BAYES_00,HTML_70_80,HTML_MESSAGE 
scantime=0.6,size=254865,user=clamav,uid=89,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=34606,mid=<[email protected]>,bayes=1.66533453693773e-16,autolearn=ham
2010-05-05 01:08:50.902787500 [3578] info: prefork: child states: II
2010-05-05 01:46:22.849608500 [7017] info: spamd: connection from 
localhost.localdomain [127.0.0.1] at port 35217
2010-05-05 01:46:22.864569500 [7017] info: spamd: processing message 
<750085942.781871273016781588.javamail.dcad...@be-2k3cf-mac65> for clamav:89
2010-05-05 01:46:24.446872500 [7017] info: spamd: clean message (-1.9/5.0) for 
clamav:89 in 1.6 seconds, 12700 bytes.
2010-05-05 01:46:24.446882500 [7017] info: spamd: result: . -1 - 
AWL,BAYES_00,HTML_70_80,HTML_LINK_IMAGE_BUG,HTML_MESSAGE 
scantime=1.6,size=12700,user=clamav,uid=89,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=35217,mid=<750085942.781871273016781588.javamail.dcad...@be-2k3cf-mac65>,bayes=0,autolearn=ham
2010-05-05 01:46:24.637899500 [3578] info: prefork: child states: II
2010-05-05 01:50:01.336641500 [7017] info: spamd: connection from 
localhost.localdomain [127.0.0.1] at port 35268
2010-05-05 01:50:01.349891500 [7017] info: spamd: processing message 
<[email protected]> for clamav:89
2010-05-05 01:50:01.844513500 [7017] info: spamd: clean message (1.9/5.0) for 
clamav:89 in 0.5 seconds, 9352 bytes.
2010-05-05 01:50:01.844993500 [7017] info: spamd: result: .  1 - 
AWL,BAYES_00,HTML_MESSAGE,HTML_TAG_EXIST_TBODY,MIME_BASE64_TEXT,MIME_HTML_ONLY,TW_PT 
scantime=0.5,size=9352,user=clamav,uid=89,required_score=5.0,rhost=localhost.localdomain,raddr=127.0.0.1,rport=35268,mid=<[email protected]>,bayes=3.88578058618805e-16,autolearn=no
2010-05-05 01:50:02.036774500 [3578] info: prefork: child states: II
# cat /var/log/qmail/send/current |tai64nlocal| grep "2010-05-05 01"  
2010-05-05 01:02:10.777135500 new msg 276896
2010-05-05 01:02:10.777144500 info msg 276896: bytes 1262 from 
<[email protected]> qp 1028 uid 0
2010-05-05 01:02:10.782716500 starting delivery 1612: msg 276896 to local 
[email protected]
2010-05-05 01:02:10.782725500 status: local 1/10 remote 0/60
2010-05-05 01:02:10.901114500 new msg 276933
2010-05-05 01:02:10.901123500 info msg 276933: bytes 1362 from 
<[email protected]> qp 1033 uid 89
2010-05-05 01:02:10.906855500 starting delivery 1613: msg 276933 to local 
[email protected]
2010-05-05 01:02:10.906864500 status: local 2/10 remote 0/60
2010-05-05 01:02:10.906868500 delivery 1612: success: 
vdelivermail:_valiases_processed/did_0+0+1/
2010-05-05 01:02:10.906874500 status: local 1/10 remote 0/60
2010-05-05 01:02:10.906879500 end msg 276896
2010-05-05 01:02:11.079517500 delivery 1613: success: did_0+0+1/
2010-05-05 01:02:11.079526500 status: local 0/10 remote 0/60
2010-05-05 01:02:11.079530500 end msg 276933
2010-05-05 01:25:10.869634500 starting delivery 1614: msg 276925 to remote 
s...@kr_ierservice.dk
2010-05-05 01:25:10.869644500 status: local 0/10 remote 1/60
2010-05-05 01:26:11.434835500 delivery 1614: deferral: 
Sorry,_I_wasn't_able_to_establish_an_SMTP_connection._(#4.4.1)/
2010-05-05 01:26:11.434845500 status: local 0/10 remote 0/60
2010-05-05 01:46:24.649715500 new msg 276936
2010-05-05 01:46:24.649724500 info msg 276936: bytes 13114 from 
<[email protected]> qp 2399 uid 89
2010-05-05 01:46:24.658220500 starting delivery 1615: msg 276936 to local 
[email protected]
2010-05-05 01:46:24.658230500 status: local 1/10 remote 0/60
2010-05-05 01:46:24.748623500 delivery 1615: success: did_0+0+1/
2010-05-05 01:46:24.748632500 status: local 0/10 remote 0/60
2010-05-05 01:46:24.748637500 end msg 276936
2010-05-05 01:50:02.201521500 new msg 276936
2010-05-05 01:50:02.201529500 info msg 276936: bytes 9795 from 
<[email protected]> qp 2502 uid 89
2010-05-05 01:50:02.208926500 starting delivery 1616: msg 276936 to local 
[email protected]
2010-05-05 01:50:02.208936500 status: local 1/10 remote 0/60
2010-05-05 01:50:02.472094500 delivery 1616: success: did_0+0+1/
2010-05-05 01:50:02.472103500 status: local 0/10 remote 0/60
2010-05-05 01:50:02.472108500 end msg 276936
Den 05/05/2010 kl. 16.03 skrev Jake Vickers:

On 05/05/2010 08:24 AM, Ulrik S. Kofod wrote:

Hi all I need a little help.

Today I got a complaint from a user because hid dad had tried to send him a 
mail,
but they got rejected. I didn't get the exact error message that his dad 
received,
but investigating the logs something seems to be wrong.

In the /var/log/qmail/smtp/current log I see 4 mails from from<[email protected]::>:

2010-05-04 16:32:17.203413500 CHKUSER accepted rcpt: from<[email protected]::>  remote
<parismailgw.gratisdns.dk:unknown:213.173.243.250>  rcpt<[email protected]>  : found
existing recipient
2010-05-05 01:04:05.201492500 CHKUSER accepted rcpt: from<[email protected]::>  remote
<parismailgw.gratisdns.dk:unknown:213.173.243.250>  rcpt<[email protected]>  : found
existing recipient
2010-05-05 01:08:49.524959500 CHKUSER accepted rcpt: from<[email protected]::>  remote
<parismailgw.gratisdns.dk:unknown:213.173.243.250>  rcpt<[email protected]>  : found
existing recipient
2010-05-05 08:16:54.797847500 CHKUSER accepted rcpt: from<[email protected]::>  remote
<parismailgw.gratisdns.dk:unknown:213.173.243.250>  rcpt<[email protected]>  : found
existing recipient



We need to see more of the logs - a couple lines before and 5-10 lines after 
each instance.


In my /var/log/qmail/send/current log I only see 2?
2010-05-04 16:32:17.951872500 info msg 276936: bytes 2326 from<[email protected]>  qp 
12946
uid 89
2010-05-05 08:16:55.613505500 info msg 276936: bytes 3669 from<[email protected]>  qp 
24344
uid 89

The two from around 01am are missing?

In the /var/log/qmail/clamd/current log I see both was scanned and found OK.
2010-05-05 01:01:30.131725500 SelfCheck: Database status OK.
2010-05-05 01:04:05.830571500
/var/qmail/simscan/1273014245.202707.1091/msg.1273014245.202707.1091: OK 
2010-05-05
01:08:50.065474500
/var/qmail/simscan/1273014529.526208.1249/msg.1273014529.526208.1249: OK 
2010-05-05
01:18:49.904600500 SelfCheck: Database status OK.

In the /var/log/qmail/spamd/current log I see both and they are not spam.

2010-05-05 01:04:06.456866500 [7017] info: spamd: result: . -2
2010-05-05 01:08:50.689354500 [7017] info: spamd: result: . -1

Where did they go or where did they get rejected?


Need to see more of the logs - are they stuck in the queue?

---------------------------------------------------------------------------------
Qmailtoaster is sponsored by Vickers Consulting Group 
(www.vickersconsulting.com)
Vickers Consulting Group offers Qmailtoaster support and installations.
  If you need professional help with your setup, contact them today!
---------------------------------------------------------------------------------
 Please visit qmailtoaster.com for the latest news, updates, and packages.
      To unsubscribe, e-mail: [email protected]
 For additional commands, e-mail: [email protected]



---------------------------------------------------------------------------------
Qmailtoaster is sponsored by Vickers Consulting Group 
(www.vickersconsulting.com)
  Vickers Consulting Group offers Qmailtoaster support and installations.
    If you need professional help with your setup, contact them today!

--
-Eric 'shubes'



---------------------------------------------------------------------------------
Qmailtoaster is sponsored by Vickers Consulting Group 
(www.vickersconsulting.com)
  Vickers Consulting Group offers Qmailtoaster support and installations.
    If you need professional help with your setup, contact them today!
---------------------------------------------------------------------------------
   Please visit qmailtoaster.com for the latest news, updates, and packages.
        To unsubscribe, e-mail: [email protected]
   For additional commands, e-mail: [email protected]





---------------------------------------------------------------------------------
Qmailtoaster is sponsored by Vickers Consulting Group 
(www.vickersconsulting.com)
    Vickers Consulting Group offers Qmailtoaster support and installations.
      If you need professional help with your setup, contact them today!



---------------------------------------------------------------------------------
Qmailtoaster is sponsored by Vickers Consulting Group 
(www.vickersconsulting.com)
   Vickers Consulting Group offers Qmailtoaster support and installations.
     If you need professional help with your setup, contact them today!
---------------------------------------------------------------------------------
    Please visit qmailtoaster.com for the latest news, updates, and packages.

    
     To unsubscribe, e-mail: [email protected]

    For additional commands, e-mail: [email protected]
























					Reply via email to