Mailscanner does not scan mails

LGi at b-w-computer.de LGi at b-w-computer.de
Fri Oct 8 13:24:46 IST 2010


I just ugraded to MailScanner-4.81.4-1

All seems fine, but it's just not scanning messages.
The debug output says:

        14:10:29 Building a message batch to scan...

but nothing happens

ps ax shows:

        29532 pts/3    S+     0:38 MailScanner: waiting for messages

The Incoming Queue Dir is configured correctly:

Incoming Queue Dir = /var/spool/postfix/hold

When I start the job with strace the Mailscanner processs seem to look 
into the queue directory every 6 seconds:

[pid 29692] chdir("/var/spool/postfix/hold") = 0
[pid 29692] open(".", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|0x80000) 
= 9
[pid 29692] getdents64(9, /* 120 entries */, 32768) = 3824
[pid 29692] getdents64(9, /* 0 entries */, 32768) = 0
[pid 29692] close(9)                    = 0
[pid 29692] umask(0177)                 = 077
[pid 29692] umask(077)                  = 0177
[pid 29692] time(NULL)                  = 1286540143
[pid 29692] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 29692] rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
[pid 29692] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 29692] nanosleep({6, 0}, {6, 0})   = 0
[pid 29692] time(NULL)                  = 1286540149
[pid 29692] chdir("/var/spool/postfix/hold") = 0
[pid 29692] open(".", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|0x80000) 
= 9
[pid 29692] getdents64(9, /* 120 entries */, 32768) = 3824
[pid 29692] getdents64(9, /* 0 entries */, 32768) = 0
[pid 29692] close(9)                    = 0
[pid 29692] umask(0177)                 = 077
[pid 29692] umask(077)                  = 0177
[pid 29692] time(NULL)                  = 1286540149
[pid 29692] rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 29692] rt_sigaction(SIGCHLD, NULL, {SIG_DFL}, 8) = 0
[pid 29692] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 29692] nanosleep({6, 0},


There are several new messages in the directory /var/spool/postfix/hold 
but MailScanner does not pick them.

any idea how to get this to work?
Previus Version MailScanner-4.52.2 is working fine.





best regards


Lars Gierling




Think before you print
Diese E-Mail und alle Anhänge enthalten vertrauliche und/oder rechtlich 
geschützte Informationen. Wenn Sie nicht der richtige Adressat sind oder 
diese E-Mail irrtümlich erhalten haben, informieren Sie bitte sofort den 
Absender und vernichten Sie diese E-Mail und ihren Inhalt. Das unerlaubte 
Kopieren sowie die unbefugte Weitergabe dieser E-Mail ist nicht gestattet.

This e-mail and any attached files may contain confidential and/or 
privileged information. If you are not the intended recipient (or have 
received this e-mail by mistake) please notify the sender immediately and 
delete this e-mail. Any unauthorised duplication, disclosure or 
distribution of this e-mail and content is strictly forbidden. 

-------------- next part --------------
fw-1 opt # /opt/MailScanner/bin/MailScanner --debug --debug-sa


In Debugging mode, not forking...
Trying to setlogsock(unix)
14:09:53 Oct  8 14:09:53.455 [29532] dbg: logger: adding facilities: all
14:09:53 Oct  8 14:09:53.455 [29532] dbg: logger: logging level is DBG
14:09:53 Oct  8 14:09:53.456 [29532] dbg: generic: SpamAssassin version 3.3.1
14:09:53 Oct  8 14:09:53.456 [29532] dbg: generic: Perl 5.008008, PREFIX=/usr, DEF_RULES_DIR=/usr/share/spamassassin, LOCAL_RULES_DIR=/etc/mail/spamassassin, LOCAL_STATE_DIR=/var/lib/spamassassin
14:09:53 Oct  8 14:09:53.456 [29532] dbg: config: timing enabled
14:09:53 Oct  8 14:09:53.458 [29532] dbg: config: score set 0 chosen.
14:09:53 Oct  8 14:09:53.462 [29532] dbg: util: running in taint mode? no
14:09:53 Oct  8 14:09:53.470 [29532] dbg: dns: no ipv6
14:09:53 Oct  8 14:09:53.470 [29532] dbg: dns: is Net::DNS::Resolver available? yes
14:09:53 Oct  8 14:09:53.470 [29532] dbg: dns: Net::DNS version: 0.65
14:09:53 Oct  8 14:09:53.472 [29532] dbg: config: using "/etc/mail/spamassassin" for site rules pre files
14:09:53 Oct  8 14:09:53.472 [29532] dbg: config: read file /etc/mail/spamassassin/init.pre
14:09:53 Oct  8 14:09:53.473 [29532] dbg: config: read file /etc/mail/spamassassin/v310.pre
14:09:53 Oct  8 14:09:53.473 [29532] dbg: config: read file /etc/mail/spamassassin/v312.pre
14:09:53 Oct  8 14:09:53.473 [29532] dbg: config: read file /etc/mail/spamassassin/v320.pre
14:09:53 Oct  8 14:09:53.474 [29532] dbg: config: read file /etc/mail/spamassassin/v330.pre
14:09:53 Oct  8 14:09:53.474 [29532] dbg: config: using "/usr/share/spamassassin" for sys rules pre files
14:09:53 Oct  8 14:09:53.474 [29532] dbg: config: using "/usr/share/spamassassin" for default rules dir
14:09:53 Oct  8 14:09:53.475 [29532] dbg: config: using "/etc/mail/spamassassin" for site rules dir
14:09:53 Oct  8 14:09:53.476 [29532] dbg: config: read file /etc/mail/spamassassin/local.cf
14:09:53 Oct  8 14:09:53.476 [29532] dbg: config: read file /etc/mail/spamassassin/mailscanner.cf
14:09:53 Oct  8 14:09:53.476 [29532] dbg: config: read file /etc/mail/spamassassin/secrets.cf
14:09:53 Oct  8 14:09:53.478 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDNSBL from @INC
14:09:53 Oct  8 14:09:53.491 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::Hashcash from @INC
14:09:53 Oct  8 14:09:53.499 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::SPF from @INC
14:09:53 Oct  8 14:09:53.509 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::Pyzor from @INC
14:09:53 Oct  8 14:09:53.515 [29532] dbg: pyzor: network tests on, attempting Pyzor
14:09:53 Oct  8 14:09:53.515 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::Razor2 from @INC
14:09:53 Oct  8 14:09:53.521 [29532] dbg: razor2: razor2 is not available
14:09:53 Oct  8 14:09:53.522 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::SpamCop from @INC
14:09:53 Oct  8 14:09:53.549 [29532] dbg: reporter: network tests on, attempting SpamCop
14:09:53 Oct  8 14:09:53.550 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC
14:09:53 Oct  8 14:09:53.553 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::WhiteListSubject from @INC
14:09:53 Oct  8 14:09:53.555 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEHeader from @INC
14:09:53 Oct  8 14:09:53.558 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::ReplaceTags from @INC
14:09:53 Oct  8 14:09:53.562 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::DKIM from @INC
14:09:53 Oct  8 14:09:53.574 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::Check from @INC
14:09:53 Oct  8 14:09:53.591 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTTPSMismatch from @INC
14:09:53 Oct  8 14:09:53.593 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIDetail from @INC
14:09:53 Oct  8 14:09:53.597 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::Bayes from @INC
14:09:53 Oct  8 14:09:53.619 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::BodyEval from @INC
14:09:53 Oct  8 14:09:53.624 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::DNSEval from @INC
14:09:53 Oct  8 14:09:53.631 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::HTMLEval from @INC
14:09:53 Oct  8 14:09:53.636 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::HeaderEval from @INC
14:09:53 Oct  8 14:09:53.651 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::MIMEEval from @INC
14:09:53 Oct  8 14:09:53.658 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::RelayEval from @INC
14:09:53 Oct  8 14:09:53.664 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::URIEval from @INC
14:09:53 Oct  8 14:09:53.666 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::WLBLEval from @INC
14:09:53 Oct  8 14:09:53.672 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::VBounce from @INC
14:09:53 Oct  8 14:09:53.675 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::ImageInfo from @INC
14:09:53 Oct  8 14:09:53.681 [29532] dbg: plugin: loading Mail::SpamAssassin::Plugin::FreeMail from @INC
14:09:53 Oct  8 14:09:53.695 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::FreeMail=HASH(0xb9f6a3c8) implements 'parse_config', priority 0
14:09:53 Oct  8 14:09:53.695 [29532] info: config: failed to parse line, skipping, in "/etc/mail/spamassassin/mailscanner.cf": use_auto_whitelist 0
14:09:53 Oct  8 14:09:53.697 [29532] dbg: config: finish parsing
14:09:53 Oct  8 14:09:53.698 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::ReplaceTags=HASH(0xb9d52e98) implements 'finish_parsing_end', priority 0
14:09:53 Oct  8 14:09:53.698 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::FreeMail=HASH(0xb9f6a3c8) implements 'finish_parsing_end', priority 0
14:09:53 Oct  8 14:09:53.698 [29532] dbg: replacetags: replacing tags
14:09:53 Oct  8 14:09:53.698 [29532] dbg: replacetags: done replacing tags
14:09:53 Oct  8 14:09:53.699 [29532] dbg: FreeMail: no freemail_domains entries defined, disabling plugin
14:09:53 Oct  8 14:09:53.701 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0xb9df392c) implements 'learner_new', priority 0
14:09:53 Oct  8 14:09:53.702 [29532] dbg: bayes: learner_new self=Mail::SpamAssassin::Plugin::Bayes=HASH(0xb9df392c), bayes_store_module=Mail::SpamAssassin::BayesStore::DBM
14:09:53 Oct  8 14:09:53.733 [29532] dbg: bayes: learner_new: got store=Mail::SpamAssassin::BayesStore::DBM=HASH(0xb9f88be8)
14:09:53 Oct  8 14:09:53.734 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0xb9df392c) implements 'learner_is_scan_available', priority 0
14:09:53 Oct  8 14:09:53.734 [29532] dbg: bayes: tie-ing to DB file R/O /var/spool/MailScanner/spamassassin/bayes_toks
14:09:53 Oct  8 14:09:53.735 [29532] dbg: bayes: tie-ing to DB file R/O /var/spool/MailScanner/spamassassin/bayes_seen
14:09:53 Oct  8 14:09:53.736 [29532] dbg: bayes: found bayes db version 3
14:09:53 Oct  8 14:09:53.737 [29532] dbg: bayes: DB journal sync: last sync: 0
14:09:53 Oct  8 14:09:53.738 [29532] dbg: bayes: not available for scanning, only 0 spam(s) in bayes DB < 200
14:09:53 Oct  8 14:09:53.738 [29532] dbg: bayes: untie-ing
14:09:53 Oct  8 14:09:53.738 [29532] dbg: config: score set 1 chosen.
14:09:53 Oct  8 14:09:53.739 [29532] dbg: ignore: test message to precompile patterns and load modules
14:09:53 Oct  8 14:09:53.739 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::HeaderEval=HASH(0xb9ed15e4) implements 'compile_now_start', priority 0
14:09:53 Oct  8 14:09:53.740 [29532] dbg: eval: failed to locate the triplets.txt file
14:09:53 Oct  8 14:09:53.741 [29532] dbg: message: main message type: text/plain
14:09:53 Oct  8 14:09:53.741 [29532] dbg: message: ---- MIME PARSER START ----
14:09:53 Oct  8 14:09:53.741 [29532] dbg: message: parsing normal part
14:09:53 Oct  8 14:09:53.741 [29532] dbg: message: ---- MIME PARSER END ----
14:09:53 Oct  8 14:09:53.742 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::DNSEval=HASH(0xb9e7486c) implements 'check_start', priority 0
14:09:53 Oct  8 14:09:53.744 [29532] dbg: bayes: tie-ing to DB file R/O /var/spool/MailScanner/spamassassin/bayes_toks
14:09:53 Oct  8 14:09:53.745 [29532] dbg: bayes: tie-ing to DB file R/O /var/spool/MailScanner/spamassassin/bayes_seen
14:09:53 Oct  8 14:09:53.746 [29532] dbg: bayes: found bayes db version 3
14:09:53 Oct  8 14:09:53.747 [29532] dbg: bayes: DB journal sync: last sync: 0
14:09:53 Oct  8 14:09:53.747 [29532] dbg: bayes: not available for scanning, only 0 spam(s) in bayes DB < 200
14:09:53 Oct  8 14:09:53.747 [29532] dbg: bayes: untie-ing
14:09:53 Oct  8 14:09:53.748 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::Check=HASH(0xb9dd98b0) implements 'check_main', priority 0
14:09:53 Oct  8 14:09:53.749 [29532] dbg: config: trusted_networks are not configured; it is recommended that you configure trusted_networks manually
14:09:53 Oct  8 14:09:53.749 [29532] dbg: metadata: X-Spam-Relays-Trusted:
14:09:53 Oct  8 14:09:53.750 [29532] dbg: metadata: X-Spam-Relays-Untrusted:
14:09:53 Oct  8 14:09:53.750 [29532] dbg: metadata: X-Spam-Relays-Internal:
14:09:53 Oct  8 14:09:53.750 [29532] dbg: metadata: X-Spam-Relays-External:
14:09:53 Oct  8 14:09:53.751 [29532] dbg: message: no encoding detected
14:09:53 Oct  8 14:09:53.751 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH(0xb9c469e0) implements 'parsed_metadata', priority 0
14:09:53 Oct  8 14:09:53.752 [29532] dbg: dns: no ipv6
14:09:53 Oct  8 14:09:53.752 [29532] dbg: dns: is Net::DNS::Resolver available? yes
14:09:53 Oct  8 14:09:53.753 [29532] dbg: dns: Net::DNS version: 0.65
14:09:53 Oct  8 14:09:53.753 [29532] dbg: dns: name server: 193.97.213.10, LocalAddr: 0.0.0.0
14:09:53 Oct  8 14:09:53.754 [29532] dbg: dns: resolver socket rx buffer size is 108544 bytes
14:09:53 Oct  8 14:09:53.754 [29532] dbg: dns: dns_available set to yes in config file, skipping test
14:09:53 Oct  8 14:09:53.757 [29532] dbg: uridnsbl: domains to query:
14:09:53 Oct  8 14:09:53.758 [29532] dbg: check: running tests for priority: 0
14:09:53 Oct  8 14:09:53.758 [29532] dbg: rules: running head tests; score so far=0
14:09:53 Oct  8 14:09:53.760 [29532] dbg: rules: flush_evalstr (run_generic_tests) compiling 858 chars of Mail::SpamAssassin::Plugin::Check::_head_tests_0_1
14:09:53 Oct  8 14:09:53.760 [29532] dbg: rules: run_generic_tests - compiling eval code: head, priority 0
14:09:53 Oct  8 14:09:53.761 [29532] dbg: rules: compiled head tests
14:09:53 Oct  8 14:09:53.761 [29532] dbg: rules: running body tests; score so far=0
14:09:53 Oct  8 14:09:53.762 [29532] dbg: rules: flush_evalstr (run_generic_tests) compiling 221 chars of Mail::SpamAssassin::Plugin::Check::_body_tests_0_1
14:09:53 Oct  8 14:09:53.762 [29532] dbg: rules: run_generic_tests - compiling eval code: body, priority 0
14:09:53 Oct  8 14:09:53.763 [29532] dbg: rules: compiled body tests
14:09:53 Oct  8 14:09:53.763 [29532] dbg: rules: running uri tests; score so far=0
14:09:53 Oct  8 14:09:53.763 [29532] dbg: rules: flush_evalstr (run_generic_tests) compiling 219 chars of Mail::SpamAssassin::Plugin::Check::_uri_tests_0_1
14:09:53 Oct  8 14:09:53.764 [29532] dbg: rules: run_generic_tests - compiling eval code: uri, priority 0
14:09:53 Oct  8 14:09:53.764 [29532] dbg: rules: compiled uri tests
14:09:53 Oct  8 14:09:53.765 [29532] dbg: rules: running rawbody tests; score so far=0
14:09:53 Oct  8 14:09:53.765 [29532] dbg: rules: flush_evalstr (run_generic_tests) compiling 227 chars of Mail::SpamAssassin::Plugin::Check::_rawbody_tests_0_1
14:09:53 Oct  8 14:09:53.766 [29532] dbg: rules: run_generic_tests - compiling eval code: rawbody, priority 0
14:09:53 Oct  8 14:09:53.766 [29532] dbg: rules: compiled rawbody tests
14:09:53 Oct  8 14:09:53.767 [29532] dbg: rules: running full tests; score so far=0
14:09:53 Oct  8 14:09:53.767 [29532] dbg: rules: flush_evalstr (run_generic_tests) compiling 256 chars of Mail::SpamAssassin::Plugin::Check::_full_tests_0_1
14:09:53 Oct  8 14:09:53.767 [29532] dbg: rules: run_generic_tests - compiling eval code: full, priority 0
14:09:53 Oct  8 14:09:53.768 [29532] dbg: rules: compiled full tests
14:09:53 Oct  8 14:09:53.768 [29532] dbg: rules: running meta tests; score so far=0
14:09:53 Oct  8 14:09:53.769 [29532] dbg: rules: flush_evalstr (run_generic_tests) compiling 281 chars of Mail::SpamAssassin::Plugin::Check::_meta_tests_0_1
14:09:53 Oct  8 14:09:53.769 [29532] dbg: rules: run_generic_tests - compiling eval code: meta, priority 0
14:09:53 Oct  8 14:09:53.770 [29532] dbg: rules: compiled meta tests
14:09:53 Oct  8 14:09:53.770 [29532] dbg: dns: harvest_dnsbl_queries
14:09:53 Oct  8 14:09:53.771 [29532] dbg: check: is spam? score=0 required=5
14:09:53 Oct  8 14:09:53.772 [29532] dbg: check: tests=
14:09:53 Oct  8 14:09:53.772 [29532] dbg: check: subtests=
14:09:53 Oct  8 14:09:53.773 [29532] dbg: plugin: Mail::SpamAssassin::Plugin::Bayes=HASH(0xb9df392c) implements 'learner_close', priority 0

14:10:29 Building a message batch to scan...
-------------- next part --------------
fw-1 opt # /opt/MailScanner/bin/MailScanner --lint
Trying to setlogsock(unix)

Reading configuration file /opt/MailScanner/etc/MailScanner.conf
Reading configuration file /opt/MailScanner/etc/conf.d/README
Read 865 hostnames from the phishing whitelist
Read 5718 hostnames from the phishing blacklists

Checking version numbers...
Version number in MailScanner.conf (4.81.4) is correct.

ERROR: The "envelope_sender_header" in your spam.assassin.prefs.conf
ERROR: is not correct, it should match X-VOSSCHEMIE-MailScanner-From

MailScanner setting GID to  (207)
MailScanner setting UID to  (207)

Checking for SpamAssassin errors (if you use it)...
Using SpamAssassin results cache
Connected to SpamAssassin cache database
SpamAssassin reported no errors.
Connected to Processing Attempts Database
Created Processing Attempts Database successfully
There are 0 messages in the Processing Attempts Database
lock.pl sees Config  LockType =  posix
lock.pl sees have_module =  0
Using locktype = posix
MailScanner.conf says "Virus Scanners = clamavmodule"
Debug Mode Is On
Use Threads : NO
Socket    : /tmp/clamd.socket
IP        : Using Sockets
Lock File : NOT USED
Time Out  : 300
Scan Dir  : /var/spool/MailScanner/incoming/30108/ISITINSTALLED
Found these virus scanners installed: clamavmodule
===========================================================================
Created attachment dirs for 1 messages
Looked up unknown string nonpasswordedarchive in language translation file /opt/MailScanner/etc/vosschemie-reports/de/languages.conf at /opt/MailScanner/lib/MailScanner/Config.pm line 1372
Filename Checks: Windows/DOS Executable (1 eicar.com)
Completed checking by /usr/bin/file
Other Checks: Found 1 problems
Virus and Content Scanning: Starting
Commencing scanning by clamavmodule...
ClamAVModule::INFECTED:: Eicar-Test-Signature:: ./1/eicar.com
Completed scanning by clamavmodule
Virus Scanning: ClamAVModule found 2 infections
Infected message 1 came from 10.1.1.1
Virus Scanning: Found 2 viruses
===========================================================================
Virus Scanner test reports:
ClamAVModule said "eicar.com was infected: Eicar-Test-Signature"

If any of your virus scanners (clamavmodule)
are not listed there, you should check that they are installed correctly
and that MailScanner is finding them correctly via its virus.scanners.conf.


More information about the MailScanner mailing list