Strange message !
tlum
mailscanner.info at tedworld.com
Tue Mar 11 18:47:34 GMT 2008
MailWatch.pm might also be found @
./usr/lib/MailScanner/MailScanner/CustomFunctions/MailWatch.pm
MailWatch is logging where it says "Logging message xxxxxxxxxx.xxxxx to
SQL" - after the whole clam issue. However, MailWatch makes frequent
database calls to pull white and black lists, for example.
There is no output to the console and all debug output goes to syslog,
and as far as I can see has already been posted here.
DBI->trace(2,'/root/dbitrace.log'); is already uncommented but generates
no output. This is because the whole thing is running as postfix and
can't write to /root. Pointed it to /tmp and get the following:
->
DBI->connect(dbi:SQLite:/var/spool/MailScanner/incoming/SpamAssassin.cache.db,
, ****, HASH(0xa664b7c))
-> DBI->install_driver(SQLite) for linux perl=5.008008 pid=16827
ruid=89 euid=89
install_driver: DBD::SQLite version 1.14 loaded from
/usr/lib/perl5/site_perl/5.8.8/i386-linux-thread-multi/DBD/SQLite.pm
<- install_driver= DBI::dr=HASH(0xa66f0a4)
!! warn: 0 CLEARED by call to connect method
-> connect for DBD::SQLite::dr (DBI::dr=HASH(0xa66f0a4)~0xa66f0ec
'/var/spool/MailScanner/incoming/SpamAssassin.cache.db' '' ****
HASH(0x974e594)) thr#8cd2008
<- connect= DBI::db=HASH(0xa66f4dc) at DBI.pm line 637
-> STORE for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'PrintError' 0) thr#8cd2008
<- STORE= 1 at DBI.pm line 689
-> STORE for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'AutoCommit' 1) thr#8cd2008
<- STORE= 1 at DBI.pm line 689
-> STORE for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'InactiveDestroy' 1) thr#8cd2008
<- STORE= 1 at DBI.pm line 692
-> FETCH for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'InactiveDestroy') thr#8cd2008
<- FETCH= 1 at DBI.pm line 692
-> STORE for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'Username' '') thr#8cd2008
<- STORE= 1 at DBI.pm line 692
<> FETCH= '' ('Username' from cache) at DBI.pm line 692
-> connected in DBD::_::db for DBD::SQLite::db
(DBI::db=HASH(0xa66f4dc)~0xa66f4ac
'dbi:SQLite:/var/spool/MailScanner/incoming/SpamAssassin.cache.db' '' ''
HASH(0xa664b7c)) thr#8cd2008
<- connected= undef at DBI.pm line 698
<- connect= DBI::db=HASH(0xa66f4dc)
-> STORE for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'dbi_connect_closure' CODE(0xa66f068)) thr#8cd2008
<- STORE= 1 at DBI.pm line 707
-> do in DBD::_::db for DBD::SQLite::db
(DBI::db=HASH(0xa66f4dc)~0xa66f4ac 'CREATE TABLE cache (md5 TEXT, count
INTEGER, last TIMESTAMP, first TIMESTAMP, sasaysspam INT, sahighscoring
INT, sascore FLOAT, saheader BLOB, salongreport BLOB, virusinfected
INT)') thr#8cd2008
1 -> prepare for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'CREATE TABLE cache (md5 TEXT, count INTEGER, last TIMESTAMP, first
TIMESTAMP, sasaysspam INT, sahighscoring INT, sascore FLOAT, saheader
BLOB, salongreport BLOB, virusinfected INT)' undef) thr#8cd2008
sqlite trace: prepare statement: CREATE TABLE cache (md5 TEXT, count
INTEGER, last TIMESTAMP, first TIMESTAMP, sasaysspam INT, sahighscoring
INT, sascore FLOAT, saheader BLOB, salongreport BLOB, virusinfected INT)
at dbdimp.c line 258
-> DESTROY for DBD::SQLite::st (DBI::st=HASH(0xa66f674)~INNER)
thr#8cd2008
DESTROY for DBI::st=HASH(0xa66f674) ignored - handle not
initialised
ERROR: 1 'table cache already exists(1) at dbdimp.c line 271' (err#0)
<- DESTROY= undef at DBI.pm line 1561
!! ERROR: 1 'table cache already exists(1) at dbdimp.c line 271' (err#0)
1 <- prepare= undef at DBI.pm line 1561
!! ERROR: 1 'table cache already exists(1) at dbdimp.c line 271' (err#0)
<- do= undef at SA.pm line 215
!! ERROR: 1 CLEARED by call to do method
-> do for DBD::SQLite::db (DBI::db=HASH(0xa66f4dc)~0xa66f4ac 'CREATE
UNIQUE INDEX md5_uniq ON cache(md5)') thr#8cd2008
1 -> prepare for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'CREATE UNIQUE INDEX md5_uniq ON cache(md5)' undef) thr#8cd2008
sqlite trace: prepare statement: CREATE UNIQUE INDEX md5_uniq ON
cache(md5) at dbdimp.c line 258
-> DESTROY for DBD::SQLite::st (DBI::st=HASH(0x9fab1c8)~INNER)
thr#8cd2008
DESTROY for DBI::st=HASH(0x9fab1c8) ignored - handle not
initialised
ERROR: 1 'index md5_uniq already exists(1) at dbdimp.c line 271'
(err#0)
<- DESTROY= undef at DBI.pm line 1561
!! ERROR: 1 'index md5_uniq already exists(1) at dbdimp.c line 271'
(err#0)
1 <- prepare= undef at DBI.pm line 1561
!! ERROR: 1 'index md5_uniq already exists(1) at dbdimp.c line 271'
(err#0)
<- do= undef at SA.pm line 216
!! ERROR: 1 CLEARED by call to do method
-> do for DBD::SQLite::db (DBI::db=HASH(0xa66f4dc)~0xa66f4ac 'CREATE
INDEX last_seen_idx ON cache(last)') thr#8cd2008
1 -> prepare for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'CREATE INDEX last_seen_idx ON cache(last)' undef) thr#8cd2008
sqlite trace: prepare statement: CREATE INDEX last_seen_idx ON
cache(last) at dbdimp.c line 258
-> DESTROY for DBD::SQLite::st (DBI::st=HASH(0x9ebaa8c)~INNER)
thr#8cd2008
DESTROY for DBI::st=HASH(0x9ebaa8c) ignored - handle not
initialised
ERROR: 1 'index last_seen_idx already exists(1) at dbdimp.c line
271' (err#0)
<- DESTROY= undef at DBI.pm line 1561
!! ERROR: 1 'index last_seen_idx already exists(1) at dbdimp.c line
271' (err#0)
1 <- prepare= undef at DBI.pm line 1561
!! ERROR: 1 'index last_seen_idx already exists(1) at dbdimp.c line
271' (err#0)
<- do= undef at SA.pm line 217
!! ERROR: 1 CLEARED by call to do method
-> do for DBD::SQLite::db (DBI::db=HASH(0xa66f4dc)~0xa66f4ac 'CREATE
INDEX first_seen_idx ON cache(first)') thr#8cd2008
1 -> prepare for DBD::SQLite::db (DBI::db=HASH(0xa66f4ac)~INNER
'CREATE INDEX first_seen_idx ON cache(first)' undef) thr#8cd2008
sqlite trace: prepare statement: CREATE INDEX first_seen_idx ON
cache(first) at dbdimp.c line 258
-> DESTROY for DBD::SQLite::st (DBI::st=HASH(0xa66f74c)~INNER)
thr#8cd2008
DESTROY for DBI::st=HASH(0xa66f74c) ignored - handle not
initialised
ERROR: 1 'index first_seen_idx already exists(1) at dbdimp.c line
271' (err#0)
<- DESTROY= undef at DBI.pm line 1561
!! ERROR: 1 'index first_seen_idx already exists(1) at dbdimp.c line
271' (err#0)
1 <- prepare= undef at DBI.pm line 1561
!! ERROR: 1 'index first_seen_idx already exists(1) at dbdimp.c line
271' (err#0)
<- do= undef at SA.pm line 218
!! ERROR: 1 CLEARED by call to prepare method
-> prepare for DBD::SQLite::db (DBI::db=HASH(0xa66f4dc)~0xa66f4ac '
DELETE FROM cache WHERE (
(sasaysspam=0 AND virusinfected<1 AND first<=(strftime('%s','now')-?)) OR
(sasaysspam>0 AND sahighscoring=0 AND virusinfected<1 AND
first<=(strftime('%s','now')-?)) OR
(sasaysspam>0 AND sahighscoring>0 AND virusinfected<1 AND
last<=(strftime('%s','now')-?)) OR
(virusinfected>=1 AND last<=(strftime('%s','now')-?))
)') thr#8cd2008
sqlite trace: prepare statement:
DELETE FROM cache WHERE (
(sasaysspam=0 AND virusinfected<1 AND first<=(strftime('%s','now')-?)) OR
(sasaysspam>0 AND sahighscoring=0 AND virusinfected<1 AND
first<=(strftime('%s','now')-?)) OR
(sasaysspam>0 AND sahighscoring>0 AND virusinfected<1 AND
last<=(strftime('%s','now')-?)) OR
(virusinfected>=1 AND last<=(strftime('%s','now')-?))
) at dbdimp.c line 258
<- prepare= DBI::st=HASH(0xa66f7dc) at SA.pm line 730
-> execute for DBD::SQLite::st (DBI::st=HASH(0xa66f7dc)~0xa66f818
'1800' '300' '10800' '172800') thr#8cd2008
<- execute= '0E0' at SA.pm line 738
-> finish for DBD::SQLite::st (DBI::st=HASH(0xa66f7dc)~0xa66f818)
thr#8cd2008
<- finish= 1 at SA.pm line 739
-> DESTROY for DBD::SQLite::st (DBI::st=HASH(0xa66f818)~INNER)
thr#8cd2008
<- DESTROY= undef at SA.pm line 222
Rick Cooper wrote:
> First off, this appears to be a perl error being directed to stderr
> and that is why it's showing up in your clamd parsing. I am not sure
> where in the process mailwatch is logging, and the mailwatch people
> might know right off the bat, however; Perhaps you should look at the
> debug output (both console and logging) and post those here and also
> look at the top of
> /opt/MailScanner/lib/MailScanner/CustomFunctions/MailWatch.pm for:
>
> # DBI->trace(2,'/root/dbitrace.log');
>
> and uncomment that and check the trace log.
>
> Also run MailScanner -v and post/check the output
>
> Rick
>
> ------------------------------------------------------------------------
> *From:* mailscanner-bounces at lists.mailscanner.info
> [mailto:mailscanner-bounces at lists.mailscanner.info] *On Behalf Of
> *Thiago Henrique
> *Sent:* Tuesday, March 11, 2008 10:51 AM
> *To:* MailScanner discussion
> *Subject:* Re: Strange message !
>
> Rick,
>
> I'm using MailWatch for parse logs, every message have logged in
> mysql data base. The strange messages occur after a virus scanner
> start:
>
> Mar 11 08:49:20 morpheus MailScanner[20893]: Virus and Content
> Scanning: Starting
> Mar 11 08:49:20 morpheus MailScanner[20893]: Clamd:: --
> DBI::END ($@: , $!: )
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd:: ->
> disconnect_all for DBD::mysql::dr (DBI::dr=HASH(0x932a7ec)~0x932cac4)
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd:: <-
> disconnect_all= (not implemented) at DBI.pm line 718
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd:: ->
> disconnect_all for DBD::SQLite::dr (DBI::dr=HASH(0x98d6e64)~0x98d6eac)
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd:: <-
> disconnect_all= '' at DBI.pm line 718
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::! -> DESTROY
> for DBD::SQLite::db (DBI::db=HASH(0x98dab98)~INNER)
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::
> DESTROY DBI::db=HASH(0x98dab98) skipped due to InactiveDestroy
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::! <-
> DESTROY= undef during global destruction
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::! -> DESTROY
> in DBD::_::common for DBD::SQLite::dr (DBI::dr=HASH(0x98d6eac)~INNER)
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::! <-
> DESTROY= undef during global destruction
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::! -> DESTROY
> in DBD::_::dr for DBD::mysql::dr (DBI::dr=HASH(0x932cac4)~INNER)
> Mar 11 08:49:21 morpheus MailScanner[20893]: Clamd::! <-
> DESTROY= undef during global destruction
> Mar 11 08:49:21 morpheus MailScanner[20893]: Virus Scanning: Clamd
> found 12 infections
> Mar 11 08:49:21 morpheus MailScanner[20893]: Virus Scanning: Found
> 12 viruses
> Mar 11 08:49:21 morpheus MailScanner[20893]: Requeue:
> 2E48351F14.1A77F to 9FF1B778CA
> Mar 11 08:49:21 morpheus MailScanner[20893]: Uninfected: Delivered
> 1 messages
> Mar 11 08:49:21 morpheus MailScanner[20893]: Logging message
> 2E48351F14.1A77F to SQL
>
> The mail is sent normally to the user, but every 12 lines of error
> is considered virus for MailScanner.
>
>
>
> On Tue, Mar 11, 2008 at 10:49 AM, Rick Cooper <rcooper at dwford.com
> <mailto:rcooper at dwford.com>> wrote:
>
>
>
> ------------------------------------------------------------------------
> *From:* mailscanner-bounces at lists.mailscanner.info
> <mailto:mailscanner-bounces at lists.mailscanner.info>
> [mailto:mailscanner-bounces at lists.mailscanner.info
> <mailto:mailscanner-bounces at lists.mailscanner.info>] *On
> Behalf Of *Thiago Henrique
> *Sent:* Monday, March 10, 2008 8:53 PM
> *To:* mailscanner at lists.mailscanner.info
> <mailto:mailscanner at lists.mailscanner.info>
> *Subject:* Strange message !
>
> Hy All,
>
> After a upgrade for MailScanner 4.66.5, and configured
> MailScanner to use CLAMD, i have the following message in
> mail.log on every mail scanned:
>
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd:: --
> DBI::END ($@: , $!: )
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd:: ->
> disconnect_all for DBD::mysql::dr
> (DBI::dr=HASH(0x932a67c)~0x932c954)
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd:: <-
> disconnect_all= (not implemented) at DBI.pm line 718
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd:: ->
> disconnect_all for DBD::SQLite::dr
> (DBI::dr=HASH(0x98d6e34)~0x98d6e7c)
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd:: <-
> disconnect_all= '' at DBI.pm line 718
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd::! ->
> DESTROY for DBD::SQLite::db (DBI::db=HASH(0x98dab60)~INNER)
> Mar 10 21:48:51 morpheus MailScanner[30706]:
> Clamd:: DESTROY DBI::db=HASH(0x98dab60) skipped
> due to InactiveDestroy
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd::! <-
> DESTROY= undef during global destruction
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd::! ->
> DESTROY in DBD::_::common for DBD::SQLite::dr
> (DBI::dr=HASH(0x98d6e7c)~INNER)
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd::! <-
> DESTROY= undef during global destruction
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd::! ->
> DESTROY in DBD::_::dr for DBD::mysql::dr
> (DBI::dr=HASH(0x932c954)~INNER)
> Mar 10 21:48:51 morpheus MailScanner[30706]: Clamd::! <-
> DESTROY= undef during global destruction
> Mar 10 21:48:51 morpheus MailScanner[30706]: Virus
> Scanning: Clamd found 12 infections
> Mar 10 21:48:51 morpheus MailScanner[30706]: Virus
> Scanning: Found 12 viruses
>
>
>
> [Rick Cooper]
> Are you using sql logging, or is this a mailwatch issue?
>
> Rick
>
>
> --
> This message has been scanned for viruses and
> dangerous content by *MailScanner*
> <http://www.mailscanner.info/>, and is
> believed to be clean.
>
> --
> MailScanner mailing list
> mailscanner at lists.mailscanner.info
> <mailto:mailscanner at lists.mailscanner.info>
> http://lists.mailscanner.info/mailman/listinfo/mailscanner
>
> Before posting, read http://wiki.mailscanner.info/posting
>
> Support MailScanner development - buy the book off the website!
>
>
>
> --
> This message has been scanned for viruses and
> dangerous content by *MailScanner* <http://www.mailscanner.info/>,
> and is
> believed to be clean.
>
>
> --
> This message has been scanned for viruses and
> dangerous content by *MailScanner* <http://www.mailscanner.info/>, and is
> believed to be clean.
> --
> This message has been scanned for viruses and
> dangerous content by *MailScanner* <http://www.mailscanner.info/>, and is
> believed to be clean.
--
This message has been scanned for viruses and
dangerous content by MailScanner, and is
believed to be clean.
More information about the MailScanner
mailing list