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 >>>> <rasmus.b...@pol.dk::> remote >>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt <andr...@bech.it> >>>> : 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 >>>> <rasmus.b...@pol.dk::> remote >>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt <andr...@bech.it> >>>> : 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 >>>> <i...@jobagent.stepstone.dk::> remote >>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt >>>> <a...@birchlykholt.dk> : 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 >>>> <r...@mailserver03.dagensjob.dk::> remote >>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt >>>> <torp...@oddsetligaen.dk> : 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 >>>> <8409c0a9458efc4d96ae4d7994b6e546b3deaad...@ps02.rootdom.dk> 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=<8409c0a9458efc4d96ae4d7994b6e546b3deaad...@ps02.rootdom.dk>,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 >>>> <8409c0a9458efc4d96ae4d7994b6e546b3deaad...@ps02.rootdom.dk> 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=<8409c0a9458efc4d96ae4d7994b6e546b3deaad...@ps02.rootdom.dk>,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 >>>> <20100504235242.e637b173e...@mailserver03.dagensjob.dk> 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=<20100504235242.e637b173e...@mailserver03.dagensjob.dk>,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 >>>> <anonym...@cybersite.dk> qp 1028 uid 0 >>>> 2010-05-05 01:02:10.782716500 starting delivery 1612: msg 276896 to local >>>> cybersite.dk-r...@cybersite.dk >>>> 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 >>>> <anonym...@cybersite.dk> qp 1033 uid 89 >>>> 2010-05-05 01:02:10.906855500 starting delivery 1613: msg 276933 to local >>>> cybersite.dk-postmas...@cybersite.dk >>>> 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 >>>> <i...@jobagent.stepstone.dk> qp 2399 uid 89 >>>> 2010-05-05 01:46:24.658220500 starting delivery 1615: msg 276936 to local >>>> birchlykholt.dk-a...@birchlykholt.dk >>>> 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 >>>> <r...@mailserver03.dagensjob.dk> qp 2502 uid 89 >>>> 2010-05-05 01:50:02.208926500 starting delivery 1616: msg 276936 to local >>>> oddsetligaen.dk-torp...@oddsetligaen.dk >>>> 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<a...@aaa.dk::>: >>>>>> >>>>>> 2010-05-04 16:32:17.203413500 CHKUSER accepted rcpt: from<a...@aaa.dk::> >>>>>> remote >>>>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt<c...@bbb.it> : >>>>>> found >>>>>> existing recipient >>>>>> 2010-05-05 01:04:05.201492500 CHKUSER accepted rcpt: from<a...@aaa.dk::> >>>>>> remote >>>>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt<b...@bbb.it> : >>>>>> found >>>>>> existing recipient >>>>>> 2010-05-05 01:08:49.524959500 CHKUSER accepted rcpt: from<a...@aaa.dk::> >>>>>> remote >>>>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt<b...@bbb.it> : >>>>>> found >>>>>> existing recipient >>>>>> 2010-05-05 08:16:54.797847500 CHKUSER accepted rcpt: from<a...@aaa.dk::> >>>>>> remote >>>>>> <parismailgw.gratisdns.dk:unknown:213.173.243.250> rcpt<b...@bbb.it> : >>>>>> 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<a...@aaa.dk> qp 12946 >>>>>> uid 89 >>>>>> 2010-05-05 08:16:55.613505500 info msg 276936: bytes 3669 >>>>>> from<a...@aaa.dk> 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: >>>>> qmailtoaster-list-unsubscr...@qmailtoaster.com >>>>> For additional commands, e-mail: qmailtoaster-list-h...@qmailtoaster.com >>>>> >>>>> >>>> --------------------------------------------------------------------------------- >>>> 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: qmailtoaster-list-unsubscr...@qmailtoaster.com > For additional commands, e-mail: qmailtoaster-list-h...@qmailtoaster.com > > --------------------------------------------------------------------------------- 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: qmailtoaster-list-unsubscr...@qmailtoaster.com For additional commands, e-mail: qmailtoaster-list-h...@qmailtoaster.com