My recently installed qmail-scanner 1.21 under RH7.3 seems to be a
problem. The box it's on has been running stable qmail 1.03 for two
years and now freezes every other day. It'll respond to pings but that's
it.
The qmail-scanner log shows a reversing timestamp (the log part included
shows the 100+ lines running up to the hang then the next three lines
post reboot) together with a huge (616 seconds!) spamassassin scan. Am I
right in pointing the finger at the scanner or should I investigate
spamassassin?
I'll admit that I'm not really sure how to trace the fault back to the
culprit :-(
TIA
Tim Clarke
Tue, 27 Apr 2004 20:42:00 +0100:3418: program name is qmail-scanner-queue.pl, version
1.21
Tue, 27 Apr 2004 20:42:00 +0100:3418: incoming SMTP connection from via SMTP from
195.224.154.108
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: mkdir
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: start dumping incoming msg into
/var/spool/qmailscan/working/tmp/man2.m1.manifest.co.uk10830949204703418
[1083094920.86531]
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: primary Content-Type of multipart/mixed
found
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: found a top-level boundary definition of
\-\-\-\-\-\-\-\-\-\-\-\-010405060402070705060106
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: attachment 1: Content-Type of text/plain
found
Tue, 27 Apr 2004 20:42:00 +0100:3418: found C-T attachment filename linux.vcf
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: attachment 2: Content-Type of text/x-vcard
found
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: attachment 3: Content-Type of text/plain
found
Tue, 27 Apr 2004 20:42:00 +0100:3418: w_c: rename new msg from
/var/spool/qmailscan/working/tmp/man2.m1.manifest.co.uk10830949204703418 to
/var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830949204703418
[1083094920.87786]
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: starting /usr/bin/reformime
-x/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418/
</var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830949204703418
[1083094920.87816]
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: finished /usr/bin/reformime
-x/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418/ [1083094920.93496]
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: Checking all attachments to see if they're
MS-TNEF
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: is
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418/1083094920.3420-0.man2.m1.manifest.co.uk
is a TNEF file?: 256 [1083094920.93746]
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: is
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418/linux.vcf is a TNEF
file?: 256 [1083094920.93963]
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: is
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418/1083094920.3420-1.man2.m1.manifest.co.uk
is a TNEF file?: 256 [1083094920.94173]
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: Check for zip files...
Tue, 27 Apr 2004 20:42:00 +0100:3418: d_m: unpacking message took 0.063927 seconds
Tue, 27 Apr 2004 20:42:00 +0100:3418: unsetting QMAILQUEUE env var
Tue, 27 Apr 2004 20:42:00 +0100:3418: g_e_h: return-path is "[EMAIL PROTECTED]",
recips is "[EMAIL PROTECTED]"
Tue, 27 Apr 2004 20:42:00 +0100:3418: from=Chris Jones <[EMAIL PROTECTED]>,subj=Re: Is
this better? - was Hugh's long .sig, x-qmail-scanner-message-id=<[EMAIL PROTECTED]>
via SMTP from 195.224.154.108
Tue, 27 Apr 2004 20:42:00 +0100:3418: ini_sc: start scanning
Tue, 27 Apr 2004 20:42:00 +0100:3418: ini_sc: recursively scan the directory
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418/
Tue, 27 Apr 2004 20:42:00 +0100:3418: scanloop: starting scan of directory
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418"...
Tue, 27 Apr 2004 20:42:00 +0100:3418: scanloop: scanner=spamassassin,plain_text_msg=0
Tue, 27 Apr 2004 20:42:00 +0100:3418: SA: run /usr/bin/spamc -c -f -u "[EMAIL
PROTECTED]" < /var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830949204703418
Tue, 27 Apr 2004 20:42:00 +0100:3418: spamassassin: finished scan of dir
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418" in 11.717243 secs
Tue, 27 Apr 2004 20:42:00 +0100:3418: scanloop: finished scan of
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418"...
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: starting scan of directory
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418"...
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: '81:ILOVEYOU' = 'Virus-subject' = 'Love
Letter Virus/Trojan'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a header!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking for objects containing subject:
ILOVEYOU
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: '82:message/partial.*' =
'Virus-content-type' = 'Message/partial MIME attachments blocked by policy'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a header!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking for objects containing
content-type: message/partial.*
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: '85:.{100,}' = 'Virus-date' = 'MIME Header
Buffer Overflow'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a header!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking for objects containing date:
.{100,}
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: '86:.{100,}' = 'Virus-mime-version' =
'MIME Header Buffer Overflow '
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a header!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking for objects containing
mime-version: .{100,}
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: '87:.{100,}' = 'Virus-resent-date' = 'MIME
Header Buffer Overflow'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a header!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking for objects containing
resent-date: .{100,}
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: '90:[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]' = 'Virus-to' =
'BadTrans Trojan exploit!'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a header!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking for objects containing to: [EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL
PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]|[EMAIL PROTECTED]
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: 'eicar.com' = '69' = 'EICAR Test Virus'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a size!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: 'happy99.exe' = '10000' = 'Happy99 Trojan'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a size!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: 'zipped_files.exe' = '120495' =
'W32/ExploreZip.worm.pak virus'
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: type is a size!
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: skipping auto-generated file
1083094920.3420-0.man2.m1.manifest.co.uk
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking linux.vcf against perlscanner
database...
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: file linux.vcf is lowercased to linux.vcf
and has extension .vcf
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: compare linux.vcf (size 275) against
perlscanner database
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: skipping auto-generated file
1083094920.3420-1.man2.m1.manifest.co.uk
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: checking linux.vcf against perlscanner
database...
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: file linux.vcf is lowercased to linux.vcf
and has extension .vcf
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: compare linux.vcf (size 275) against
perlscanner database
Tue, 27 Apr 2004 20:42:00 +0100:3418: p_s: finished scan of dir
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830949204703418" in 0.039945 secs
Tue, 27 Apr 2004 20:42:00 +0100:3418: ini_sc: scanning message took 11.770061 seconds
Tue, 27 Apr 2004 20:42:00 +0100:3418: q_r: fork off child into
/var/qmail/bin/qmail-queue...
Tue, 27 Apr 2004 20:42:00 +0100:3427: q_r: xstatus=0
Tue, 27 Apr 2004 20:42:00 +0100:3418: cleanup: archiving into
/var/spool/qmailscan/archives/new/
27/04/2004 20:42:12:3418: all finished. Total of 12.088266 secs
Tue, 27 Apr 2004 20:48:41 +0100:3432: +++ starting debugging for process 3432 by
uid=503 at Tue, 27 Apr 2004 20:48:41 +0100
Tue, 27 Apr 2004 20:48:41 +0100:3432: setting UID to EUID so subprocesses can access
files generated by this script
Tue, 27 Apr 2004 20:48:41 +0100:3432: program name is qmail-scanner-queue.pl, version
1.21
Tue, 27 Apr 2004 20:48:41 +0100:3432: incoming SMTP connection from via SMTP from
195.224.154.108
Tue, 27 Apr 2004 20:48:41 +0100:3432: w_c: mkdir
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432
Tue, 27 Apr 2004 20:48:41 +0100:3432: w_c: start dumping incoming msg into
/var/spool/qmailscan/working/tmp/man2.m1.manifest.co.uk10830953214703432
[1083095321.64801]
Tue, 27 Apr 2004 20:48:41 +0100:3432: w_c: primary Content-Type of text/plain found
Tue, 27 Apr 2004 20:48:41 +0100:3432: w_c: rename new msg from
/var/spool/qmailscan/working/tmp/man2.m1.manifest.co.uk10830953214703432 to
/var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830953214703432
[1083095321.66351]
Tue, 27 Apr 2004 20:48:41 +0100:3432: d_m: starting /usr/bin/reformime
-x/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432/
</var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830953214703432
[1083095321.6638]
Tue, 27 Apr 2004 20:48:41 +0100:3432: d_m: finished /usr/bin/reformime
-x/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432/ [1083095322.20316]
Tue, 27 Apr 2004 20:48:41 +0100:3432: d_m: Checking all attachments to see if they're
MS-TNEF
Tue, 27 Apr 2004 20:48:41 +0100:3432: d_m: is
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432/1083095322.3434-0.man2.m1.manifest.co.uk
is a TNEF file?: 256 [1083095322.24492]
Tue, 27 Apr 2004 20:48:41 +0100:3432: d_m: Check for zip files...
Tue, 27 Apr 2004 20:48:41 +0100:3432: d_m: unpacking message took 0.58151 seconds
Tue, 27 Apr 2004 20:48:41 +0100:3432: unsetting QMAILQUEUE env var
Tue, 27 Apr 2004 20:48:41 +0100:3432: g_e_h: return-path is "[EMAIL PROTECTED]",
recips is "[EMAIL PROTECTED]"
Tue, 27 Apr 2004 20:48:41 +0100:3432: from="Benjamin J. Weiss" <[EMAIL
PROTECTED]>,subj=Re: RH rips again Was: extend EOL for Red Hat Linux 9?,
x-qmail-scanner-message-id=<[EMAIL PROTECTED]> via SMTP from 195.224.154.108
Tue, 27 Apr 2004 20:48:41 +0100:3432: ini_sc: start scanning
Tue, 27 Apr 2004 20:48:41 +0100:3432: ini_sc: recursively scan the directory
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432/
Tue, 27 Apr 2004 20:48:41 +0100:3432: scanloop: starting scan of directory
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432"...
Tue, 27 Apr 2004 20:48:41 +0100:3432: scanloop: scanner=spamassassin,plain_text_msg=0
Tue, 27 Apr 2004 20:48:41 +0100:3432: SA: run /usr/bin/spamc -c -f -u "[EMAIL
PROTECTED]" < /var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830953214703432
Tue, 27 Apr 2004 20:53:43 +0100:3443: +++ starting debugging for process 3443 by
uid=503 at Tue, 27 Apr 2004 20:53:43 +0100
Tue, 27 Apr 2004 20:53:43 +0100:3443: setting UID to EUID so subprocesses can access
files generated by this script
Tue, 27 Apr 2004 20:53:43 +0100:3443: program name is qmail-scanner-queue.pl, version
1.21
Tue, 27 Apr 2004 20:53:43 +0100:3443: incoming SMTP connection from via SMTP from
195.224.154.108
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: mkdir
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: start dumping incoming msg into
/var/spool/qmailscan/working/tmp/man2.m1.manifest.co.uk10830956234703443
[1083095624.15214]
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: primary Content-Type of
multipart/alternative found
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: found a top-level boundary definition of
\-\-\-\-_=_NextPart_001_01C42C85\.279ACF2A
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: attachment 1: Content-Type of text/plain
found
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: attachment 2: Content-Type of text/html
found
Tue, 27 Apr 2004 20:53:43 +0100:3443: w_c: rename new msg from
/var/spool/qmailscan/working/tmp/man2.m1.manifest.co.uk10830956234703443 to
/var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830956234703443
[1083095624.71661]
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: starting /usr/bin/reformime
-x/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443/
</var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830956234703443
[1083095625.037]
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: finished /usr/bin/reformime
-x/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443/ [1083095628.48771]
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: Checking all attachments to see if they're
MS-TNEF
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: is
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443/1083095627.3445-0.man2.m1.manifest.co.uk
is a TNEF file?: 256 [1083095628.85789]
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: is
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443/1083095627.3445-1.man2.m1.manifest.co.uk
is a TNEF file?: 256 [1083095629.32514]
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: Check for zip files...
Tue, 27 Apr 2004 20:53:43 +0100:3443: d_m: unpacking message took 4.416332 seconds
Tue, 27 Apr 2004 20:53:43 +0100:3443: unsetting QMAILQUEUE env var
Tue, 27 Apr 2004 20:53:43 +0100:3443: g_e_h: return-path is "[EMAIL PROTECTED]",
recips is "[EMAIL PROTECTED]"
Tue, 27 Apr 2004 20:53:43 +0100:3443: from==?iso-8859-1?Q?Bergstr=F6m_Jonas?= <[EMAIL
PROTECTED]>,subj=SV: HFNetChkPro Users, x-qmail-scanner-message-id=<[EMAIL PROTECTED]>
via SMTP from 195.224.154.108
Tue, 27 Apr 2004 20:53:43 +0100:3443: ini_sc: start scanning
Tue, 27 Apr 2004 20:53:43 +0100:3443: ini_sc: recursively scan the directory
/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443/
Tue, 27 Apr 2004 20:53:43 +0100:3443: scanloop: starting scan of directory
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830956234703443"...
Tue, 27 Apr 2004 20:53:43 +0100:3443: scanloop: scanner=spamassassin,plain_text_msg=0
Tue, 27 Apr 2004 20:53:43 +0100:3443: SA: run /usr/bin/spamc -c -f -u "[EMAIL
PROTECTED]" < /var/spool/qmailscan/working/new/man2.m1.manifest.co.uk10830956234703443
Tue, 27 Apr 2004 20:48:41 +0100:3432: spamassassin: finished scan of dir
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432" in 616.286065 secs
Tue, 27 Apr 2004 20:48:41 +0100:3432: scanloop: finished scan of
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432"...
Tue, 27 Apr 2004 20:48:41 +0100:3432: p_s: starting scan of directory
"/var/spool/qmailscan/tmp/man2.m1.manifest.co.uk10830953214703432"...
Wed, 28 Apr 2004 08:31:27 +0100:3426: +++ starting debugging for process 3426 by
uid=503 at Wed, 28 Apr 2004 08:31:27 +0100
Wed, 28 Apr 2004 08:31:27 +0100:3426: setting UID to EUID so subprocesses can access
files generated by this script
Wed, 28 Apr 2004 08:31:27 +0100:3426: program name is qmail-scanner-queue.pl, version
1.21
