SA failed: Can't locate object method "get_tag" via package "Mail::SpamAssassin::PerMsgStatus" at (eval 86) line 425
Anirudha Patil
anirudha0012 at gmail.com
Mon Feb 11 09:25:20 CET 2013
Hello Folks,
I have a MTA setup of [Postfix + Amavis-new + ClamAV + Spamassasin] of
which only the spamassasin part is disabled. Now i wish to enable the
Spamcontrol part.
But after enabling the spamassasin option in amavis-new, it shows the below
mentioned error.
*(!!)SA failed: Can't locate object method "get_tag" via package
"Mail::SpamAssassin::PerMsgStatus" at (eval 86) line 425, <GEN6> line 29.
at (eval 86) line 467, <GEN6> line 29*.
Also the above line number, does is refer to "spamd" ?
I have already checked the mailing-list for such errors but none are
referring to my case here.
Any help is to direct me towards solving the case would be appreciated.
My Setup details:
Postfix version: 2.7.3
Amavis-new version : 2.6.4-4
Spamassasin version : SpamAssassin version 3.0.1 running on Perl version
5.8.5
[root at host spamassassin]# cat /etc/sysconfig/spamassassin
# Options to spamd
SPAMDOPTIONS="-d -c -m5 -H"
[root at host spamassassin]# cat local.cf
# These values can be overridden by editing ~/.spamassassin/user_prefs.cf
# (see spamassassin(1) for details)
# These should be safe assumptions and allow for simple visual sifting
# without risking lost emails.
required_hits 5
report_safe 0
rewrite_header Subject [SPAM]
[root at host spamassassin]# ps -elf | grep spam
5 S root 29836 1 46 81 0 - 7184 pause 09:38 ? 00:00:00
/usr/bin/spamd -d -c -m5 -H
1 S root 29839 29836 0 78 0 - 7184 - 09:38 ? 00:00:00
spamd child
1 S root 29840 29836 0 78 0 - 7184 - 09:38 ? 00:00:00
spamd child
1 S root 29841 29836 0 81 0 - 7184 - 09:38 ? 00:00:00
spamd child
1 S root 29842 29836 0 81 0 - 7184 - 09:38 ? 00:00:00
spamd child
1 S root 29843 29836 0 81 0 - 7184 - 09:38 ? 00:00:00
spamd child
4 R root 29845 28512 0 78 0 - 1171 - 09:38 pts/2 00:00:00
grep spam
Please find attached the debug info of a message trace for the error
mentioned.
Please let me know if any other additional detail is required
With Regards
Anirudha Patil
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.amavis.org/pipermail/amavis-users/attachments/20130211/0ec5feb7/attachment.html>
-------------- next part --------------
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) SMTP< EHLO myhostname\r\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-[127.0.0.1]
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-VRFY
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-PIPELINING
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-SIZE
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-ENHANCEDSTATUSCODES
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-8BITMIME
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250-DSN
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250 XFORWARD NAME ADDR PORT PROTO HELO SOURCE
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP< XFORWARD NAME=myhostname ADDR=127.0.0.1 PORT=32859\r\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250 2.5.0 Ok XFORWARD
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP< XFORWARD PROTO=ESMTP HELO=mydomain SOURCE=LOCAL\r\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250 2.5.0 Ok XFORWARD
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP< MAIL FROM:<anirudha at myhostname> SIZE=445\r\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) check_mail_begin_task: task_count=1
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) TempDir::prepare: creating directory /var/amavis/tmp/amavis-20130211T090908-29615
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) TempDir::prepare_file: creating file /var/amavis/tmp/amavis-20130211T090908-29615/email.txt
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup_ip_acl: key="127.0.0.1" matches "127.0.0.0/8", result=1
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) loaded policy bank "MYNETS"
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [debug_sender] => undef, "anirudha at myhostname" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250 2.1.0 Sender <anirudha at myhostname> OK
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP< RCPT TO:<myuser at mydomain> ORCPT=rfc822;myuser at mydomain\r\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 250 2.1.5 Recipient <myuser at mydomain> OK
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP< DATA\r\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP::10024 /var/amavis/tmp/amavis-20130211T090908-29615: <anirudha at myhostname> -> <myuser at mydomain> SIZE=445 Received: from myhostname ([127.0.0.1]) by localhost (myhostname at apl.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <myuser at mydomain>; Mon, 11 Feb 2013 09:09:08 -0500 (EST)
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP> 354 End data with <CR><LF>.<CR><LF>
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ESMTP< .<CR><LF>
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) body type (ESMTP BODY): unlabeled, good (h=0, b=0)
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) body hash: 4dea7466963bd8fc5b083eebd62494a9
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Original mail size: 445; quota set to: 222500 bytes
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Checking: zV1thM+SxmOf MYNETS [127.0.0.1] <anirudha at myhostname> -> <myuser at mydomain>
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) 2822.From: <anirudha at myhostname>
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [local_domains] => true, "myuser at mydomain" matches, result="1", matching_key=".mydomain"
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [bypass_virus_checks] => undef, "myuser at mydomain" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [bypass_banned_checks] => undef, "myuser at mydomain" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [bypass_spam_checks] => undef, "myuser at mydomain" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Extracting mime components
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Issued a new file name: p001
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Charging 60 bytes to remaining quota 222500 (out of 222500, (0%)) - by mime_decode
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) p001 1 Content-Type: text/plain, size: 60 B, name:
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) decode_parts: level=1, #parts=1 : p001
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [map_full_type_to_short_type] => true, "ASCII text" matches, result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)"
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) File-type of p001: ASCII text; (asc)
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) do_ascii: Decoding part p001
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) do_ascii: Setting sigaction handler, was 0
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) do_ascii: Decoding part p001 (0 items), uulib V0.5pl20
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) decompose_part: p001 - atomic
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [bypass_header_checks] => undef, "myuser at mydomain" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [bypass_header_checks] => undef, "myuser at mydomain" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Checking for banned types and filenames
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [banned_filename], 1 matches for "myuser at mydomain", results: "(constant:DEFAULT)"=>"DEFAULT"
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) collect banned table[0]: myuser at mydomain, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0xa299e28)
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) starting banned checks - traversing message structure tree
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) check_for_banned (p001) text/plain,.asc
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [check_bann:myuser at mydomain] => undef, ["text/plain",".asc"] does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [banned_namepath_re] => undef, "P=p001\tL=1\tM=text/plain\tT=asc" does not match
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) p.path myuser at mydomain: "P=p001,L=1,M=text/plain,T=asc"
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) banned check: any=0, all=N (1)
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) lookup [keep_decoded_original] => true, "MAIL" matches, result="1", matching_key="(?-xism:^MAIL$)"
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) Issued a new file name: p002
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) presenting full original message to scanners as /var/amavis/tmp/amavis-20130211T090908-29615/parts/p002
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ask_av Using (ClamAV-clamd): CONTSCAN /var/amavis/tmp/amavis-20130211T090908-29615/parts\n
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ClamAV-clamd: Connecting to socket /tmp/clamd.socket
Feb 11 09:09:08 myhostname amavis[29615]: (29615-01) ClamAV-clamd: Sending CONTSCAN /var/amavis/tmp/amavis-20130211T090908-29615/parts\n to UNIX socket /tmp/clamd.socket
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) ask_av (ClamAV-clamd) result: /var/amavis/tmp/amavis-20130211T090908-29615/parts: OK\n
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) run_av (ClamAV-clamd): CLEAN
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) run_av (ClamAV-clamd) result: clean
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) wbl: checking sender <anirudha at myhostname>
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) lookup [blacklist_recip<myuser at mydomain>] => undef, "myuser at mydomain" does not match
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) lookup [blacklist_sender<anirudha at myhostname>,blacklist_sender] => undef, "anirudha at myhostname" does not match
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) lookup [whitelist_recip<myuser at mydomain>] => undef, "myuser at mydomain" does not match
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) lookup [whitelist_sender<anirudha at myhostname>,whitelist_sender] => undef, "anirudha at myhostname" does not match
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) lookup [score_recip<myuser at mydomain>,score_sender], 1 matches for "myuser at mydomain", results: "."=>[Amavis::Lookup::RE=ARRAY(0xa33a0e8),HASH(0xa33a154)]
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) lookup [score_sender<anirudha at myhostname>] => undef, "anirudha at myhostname" does not match
Feb 11 09:09:10 myhostname amavis[29615]: (29615-01) CALLING SA check
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) (!!)SA failed: Can't locate object method "get_tag" via package "Mail::SpamAssassin::PerMsgStatus" at (eval 86) line 425, <GEN6> line 29. at (eval 86) line 467, <GEN6> line 29.
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) spam_scan: score= autolearn= tests=[]
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_tag_level] => true, "myuser at mydomain" matches, result="2", matching_key="(constant:2)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_tag2_level] => true, "myuser at mydomain" matches, result="6.2", matching_key="(constant:6.2)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_tag3_level] => undef, "myuser at mydomain" does not match
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_kill_level] => true, "myuser at mydomain" matches, result="6.9", matching_key="(constant:6.9)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) do_notify_and_quar: ccat=Clean (1,0) ("1":Clean, "0":CatchAll) ccat_block=(), qar_mth=
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) skip admin notification, no administrators
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_tag_level] => true, "myuser at mydomain" matches, result="2", matching_key="(constant:2)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_tag2_level] => true, "myuser at mydomain" matches, result="6.2", matching_key="(constant:6.2)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup [spam_modifies_subj] => true, "myuser at mydomain" matches, result="1", matching_key="(constant:1)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) headers CLUSTERING: NEW CLUSTER <myuser at mydomain>: score=x, tag=0, tag2=0, local=1, bl=, s=, mangle=
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) (about to connect to [127.0.0.1]:10025) FWD via SMTP: <anirudha at myhostname> -> <myuser at mydomain>
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp session: setting up a new session
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp creating socket by IO::Socket::INET to [127.0.0.1]:10025
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp resp to greeting: 220 myhostname ESMTP Postfix
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp cmd> EHLO localhost
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp resp to EHLO: 250 myhostname\nPIPELINING\nSIZE 20971520\nVRFY\nETRN\nENHANCEDSTATUSCODES\n8BITMIME\nDSN
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) AUTH not needed, user='', MTA offers ''
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp cmd> MAIL FROM:<anirudha at myhostname> BODY=7BIT
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp cmd> RCPT TO:<myuser at mydomain> ORCPT=rfc822;myuser at mydomain
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp cmd> DATA
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp resp to MAIL (pip): 250 2.1.0 Ok
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp resp to RCPT (pip) (<myuser at mydomain>): 250 2.1.5 Ok
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF>
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) smtp resp to data-dot (<myuser at mydomain>): 250 2.0.0 Ok: queued as BD3BA78072
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) Amavis::Out::SMTP::Session close, keeping connection
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) FWD via SMTP: <anirudha at myhostname> -> <myuser at mydomain>,BODY=7BIT 250 2.0.0 Ok, id=29615-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as BD3BA78072
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) DSN: sender is credible (orig), SA: 0.000, <anirudha at myhostname>
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup => true, "anirudha at myhostname" matches, result="18", matching_key="(constant:18)"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) notif=N, suppressed=0, ndn_needed=0, exit=0, 250 2.0.0 Ok, id=29615-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as BD3BA78072
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) lookup_ip_acl (publicnetworks): key="127.0.0.1" matches "!127.0.0.0/8", result=0
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) Passed CLEAN, MYNETS LOCAL [127.0.0.1] [127.0.0.1] <anirudha at myhostname> -> <myuser at mydomain>, Message-ID: <20130211140842.7D47C7806E at myhostname>, mail_id: zV1thM+SxmOf, Hits: -, size: 445, queued_as: BD3BA78072, 9805 ms
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) sending SMTP response: "250 2.0.0 Ok, id=29615-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as BD3BA78072"
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) ESMTP> 250 2.0.0 Ok, id=29615-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as BD3BA78072
Feb 11 09:09:17 myhostname postfix/smtp[29646]: 7D47C7806E: to=<myuser at mydomain>, relay=127.0.0.1[127.0.0.1]:10024, delay=42, delays=33/0.04/0.03/9.8, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=29615-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as BD3BA78072)
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) TempDir::strip: /var/amavis/tmp/amavis-20130211T090908-29615
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) rmdir_recursively: /var/amavis/tmp/amavis-20130211T090908-29615/parts, excl=1
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) TIMING [total 9812 ms] - SMTP greeting: 22 (0%)0, SMTP EHLO: 2 (0%)0, SMTP pre-MAIL: 2 (0%)0, mkdir tempdir: 1 (0%)0, create email.txt: 1 (0%)0, SMTP pre-DATA-flush: 7 (0%)0, SMTP DATA: 39 (0%)1, check_init: 2 (0%)1, digest_hdr: 1 (0%)1, digest_body: 1 (0%)1, gen_mail_id: 3 (0%)1, mkdir parts: 3 (0%)1, mime_decode: 27 (0%)1, get-file-type1: 109 (1%)2, decompose_part: 3 (0%)2, parts_decode: 0 (0%)2, check_header: 2 (0%)2, AV-scan-1: 2357 (24%)26, spam-wb-list: 4 (0%)26, SA parse: 5 (0%)26, SA check: 7140 (73%)99, update_cache: 14 (0%)99, decide_mail_destiny: 2 (0%)99, fwd-connect: 28 (0%)100, fwd-mail-pip: 3 (0%)100, fwd-rcpt-pip: 0 (0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 1 (0%)100, fwd-data-contents: 0 (0%)100, fwd-end-chkpnt: 7 (0%)100, prepare-dsn: 2 (0%)100, main_log_entry: 20 (0%)100, update_snmp: 3 (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 1 (0%)100, unlink-2-files: 1 (0%)100, rundown: 1 (0%)100
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) ESMTP< QUIT\r\n
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) ESMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) SMTP session over, timer stopped
Feb 11 09:09:17 myhostname amavis[29615]: (29615-01) load: 100 %, total idle 0.000 s, busy 9.817 s
More information about the amavis-users
mailing list