>Msg receipt begins in qmail-smtpd/current: tcpserver: pid 29998 from 66.x.x.x tcpserver: ok 29998 qmail:38.x.x.x:25 :66.x.x.x::60482 smtpfront-qmail[29998]: MAIL FROM:<Sales@yaddayadda.net> SIZE=331109 smtpfront-qmail[29998]: RCPT TO:<BEA@thisisp.net> >Msg is passed to qmail-scanner :30008: w_c: rename new msg from /var/spool/qmailscan/blablabla :30008: verbose stuff skipped :30008: d_m: unpacking message took 0.078196 seconds (I know I'm looking at the right entry because of this) :30008: g_e_h: return-path is "Sales@yaddayadda.net", recips is "BEA@thisisp.net" :30008: scanloop: scanner=fprot_scanner,plain_text_msg=0 :30008: fprot: finished scan of dir "/var/bla/bla/bla" in 0.559471 secs :30008: scanloop: scanner=spamassassin,plain_text_msg=0 :30008: SA: run /usr/bin/spamc -U /tmp/.spamd -c -f -u "bea@thisisp.net" < /var/spool/qmailscan/working/new/qmail109560521966630008 >there are no more qmail-scanner logs for this process >here's what I get out of qmail-smtpd/current smtpfront-qmail[29998]: 451 qmail-queue crashed. smtpfront-qmail[29998]: bytes in: 331231 bytes out: 227 tcpserver: end 29998 status 0 My spamd log shows no scan process started when scanloop began in qmail-scanner Reproducible: Sometimes Steps to Reproduce: 1. receive email from untrusted network larger than 250k 2. 3. Actual Results: ok, here are all of the logs involved. I converted the timestamp using tai64nlocal to make it easier to read. ==> /var/log/qmail/qmail-smtpd/current <== 2004-09-19 10:20:22.204594500 tcpserver: pid 12603 from 206.46.170.103 2004-09-19 10:20:22.204774500 tcpserver: ok 12603 qmail:38.114.25.30:25 :206.46.170.103::41924 2004-09-19 10:20:23.424216500 smtpfront-qmail[12603]: MAIL FROM:<s.abney13@verizon.net> SIZE=331800 2004-09-19 10:20:23.433841500 smtpfront-qmail[12603]: RCPT TO:<busta@ectisp.net> ==> qmailscanner/logs/current <== Sun, 19 Sep 2004 10:20:24 CDT:12605: +++ starting debugging for process 12605 by uid=202 Sun, 19 Sep 2004 10:20:24 CDT:12605: setting UID to EUID so subprocesses can access files generated by this script Sun, 19 Sep 2004 10:20:24 CDT:12605: program name is qmail-scanner-queue.pl, version 1.23st Sun, 19 Sep 2004 10:20:24 CDT:12605: incoming SMTP connection from via SMTP from 206.46.170.103 Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: mkdir /var/spool/qmailscan/tmp/qmail109560722466612605 Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: start dumping incoming msg into /var/spool/qmailscan/working/tmp/qmail109560722466612605 [0.002923] Sun, 19 Sep 2004 10:20:24 CDT:12605: c_a_g: found MIME attachment Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: primary Content-Type of multipart/related found Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: found a top-level boundary definition of \-\-\-\-\=_NextPart_000_0000_01C49E18\.63F8CCF0 Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 1 [details]: Content-Type of multipart/alternative found Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 2 [details]: Content-Type of text/plain found Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 3 [details, diff]: Content-Type of text/html found Sun, 19 Sep 2004 10:20:24 CDT:12605: found C-T attachment filename bird-hat-2.jpg Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 5 [details]: Content-Type of image/jpeg found Sun, 19 Sep 2004 10:20:24 CDT:12605: found C-T attachment filename bird-hat.jpg Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 6 [details]: Content-Type of image/jpeg found Sun, 19 Sep 2004 10:20:24 CDT:12605: found C-T attachment filename amaizrul.gif Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 7 [details]: Content-Type of image/gif found Sun, 19 Sep 2004 10:20:24 CDT:12605: found C-T attachment filename maize bkgrd.jpg Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: attachment 8 [details]: Content-Type of image/jpeg found Sun, 19 Sep 2004 10:20:24 CDT:12605: w_c: rename new msg from /var/spool/qmailscan/working/tmp/qmail109560722466612605 to /var/spool/qmailscan/working/new/qmail109560722466612605 [0.958016] Sun, 19 Sep 2004 10:20:24 CDT:12605: d_m: starting /usr/bin/ripmime --unique_names -i - -d /var/spool/qmailscan/tmp/qmail109560722466612605/ </var/spool/qmailscan/working/new/qmail109560722466612605 [0.001152] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: finished /usr/bin/ripmime --unique_names -i - -d /var/spool/qmailscan/tmp/qmail109560722466612605/ [0.056052] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: Checking all attachments to see if they're MS-TNEF Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/textfile0 is a TNEF file?: 256 [0.006113] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/textfile1 is a TNEF file?: 256 [0.006664] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/textfile2 is a TNEF file?: 256 [0.006158] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/textfile3 is a TNEF file?: 256 [0.006287] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/textfile4 is a TNEF file?: 256 [0.006222] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/Bird-hat-2.jpg is a TNEF file?: 256 [0.00623] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/Bird-Hat.jpg is a TNEF file?: 256 [0.006214] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/amaizrul.gif is a TNEF file?: 256 [0.006265] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: ren Maize Bkgrd.jpg to qmail109560722566612605MaizeBkgrd.jpg Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/qmail109560722566612605MaizeBkgrd.jpg is a TNEF file?: 256 [0.0065] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: is /var/spool/qmailscan/tmp/qmail109560722466612605/textfile5 is a TNEF file?: 256 [0.006656] Sun, 19 Sep 2004 10:20:25 CDT:12605: d_m: unpacking message took 0.119858 seconds Sun, 19 Sep 2004 10:20:25 CDT:12605: unsetting QMAILQUEUE env var Sun, 19 Sep 2004 10:20:25 CDT:12605: g_e_h: return-path is "s.abney13@verizon.net", recips is "busta@ectisp.net" Sun, 19 Sep 2004 10:20:25 CDT:12605: from="Sherrie Abney" <s.abney13@verizon.net>,subj=Bird Hat, x-qmail-scanner-message-id=<20040919131546.GOCF26805.out003.verizon.net@sherrierabney> via SMTP from 206.46.170.103 Sun, 19 Sep 2004 10:20:25 CDT:12605: ini_sc: start scanning Sun, 19 Sep 2004 10:20:25 CDT:12605: ini_sc: recursively scan the directory /var/spool/qmailscan/tmp/qmail109560722466612605/ Sun, 19 Sep 2004 10:20:25 CDT:12605: scanloop: starting scan of directory "/var/spool/qmailscan/tmp/qmail109560722466612605"... Sun, 19 Sep 2004 10:20:25 CDT:12605: scanloop: scanner=fprot_scanner,plain_text_msg=0 Sun, 19 Sep 2004 10:20:25 CDT:12605: fprot: starting scan of directory "/var/spool/qmailscan/tmp/qmail109560722466612605"... Sun, 19 Sep 2004 10:20:25 CDT:12605: run /opt/f-prot/f-prot -list -archive -dumb /var/spool/qmailscan/tmp/qmail109560722466612605 2>&1 | tai64n Sun, 19 Sep 2004 10:20:25 CDT:12605: --output of fprot was: Virus scanning report - 19 September 2004 @ 10:20 F-PROT ANTIVIRUS Program version: 4.4.2 Engine version: 3.14.11 VIRUS SIGNATURE FILES SIGN.DEF created 17 September 2004 SIGN2.DEF created 17 September 2004 MACRO.DEF created 13 September 2004 Search: /var/spool/qmailscan/tmp/qmail109560722466612605 Action: Report only Files: "Dumb" scan of all files Switches: -ARCHIVE -PACKED -SERVER -AI Results of virus scanning: Files: 11 MBRs: 0 Boot sectors: 0 Objects scanned: 15 Time: 0:00 No viruses or suspicious files/boot sectors were found. -- Sun, 19 Sep 2004 10:20:25 CDT:12605: fprot: finished scan of dir "/var/spool/qmailscan/tmp/qmail109560722466612605" in 0.38364 secs Sun, 19 Sep 2004 10:20:25 CDT:12605: Sun, 19 Sep 2004 10:20:25 CDT:12605: scanloop: scanner=spamassassin,plain_text_msg=0 Sun, 19 Sep 2004 10:20:25 CDT:12605: SA: run /usr/bin/spamc -U /tmp/.spamd -c -f -u "busta@ectisp.net" < /var/spool/qmailscan/working/new/qmail109560722466612605 ==> /var/log/qmail/qmail-smtpd/current <== 2004-09-19 10:20:25.541899500 smtpfront-qmail[12603]: 451 qmail-queue crashed. 2004-09-19 10:20:25.593782500 smtpfront-qmail[12603]: bytes in: 331927 bytes out: 243 2004-09-19 10:20:25.594345500 tcpserver: end 12603 status 0 in /var/log/qmail/spamd/current, I found no transactions occuring at 10:20:25: 2004-09-19 10:20:16.869494500 debug: cleaned up kid 12581, pool=10 2004-09-19 10:22:17.100722500 logmsg: got connection over /tmp/.spamd Expected Results: spamassassin should recognize when a message is above 250k and stop scanning, qmail-scanner should continue with the scanloops.....after spamassassin should be perlscanner. Portage 2.0.51_rc1 (default-x86-1.4, gcc-3.4.1, glibc-2.3.4.20040808-r0, 2.6.3 i686) ================================================================= System uname: 2.6.3 i686 Pentium III (Katmai) Gentoo Base System version 1.5.3 Autoconf: sys-devel/autoconf-2.59-r4 Automake: sys-devel/automake-1.8.5-r1 Binutils: sys-devel/binutils-2.15.90.0.1.1-r3 Headers: sys-kernel/linux-headers-2.4.19-r1,sys-kernel/linux-headers-2.4.22 Libtools: sys-devel/libtool-1.5.2-r5 ACCEPT_KEYWORDS="x86 ~x86" AUTOCLEAN="yes" CFLAGS="-march=pentium3 -O3 -pipe" CHOST="i686-pc-linux-gnu" COMPILER="" CONFIG_PROTECT="/etc /usr/X11R6/lib/X11/xkb /usr/kde/2/share/config /usr/kde/3/share/config /usr/share/config /var/qmail/alias /var/qmail/control" CONFIG_PROTECT_MASK="/etc/gconf /etc/terminfo /etc/env.d" CXXFLAGS="-march=pentium3 -O3 -pipe" DISTDIR="/usr/portage/distfiles" FEATURES="autoaddcvs ccache sandbox" GENTOO_MIRRORS="http://mirror.tucdemonic.org/gentoo/ http://cudlug.cudenver.edu/gentoo/ http://open-systems.ufl.edu/mirrors/gentoo ftp://gentoo.ccccom.com ftp://gentoo.netnitco.net/pub/mirrors/gentoo/source/" MAKEOPTS="-j3" PKGDIR="/usr/portage/packages" PORTAGE_TMPDIR="/var/tmp" PORTDIR="/usr/portage" PORTDIR_OVERLAY="" SYNC="rsync://rsync.gentoo.org/gentoo-portage" USE="apm arts avi berkdb bitmap-fonts crypt cups encode foomaticdb gd gdbm gif gpm gtk2 imap imlib jpeg kde libg++ libwww mad mikmod motif mpeg mysql ncurses nls oggvorbis opengl oss pam pdflib perl png python qt quicktime readline sdl slang spell ssl tcltk tcpd truetype x86 xml2 xmms xprint xv zlib"
I added spamc_option -s 250000, but same results.....I'll keep trying with lower numbers.
I've tested qmail+qmail-scanner+spamassasion with a 1GB email, and had no problems, but you do need to raise SOFTLIMIT_OPTS in the appropriate conf-* for it to work. Also spamasssasin's -s parameter does work perfectly fine in further testing.
I'M NOT CALLING THIS A FIX!!!!!!!!! TOMORROW, WHEN I REVIEW MY LOGS AND SEE NO MORE 451 ERRORS I WILL POST AGAIN. This has been running fine until the qmail-scanner-1.23-r3 update. It even worked fine after I updated perl to 5.8.5 (with a teeny bit of grief caused by the suidperl thingy and the qmail-scanner-queue wrapper) So anyway, the problem began with qmail-scanner-1.23-r3, I began seeing these 451 errors in the qmail-smtpd log (the name is leftover from when I ran qmail-smtpd, now I run smtpfront-qmail) So, I started poking around the mailfront files and noticed that my configuration was perfect for a mailfront-0.91 install, but I was running mailfront-0.88 (the latest available in portage). I compiled updated bglibs (using portage) and compiled mailfront-0.91 (using source) and placed the binaries in the correct places. I haven't seen the error since updating mailfront (and now my MAXNOTIMPL seems to be working......bonus) Early on, I thought that it might be my softlimit settings, so I gave qmail-smtpd (smtpfront-qmail) 32, then 64, then 128, then 384, then 512MB! I thought that spamd might be causing it as well, so I gave it (same as above, incremented it to) 384MB, same issue. I don't doubt that this configuration works for you, but I'm also running mailfront (for the ability to reject invalid recipients during delivery and provide smtp-auth with cvm-vmlookup/cvm-vmailmgr respectively.) There don't seem to be many that use qmail in my configuration. This is the first bug I've entered for gentoo and I'm very impressed with the speed at which this bug got attention. I certainly hope that this upgrade of mailfront solves the issue, as I'd genuinely like to use this as another bragging point for gentoo!
Just another update.....since I implemented the newest mailfront at around 10AM, I've had no 451 errors in the logs. Mail seems to be moving through the system as intended. My server load jumps at 9AM weekdays, so I'll have to see how this works with a heavy load. I will confirm this by tomorrow morning just after 10AM CST.
So as you note this was a mailfront error, not specific to qmail. For qmail-scanner and the latest perl that removes suidperl, you need -r3 for it to work. This has caught other people as there is no way to specify that upgrading perl needs to cause qmail-scanner to upgrade.
I know that something was triggering the automatic queue error response that I was getting, but I didn't know exactly where it was coming from. The logs were non-specific. I noticed the suidperl problem right away. qmail-scanner was the next thing to update (I figure that I may as well upgrade everything that uses perl) and then the problem started. This new version of qmail-scanner offers rejection. perhaps smtpfront-qmail 0.88 isn't prepared to handle that as well as the newer version. I totally agree, this isn't a problem with qmail itself. I think it's a version compatibility issue between qmail-scanner and mailfront. The old mailfront (0.88 portage current) works fine with 1.22 series (pre st patch) qmail-scanner and has existed happily on this server for 2943454 messages. Once I upgraded qmail-scanner is when the problems began.
By the way, still no 451's. I'm done watching this thing for tonight....I'm going to bed
It's been over 24 hours since upgrading to mailfront-0.91 and the logs show no more 451 errors from smtpfront-qmail (or anywhere for that matter) a new ebuild needs to be created for mailfront-0.91 depends on the latest bglibs-1.017 I don't know exactly how to do this, but would be willing to give it a shot (it compiled with the same instructions as 0.88 did, so I imagine that it will be almost identical to the 0.88 ebuild.) I'm willing to call this fixed pending creation of a new mailfront ebuild.
Created attachment 40044 [details] new ebuild for mailfront 0.91 I had to unmerge mailfront-0.88 before I could emerge 0.91. I don't know what I did wrong, so if anyone would like to tell me I'd appreciate it. Once 0.88 was unmerged, 0.91 emerged without any issue. also attached is the digest....
Created attachment 40045 [details] digest for mailfront 0.91 digest file as promised
Hi, So this is a problem with mailfront, should we close this? Can you open another bug for mailfront? Ciao ST Lim
oh hell, yes we can close it. Sorry....the issue seems resolved with the newest mailfront 0.91
