From: Chris B. <cb...@da...> - 2013-03-29 20:42:11
|
I'm having a problem where one of my users can't receive emails with attachments from a single customer. When the message first comes in I get the following in /var/log/qmail/smtpd/current: 2013-03-29 09:42:33.680656500.s:@400000005155c38507dbecbc tcpserver: pid 21905 from 192.104.67.3 2013-03-29 09:42:33.680656500.s:@400000005155c38507df963c tcpserver: ok 21905 relay.davistl.com:192.168.200.25:25 mail2.eaton.com:192.104.67.3::29629 2013-03-29 09:42:33.680656500.s:@400000005155c3862bf16d84 mailfront[21905]: MAIL FROM:<GaryShojaie@Eaton.com> SIZE=7823876 2013-03-29 09:42:33.680656500.s:@400000005155c3862bf17554 mailfront[21905]: RCPT TO:<MI...@da...> 2013-03-29 09:42:33.680656500.s:@400000005155c3a0379e1b14 mailfront[21905]: 451 4.3.0 Temporary qmail-queue failure. 2013-03-29 09:42:33.680656500.s:@400000005155c3a0379e1efc mailfront[21905]: bytes in: 7823992 bytes out: 285 2013-03-29 09:42:33.680656500.s:@400000005155c3a037a097cc tcpserver: end 21905 status 0 Initially I thought softlimit might not be high enough, but increasing it didn't help and emailing a file with an even larger attachment from one of my accounts worked fine: 2013-03-29 09:52:39.069600500 tcpserver: pid 23160 from 205.188.105.147 2013-03-29 09:52:39.165676500 tcpserver: ok 23160 relay.davistl.com:192.168.200.25:25 imr-da05.mx.aol.com:205.188.105.147::64354 2013-03-29 09:52:41.803962500 mailfront[23160]: MAIL FROM:<blu...@ao...> SIZE=11808740 2013-03-29 09:52:41.803964500 mailfront[23160]: RCPT TO:<mi...@da...> 2013-03-29 09:53:12.182697500 mailfront[23160]: 2.6.0 Accepted message qp 23162 bytes 11657485 2013-03-29 09:53:12.182698500 mailfront[23160]: bytes in: 11808855 bytes out: 295 2013-03-29 09:53:12.182819500 tcpserver: end 23160 status 0 After reading some of the mailfront code it didn't look like the problem was there, so I looked at /var/spool/qscan/qmail-queue.log and found messages like this: Fri, 29 Mar 2013 10:13:19 PDT:24830: +++ starting debugging for process 24830 by uid=1003 Fri, 29 Mar 2013 10:13:19 PDT:24830: setting UID to EUID so subprocesses can access files generated by this script Fri, 29 Mar 2013 10:13:19 PDT:24830: program name is qmail-scanner-queue.pl, version 2.10 Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: mkdir /var/spool/qscan/tmp/relay136457719958624830 Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: start dumping incoming msg into /var/spool/qscan/working/tmp/relay136457719958624830 [0.000262] Fri, 29 Mar 2013 10:13:19 PDT:24830: c_a_g: found MIME attachment Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: primary Content-Type of multipart/mixed found Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: found a top-level boundary definition of _004_5137F0726DAB194A9D1D9AC87004F6D309F90ASIMTCSMB06napaade_ Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: attachment 1: Content-Type of multipart/alternative found Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: attachment 2: Content-Type of text/plain found Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: attachment 3: Content-Type of text/html found Fri, 29 Mar 2013 10:13:19 PDT:24830: found C-T attachment filename "1c17784.zip" Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: attachment 5: Content-Type of application/x-zip-compressed found Fri, 29 Mar 2013 10:13:19 PDT:24830: w_c: base64 looks like a zip file, filename=1c17784.zip,type=application/x-zip-compressed Fri, 29 Mar 2013 10:13:38 PDT:24830: w_c: rename new msg from /var/spool/qscan/working/tmp/relay136457719958624830 to /var/spool/qscan/working/new/relay136457719958624830 Fri, 29 Mar 2013 10:13:38 PDT:24830: w_c: total time between DATA command and "." was 18.987336 secs Fri, 29 Mar 2013 10:13:38 PDT:24830: w_c: (this is basically the time it took the client to send the message over the network Fri, 29 Mar 2013 10:13:38 PDT:24830: w_c: resetting timer so as to measure actual Qmail-Scanner processing time Fri, 29 Mar 2013 10:13:38 PDT:24830: incoming SMTP connection from via SMTP from mail2.eaton.com Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: starting /usr/bin/reformime -x/var/spool/qscan/tmp/relay136457719958624830/ </var/spool/qscan/working/new/relay136457719958624830 [0.000246] Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: finished /usr/bin/reformime -x/var/spool/qscan/tmp/relay136457719958624830/ [0.06757] Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: Checking all attachments to see if they're MS-TNEF Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: is /var/spool/qscan/tmp/relay136457719958624830/1C17784.zip is a TNEF file?: 256 [0.001004] Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: is /var/spool/qscan/tmp/relay136457719958624830/1364577218.24865-0.relay is a TNEF file?: 256 [0.000773] Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: is /var/spool/qscan/tmp/relay136457719958624830/1364577218.24865-1.relay is a TNEF file?: 256 [0.000746] Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: Check for zip files... Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: potential zip archive file found (1C17784.zip). Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: it is possibly a zip file, run unzip -Pxx1518412100xx -t /var/spool/qscan/tmp/relay136457719958624830/1C17784.zip Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: it is a zip file Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: check size of contents before unzipping to disk Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: this zip file unpacks to 4585272 bytes of content Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: run /usr/bin/unzip -Pxx1518412100xx /var/spool/qscan/tmp/relay136457719958624830/1C17784.zip 2>&1 Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: 0, and successfully unzipped Fri, 29 Mar 2013 10:13:38 PDT:24830: u_f: using chmod to ensure files are readable () Fri, 29 Mar 2013 10:13:38 PDT:24830: d_m: unpacking message took 0.147106 seconds Fri, 29 Mar 2013 10:13:38 PDT:24830: unsetting QMAILQUEUE env var Fri, 29 Mar 2013 10:13:38 PDT:24830: g_e_h: return-path is "GaryShojaie@Eaton.com", recips is "MI...@da...,cb...@da..." Fri, 29 Mar 2013 10:13:38 PDT:24830: from=<GaryShojaie@Eaton.com>,subj=RE: Davis Tool Contact Info., x-qmail-scanner-message-id=<5137F0726DAB194A9D1D9AC87004F6D309F90A@SIMTCSMB06.napa.ad.etn.com> via SMTP from mail2.eaton.com Fri, 29 Mar 2013 10:13:38 PDT:24830: ini_sc: start scanning Fri, 29 Mar 2013 10:13:38 PDT:24830: ini_sc: recursively scan the directory /var/spool/qscan/tmp/relay136457719958624830/ Fri, 29 Mar 2013 10:13:38 PDT:24830: scanloop(virus): starting scan of directory "/var/spool/qscan/tmp/relay136457719958624830"... Fri, 29 Mar 2013 10:13:38 PDT:24830: scanloop: scanner=clamdscan_scanner,plain_text_msg=0 Fri, 29 Mar 2013 10:13:38 PDT:24830: clamdscan: starting scan of directory "/var/spool/qscan/tmp/relay136457719958624830"... Fri, 29 Mar 2013 10:13:38 PDT:24830: run /usr/bin/clamdscan --no-summary /var/spool/qscan/tmp/relay136457719958624830 2>&1 Fri, 29 Mar 2013 10:13:39 PDT:24830: --output of clamdscan was: /var/spool/qscan/tmp/relay136457719958624830: OK -- Fri, 29 Mar 2013 10:13:39 PDT:24830: clamdscan: finished scan of dir "/var/spool/qscan/tmp/relay136457719958624830" in 1.280143 secs Fri, 29 Mar 2013 10:13:39 PDT:24830: scanloop: scanner=mhr_scanner,plain_text_msg=0 Fri, 29 Mar 2013 10:13:39 PDT:24830: mhr: starting scan of directory "/var/spool/qscan/tmp/relay136457719958624830"... Fri, 29 Mar 2013 10:13:39 PDT:24830: error_condition: X-Qmail-Scanner-2.10: Requeuing: Read failed: Is a directory at /var/qmail/bin/qmail-scanner-queue.pl line 2761 The last line looks like a problem. I saw the note in the 2.11 release (I'm on 2.10) about mhr so I double checked that Digest::SHA and Digest::SHA1 were installed and working: relay:/var/log/qmail/smtpd # perl -MDigest::SHA -el relay:/var/log/qmail/smtpd # perl -MDigest::SHA1 -el The permissions and ownership of the /var/spool/qscan/tmp folder look ok: relay:/var/spool/qscan # ls -alh | grep tmp drwxr-x--- 2 qscand qscand 4.0K Mar 29 13:30 tmp It appears that my config thinks it should be using MHR: relay:/var/spool/qscan # cat /var/qmail/bin/qmail-scanner-queue.pl | grep @scanner_array= my @scanner_array=("clamdscan_scanner","mhr_scanner","spamassassin"); I don't remember turning that on, but I see from the 2.10 change log notes that perhaps it's a new default? Since it's failing near there I'm wondering if that might be the problem. Any thoughts? Chris Berry Linux Systems Administrator Davis Tool x521 |
From: Jason H. <Jas...@tr...> - 2013-03-30 05:55:05
|
On 30/03/13 09:41, Chris Berry wrote: > > Fri, 29 Mar 2013 10:13:39 PDT:24830: mhr: starting scan of directory > "/var/spool/qscan/tmp/relay136457719958624830"... > > Fri, 29 Mar 2013 10:13:39 PDT:24830: error_condition: > X-Qmail-Scanner-2.10: Requeuing: Read failed: Is a directory at > /var/qmail/bin/qmail-scanner-queue.pl line 2761 > > As each Q-S install is different, you will need to look at line 2761 in qmail-scanner-queue.pl to see what it was trying to do. Looks like it wanted to open a file but found a directory instead > relay:/var/spool/qscan # cat /var/qmail/bin/qmail-scanner-queue.pl | > grep @scanner_array= > > my @scanner_array=("clamdscan_scanner","mhr_scanner","spamassassin"); > > > I don't remember turning that on, but I see from the 2.10 change log > notes that perhaps it's a new default? Since it's failing near there > I'm wondering if that might be the problem. Any thoughts? > > You must have installed is as "automatic" - so it just enabled all the AVs it discovered. You can explicitly tell the ./configure script you only want clamdscan and SA and get rid of MHR if you wish -- Cheers Jason Haar Information Security Manager, Trimble Navigation Ltd. Phone: +1 408 481 8171 PGP Fingerprint: 7A2E 0407 C9A6 CAF6 2B9F 8422 C063 5EBB FE1D 66D1 |
From: Salvatore T. <to...@pu...> - 2013-03-30 09:09:04
|
Hi Maybe the problem is with mhr and zip attachments... There was an error there that has been fixed in version 2.11, but Jason forgot to mention it in the changes... v2.10 if($file eq "." || $file eq ".." || $file =~ /^[0-9]+\.[0-9]+\-[0-9]+\.$hostname|^(orig\-|)$file_id|^textfile[0-9]+/){ v2.11 if(-d $file || $file eq "." || $file eq ".." || $file =~ /^[0-9]+\.[0-9]+\-[0-9]+\.$hostname|^(orig\-|)$file_id|^textfile[0-9]+/){ So updating to 2.11 should fix your problem. ST At 18:54 +1300 30-03-2013, Jason Haar wrote: >On 30/03/13 09:41, Chris Berry wrote: >> >> Fri, 29 Mar 2013 10:13:39 PDT:24830: mhr: starting scan of directory >> "/var/spool/qscan/tmp/relay136457719958624830"... >> >> Fri, 29 Mar 2013 10:13:39 PDT:24830: error_condition: >> X-Qmail-Scanner-2.10: Requeuing: Read failed: Is a directory at >> /var/qmail/bin/qmail-scanner-queue.pl line 2761 >> >> > >As each Q-S install is different, you will need to look at line 2761 in >qmail-scanner-queue.pl to see what it was trying to do. Looks like it >wanted to open a file but found a directory instead > >> relay:/var/spool/qscan # cat /var/qmail/bin/qmail-scanner-queue.pl | >> grep @scanner_array= >> >> my @scanner_array=("clamdscan_scanner","mhr_scanner","spamassassin"); >> >> >> I don't remember turning that on, but I see from the 2.10 change log >> notes that perhaps it's a new default? Since it's failing near there >> I'm wondering if that might be the problem. Any thoughts? >> >> > >You must have installed is as "automatic" - so it just enabled all the >AVs it discovered. You can explicitly tell the ./configure script you >only want clamdscan and SA and get rid of MHR if you wish > >-- >Cheers > |
From: Chris B. <cb...@da...> - 2013-04-01 16:27:34
|
That was likely the problem. We ended up reconfiguring without MHR since it's for non-commercial use anyways. Leaving MHR out fixed the issue for our use case. Thanks for the feedback. Chris Berry Linux Systems Administrator Davis Tool x521 >>> Salvatore Toribio <to...@pu...> 3/30/2013 2:08 AM >>> Hi Maybe the problem is with mhr and zip attachments... There was an error there that has been fixed in version 2.11, but Jason forgot to mention it in the changes... v2.10 if($file eq "." || $file eq ".." || $file =~ /^[0-9]+\.[0-9]+\-[0-9]+\.$hostname|^(orig\-|)$file_id|^textfile[0-9]+/){ v2.11 if(-d $file || $file eq "." || $file eq ".." || $file =~ /^[0-9]+\.[0-9]+\-[0-9]+\.$hostname|^(orig\-|)$file_id|^textfile[0-9]+/){ So updating to 2.11 should fix your problem. ST At 18:54 +1300 30-03-2013, Jason Haar wrote: >On 30/03/13 09:41, Chris Berry wrote: >> >> Fri, 29 Mar 2013 10:13:39 PDT:24830: mhr: starting scan of directory >> "/var/spool/qscan/tmp/relay136457719958624830"... >> >> Fri, 29 Mar 2013 10:13:39 PDT:24830: error_condition: >> X-Qmail-Scanner-2.10: Requeuing: Read failed: Is a directory at >> /var/qmail/bin/qmail-scanner-queue.pl line 2761 >> >> > >As each Q-S install is different, you will need to look at line 2761 in >qmail-scanner-queue.pl to see what it was trying to do. Looks like it >wanted to open a file but found a directory instead > >> relay:/var/spool/qscan # cat /var/qmail/bin/qmail-scanner-queue.pl | >> grep @scanner_array= >> >> my @scanner_array=("clamdscan_scanner","mhr_scanner","spamassassin"); >> >> >> I don't remember turning that on, but I see from the 2.10 change log >> notes that perhaps it's a new default? Since it's failing near there >> I'm wondering if that might be the problem. Any thoughts? >> >> > >You must have installed is as "automatic" - so it just enabled all the >AVs it discovered. You can explicitly tell the ./configure script you >only want clamdscan and SA and get rid of MHR if you wish > >-- >Cheers > ------------------------------------------------------------------------------ Own the Future-Intel(R) Level Up Game Demo Contest 2013 Rise to greatness in Intel's independent game demo contest. Compete for recognition, cash, and the chance to get your game on Steam. $5K grand prize plus 10 genre and skill prizes. Submit your demo by 6/6/13. http://altfarm.mediaplex.com/ad/ck/12124-176961-30367-2 _______________________________________________ Qmail-scanner-general mailing list Qma...@li... https://lists.sourceforge.net/lists/listinfo/qmail-scanner-general |