clamav (under amavis) not filtering out viruses!

[Dino Edwards]

Hi Niko,

Try this:

https://github.com/extremeshok/clamav-unofficial-sigs

This has worked wonderfully for us.



-----Original Message-----
From: amavis-users <amavis-users-bounces+dino.edwards=mydirectmail.net at amavis.org> On Behalf Of Nikolaos Milas
Sent: Thursday, October 15, 2020 8:41 AM
To: amavis-users at amavis.org
Subject: Re: clamav (under amavis) not filtering out viruses!

On 15/10/2020 3:26 μ.μ., Nikolaos Milas wrote:

> This doesn't seem to be the problem, because the infected attachments 
> are simply found CLEAN;


For your reference, here is a verbose log of the AV check on a message which should have been found INFECTED, but it is rather judged CLEAN:

==================================================================================

Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Extracting mime components from a string Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Issued a new file name: 
p001
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Issued a new file name: 
p002
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Issued a new pseudo
part: p003
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) p003 1 Content-Type: 
multipart/mixed
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) mime_decode_epilogue: 1 lines Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Charging 239 bytes to remaining quota 97559500 (out of 97559500, (0%)) - by mime_decode Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) p001 1/1 Content-Type: 
text/html, size: 239 B, name:
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) reparenting p001 from
p000 to p003
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Charging 140468 bytes to remaining quota 97559261 (out of 97559500, (0%)) - by mime_decode Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) p002 1/2 Content-Type: 
application/msword, size: 140468 B, name: attachments 54972.doc Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) reparenting p002 from
p000 to p003
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline mime_decode - deadline in 480.0 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
mime_decode: timer 336, was 336, deadline in 480.0 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline
mime_decode-1 - deadline in 480.0 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
mime_decode-1: timer 336, was 336, deadline in 480.0 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) decode_parts: level=1,
#parts=3 : p001, p002, p003
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) running file(1) on 2 files, arglist size 23 Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_command: [3286] /usr/bin/file p001 p002 </dev/null 2>&1 Oct 15 14:43:44 mailgw3 amavis[3286]: (03253-10) open_on_specific_fd: 
target fd0 closing, to become < /dev/null Oct 15 14:43:44 mailgw3 amavis[3286]: (03253-10) open_on_specific_fd: 
target fd1 closing, to become (65) &=13
Oct 15 14:43:44 mailgw3 amavis[3286]: (03253-10) open_on_specific_fd: 
target fd1 dup2 from fd13 (65) &=13
Oct 15 14:43:44 mailgw3 amavis[3286]: (03253-10) open_on_specific_fd: 
source fd13 closed
Oct 15 14:43:44 mailgw3 amavis[3286]: (03253-10) open_on_specific_fd: 
target fd2 closing, to become (65) &1
Oct 15 14:43:44 mailgw3 amavis[3286]: (03253-10) open_on_specific_fd: 
target fd2 dup2 from fd1 (65) &1
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) result line from
file(1): p001: HTML document text\n
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup_re("HTML document text") matches key "(?-xism:^HTML document text\b)", result="html"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [map_full_type_to_short_type] => true,  "HTML document text" matches, result="html", matching_key="(?-xism:^HTML document text\134b)"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) File-type of p001: HTML document text; (html) Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) result line from
file(1): p002: CDF V2 Document, corrupt: Can't expand summary_info\n Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup_re("CDF V2 Document, corrupt: Can't expand summary_info") matches key "(?-xism:^)", result="dat"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [map_full_type_to_short_type] => true,  "CDF V2 Document, corrupt: Can't expand summary_info" matches, result="dat",matching_key="(?-xism:^)"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) File-type of p002: CDF
V2 Document, corrupt: Can't expand summary_info; (dat) Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) decompose_part: p001 - atomic Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) decompose_part: p002 - atomic Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline parts_decode - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
parts_decode: timer 336, was 336, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup: (scalar) matches, result="1"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [bypass_header_checks] => true,  "userxxx at noa.gr" matches, result="1", matching_key="(constant:1)"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Checking for banned types and filenames Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup: (scalar) matches, result="DEFAULT"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [banned_filename], 1 matches for "userxxx at noa.gr", results: 
"(constant:DEFAULT)"=>"DEFAULT"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) collect banned
table[0]: userxxx at noa.gr, tables: 
DEFAULT=>Amavis::Lookup::RE=ARRAY(0x35a37f8)
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) starting banned checks
- traversing message structure tree
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) check_for_banned
(p003,p001) multipart/mixed | text/html,.html Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) doing banned check for userxxx at noa.gr on multipart/mixed | text/html,.html Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup_re(["multipart/mixed","text/html",".html"]), no matches Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [check_bann:userxxx at noa.gr] => undef, ["multipart/mixed","text/html",".html"] does not match Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [banned_namepath_re] => undef, "P=p003\tL=1\tM=multipart/mixed\nP=p001\tL=1/1\tM=text/html\tT=html" 
does not match
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) p.path userxxx at noa.gr: 
"P=p003,L=1,M=multipart/mixed | P=p001,L=1/1,M=text/html,T=html"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) check_for_banned
(p003,p002) multipart/mixed | application/msword,.dat,attachments 54972.doc Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) doing banned check for userxxx at noa.gr on multipart/mixed | application/msword,.dat,attachments
54972.doc
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup_re(["multipart/mixed","application/msword",".dat","attachments
54972.doc"]), no matches
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [check_bann:userxxx at noa.gr] => undef, ["multipart/mixed","application/msword",".dat","attachments 54972.doc"] does not match Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [banned_namepath_re] => undef, "P=p003\tL=1\tM=multipart/mixed\nP=p002\tL=1/2\tM=application/msword\tT=dat\tN=attachments
54972.doc" does not match
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) p.path userxxx at noa.gr: 
"P=p003,L=1,M=multipart/mixed |
P=p002,L=1/2,M=application/msword,T=dat,N=attachments 54972.doc"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) banned check: any=0, all=N (1) Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup_re("MAIL") matches key "(?-xism:^MAIL$)", result="1"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) lookup [keep_decoded_original] => true,  "MAIL" matches, result="1", matching_key="(?-xism:^MAIL$)"
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Issued a new file name: 
p004
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) presenting full original message to scanners as
/var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts/p004
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) Calling virus scanners,
3 files to scan in
/var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) invoking av-scanner ClamAV-clamd Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) ask_daemon: proto=DFLT, spawn=0, (ClamAV-clamd) /var/run/clamav/clamd.sock Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_av (ClamAV-clamd): 
query template(1,2): CONTSCAN {}\n
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline run_av_pre
- deadline in 479.9 s, set to 336.000 s
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
run_av_pre: timer 336, was 336, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline run_av_scan - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
run_av_scan: timer 336, was 336, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_av Using
(ClamAV-clamd): (code) CONTSCAN
/var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts\n
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline ask_daemon_internal_connect_pre - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline ask_daemon_internal_connect - deadline in 479.9 s, set to 10.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
ask_daemon_internal_connect: timer 10, was 336, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) ClamAV-clamd: 
Connecting to socket  /var/run/clamav/clamd.sock Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) new socket by IO::Socket::UNIX to /var/run/clamav/clamd.sock, timeout 10 Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) connected to /var/run/clamav/clamd.sock successfully Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) ClamAV-clamd: Sending CONTSCAN /var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts\n
to socket /var/run/clamav/clamd.sock
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: needline=0, flush=1, wr=1, timeout=10 Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: sending 69 chars Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop sent 69> CONTSCAN /var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts\n
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline ask_daemon_internal_scan - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
ask_daemon_internal_scan: timer 336, was 10, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: needline=0, flush=0, wr=0, timeout=335.994 Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: receiving Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop read 64 chars<
/var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts: OK\n Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: needline=0, flush=0, wr=0, timeout=335.994 Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: receiving Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop read: got eof Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline ask_daemon_internal - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
ask_daemon_internal: timer 336, was 336, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline run_av_3 - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer run_av_3: 
timer 336, was 336, deadline in 479.9 s
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_av (ClamAV-clamd)
result: /var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts: OK\n Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: needline=0, flush=0, wr=0, timeout=335.994 Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop: receiving Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) rw_loop read: got eof Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline ask_daemon_internal - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer
ask_daemon_internal: timer 336, was 336, deadline in 479.9 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) get_deadline run_av_3 - deadline in 479.9 s, set to 336.000 s Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) prolong_timer run_av_3: 
timer 336, was 336, deadline in 479.9 s
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_av (ClamAV-clamd)
result: /var/amavis/tmp/amavis-20201015T144232-03253-hA2kU9oE/parts: OK\n Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_av (ClamAV-clamd): 
CLEAN
Oct 15 14:43:44 mailgw3 amavis[3253]: (03253-10) run_av (ClamAV-clamd)
result: clean

======================================================================================================

Nick