I'm having problems with rar files and amavis. Amavis doesn't parse the content of these files for viruses, though it recognizes the file type. OTOH, ZIPped files are perfectly decompressed and scanned. I've run a couple of tests to illustrate.
0) First test is a ZIPped text file with the EICAR string, which amavis + clamav detect as a Virus. Here it is the log output.
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Checking: YJ7XfYPF4UU6 <email_address> -> <email_address>
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_virus_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Extracting mime components
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new file name: p001
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new file name: p002
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new pseudo part: p003
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p003 1 Content-Type: multipart/mixed
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Charging 143 bytes to remaining quota 764000 (out of 764000, (0%)) - by mime_decode
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p001 1/1 Content-Type: text/plain, size: 143 B, name:
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Charging 183 bytes to remaining quota 763857 (out of 764000, (0%)) - by mime_decode
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p002 1/2 Content-Type: application/octet-stream, size: 183 B, name: lala.zip
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decode_parts: level=1, #parts=3 : p001, p002, p003
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (map_full_type_to_short_type) => true, "ISO-8859 text" matches, result="txt", matching_key="(?i-xsm:^ISO-8859.*\\btext\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) File-type of p001: ISO-8859 text; (txt)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (map_full_type_to_short_type) => true, "Zip archive data, at least v1.0 to extract" matches, result="zip", matching_key="(?i-xsm:^Zip archive\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) File-type of p002: Zip archive data, at least v1.0 to extract; (zip)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decompose_part: p001 - atomic
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Unzipping p002
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new file name: p004
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Charging 69 bytes to remaining quota 763674 (out of 764000, (0%)) - by do_unzip
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (keep_decoded_original) => undef, "Zip archive data, at least v1.0 to extract" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decompose_part: p002 - archive, unpacked
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decode_parts: level=2, #parts=1 : p004
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (map_full_type_to_short_type) => true, "ASCII text, with no line terminators" matches, result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) File-type of p004: ASCII text, with no line terminators; (asc)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) do_ascii: Decoding part p004
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) do_ascii: Decoding part p004 (0 items), uulib V0.5pl20
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decompose_part: p004 - atomic
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Checking for banned types and filenames
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_banned_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (banned_filename), 1 matches for "email_address", results: "(constant:DEFAULT)"=>"DEFAULT"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) collect banned table[0]: email_address, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x8c720f4)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) starting banned checks - traversing message structure tree
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) check_for_banned (p003,p001) multipart/mixed | text/plain,.txt
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (check_bann:email_address) => undef, ["multipart/mixed","text/plain",".txt"] does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p001,L=1/1,M=text/plain,T=txt"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) check_for_banned (p003,p002,p004) multipart/mixed | application/octet-stream,.zip,lala.zip | .asc,lala.txt
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (check_bann:email_address) => false, ["multipart/mixed","application/octet-stream",".zip","lala.zip",".asc","lala.txt"] matches, result="0", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p002,L=1/2,M=application/octet-stream,T=zip,N=lala.zip | P=p004,L=1/2/1,T=asc,N=lala.txt", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) banned check: any=0, all=N (1)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (keep_decoded_original) => undef, "MAIL" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) files_to_scan: info: part p002 (zip) no longer present
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Using ClamAV-clamd: (built-in interface)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Using (ClamAV-clamd) on dir: CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts\n
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ClamAV-clamd: Connecting to socket /var/run/clamav/clamd.ctl
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ClamAV-clamd: Sending CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts\n to UNIX socket /var/run/clamav/clamd.ctl
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ask_av (ClamAV-clamd) result: /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts/p004: Eicar-Test-Signature FOUND\n
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ask_av (ClamAV-clamd): /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts INFECTED: Eicar-Test-Signature
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) virus_scan: (Eicar-Test-Signature), detected by 1 scanners: ClamAV-clamd
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_virus_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (viruses_that_fake_sender) => false, "Eicar-Test-Signature" matches, result="0", matching_key="(?i-xsm:\\bEICAR\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (spam_tag2_level) => true, "email_address" matches, result="4.6", matching_key="(constant:4.6)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (spam_tag3_level) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (spam_kill_level) => true, "email_address" matches, result="4.8", matching_key="(constant:4.8)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_spam_checks) => undef, "email_address" does not matchDec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (virus_lovers) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) do_notify_and_quarantine: ccat=Virus, (9,0)Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (virus_quarantine_to) => true, "email_address" matches, result="virus-quarantine", matching_key="(constant:virus-quarantine)"Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (virus_admin) => true, "email_address" matches, result="postmaster", matching_key="(constant:postmaster)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (newvirus_admin) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) local delivery: <email_address> -> <virus-quarantine>, mbx=/var/lib/amavis/virusmails/virus-YJ7XfYPF4UU6
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (local_domains) => true, "email_address" matches, result="1", matching_key=".viena.es"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup_ip_acl (publicnetworks): key="ip_address" matches "[::FFFF:0:0]/96", result=1
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) string_to_mime_entity: attaching original message headers
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) (about to connect to [127.0.0.1]:10025) SEND via SMTP: <> -> <postmaster>
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) AUTH not needed, user='', MTA offers 'LOGIN PLAIN'Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) response to RCPT TO for <postmaster>: "250 2.1.5 Ok"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) response to DATA: "354 End data with <CR><LF>.<CR><LF>"
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) response to data end: "250 2.0.0 Ok: queued as EBEC218C049"Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) SEND via SMTP: <> -> <postmaster>, ENVID=AM..20081230T112604Z@hostname 250 2.6.0 Ok, id=02034-02, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as EBEC218C049
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (warnvirusrecip) => undef, "email_address" does not match
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ndn_needed=, exit=99, 254 2.7.1 Ok, discarded, id=02034-02 - VIRUS: Eicar-Test-Signature
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup_ip_acl (publicnetworks): key="ip_address" matches "[::FFFF:0:0]/96", result=1
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Blocked INFECTED (Eicar-Test-Signature), [ip_address] <email_address> -> <email_address>, quarantine: virus-YJ7XfYPF4UU6, Message-ID: <007701c96a71$81a14b90$84e3e2b0$@es>, mail_id: YJ7XfYPF4UU6, Hits: -, 516 ms
1) The second test is the same EICAR file, but RARed. Again, the log:
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Checking: 1FeDdByUwYmV <email_address> -> <email_address>
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_virus_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Extracting mime components
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Issued a new file name: p001Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Issued a new file name: p002
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Issued a new pseudo part: p003
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p003 1 Content-Type: multipart/mixed
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 149 bytes to remaining quota 735000 (out of 735000, (0%)) - by mime_decode
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p001 1/1 Content-Type: text/plain, size: 149 B, name:Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 141 bytes to remaining quota 734851 (out of 735000, (0%)) - by mime_decodeDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p002 1/2 Content-Type: application/octet-stream, size: 141 B, name: lala.rarDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) decode_parts: level=1, #parts=3 : p001, p002, p003Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (map_full_type_to_short_type) => true, "ISO-8859 text" matches, result="txt", matching_key="(?i-xsm:^ISO-8859.*\\btext\\b)"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) File-type of p001: ISO-8859 text; (txt)Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (map_full_type_to_short_type) => true, "RAR archive data, v1d, os: Win32" matches, result="rar", matching_key="(?i-xsm:^RAR archive\\b)"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) File-type of p002: RAR archive data, v1d, os: Win32; (rar)Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) decompose_part: p001 - atomicDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Expanding RAR archive p002Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 69 bytes to remaining quota 734710 (out of 735000, (0%)) - by do_unrar-pre
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) flatten_and_tidy_dir: processing directory "/var/lib/amavis/tmp/amavis-20081230T122544-02035/parts/rar"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 0 bytes to remaining quota 734710 (out of 735000, (0%)) - by do_unrar
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (keep_decoded_original) => undef, "RAR archive data, v1d, os: Win32" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) decompose_part: p002 - archive, unpacked
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Checking for banned types and filenames
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_banned_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (banned_filename), 1 matches for "email_address", results: "(constant:DEFAULT)"=>"DEFAULT"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) collect banned table[0]: email_address, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x8c720f4)
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) starting banned checks - traversing message structure tree
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) check_for_banned (p003,p001) multipart/mixed | text/plain,.txt
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (check_bann:email_address) => undef, ["multipart/mixed","text/plain",".txt"] does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p001,L=1/1,M=text/plain,T=txt"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) check_for_banned (p003,p002) multipart/mixed | application/octet-stream,.rar,lala.rarDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (check_bann:email_address) => false, ["multipart/mixed","application/octet-stream",".rar","lala.rar"] matches, result="0", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p002,L=1/2,M=application/octet-stream,T=rar,N=lala.rar", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) banned check: any=0, all=N (1)
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (keep_decoded_original) => undef, "MAIL" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) files_to_scan: info: part p002 (rar) no longer presentDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Using ClamAV-clamd: (built-in interface)
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Using (ClamAV-clamd) on dir: CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts\n
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ClamAV-clamd: Connecting to socket /var/run/clamav/clamd.ctl
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ClamAV-clamd: Sending CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts\n to UNIX socket /var/run/clamav/clamd.ctl
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ask_av (ClamAV-clamd) result: /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts: OK\n
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ask_av (ClamAV-clamd): /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts CLEAN
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ClamAV-clamd result: clean
It seems that amavis is recognizing the file types but something happens with RAR files, and its content is not scanned. Any help or suggestion would be apreciated. Thanks for your help and sorry for my english.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I'm having problems with rar files and amavis. Amavis doesn't parse the content of these files for viruses, though it recognizes the file type. OTOH, ZIPped files are perfectly decompressed and scanned. I've run a couple of tests to illustrate.
0) First test is a ZIPped text file with the EICAR string, which amavis + clamav detect as a Virus. Here it is the log output.
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Checking: YJ7XfYPF4UU6 <email_address> -> <email_address>
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_virus_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Extracting mime components
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new file name: p001
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new file name: p002
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new pseudo part: p003
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p003 1 Content-Type: multipart/mixed
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Charging 143 bytes to remaining quota 764000 (out of 764000, (0%)) - by mime_decode
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p001 1/1 Content-Type: text/plain, size: 143 B, name:
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Charging 183 bytes to remaining quota 763857 (out of 764000, (0%)) - by mime_decode
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p002 1/2 Content-Type: application/octet-stream, size: 183 B, name: lala.zip
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decode_parts: level=1, #parts=3 : p001, p002, p003
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (map_full_type_to_short_type) => true, "ISO-8859 text" matches, result="txt", matching_key="(?i-xsm:^ISO-8859.*\\btext\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) File-type of p001: ISO-8859 text; (txt)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (map_full_type_to_short_type) => true, "Zip archive data, at least v1.0 to extract" matches, result="zip", matching_key="(?i-xsm:^Zip archive\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) File-type of p002: Zip archive data, at least v1.0 to extract; (zip)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decompose_part: p001 - atomic
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Unzipping p002
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Issued a new file name: p004
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Charging 69 bytes to remaining quota 763674 (out of 764000, (0%)) - by do_unzip
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (keep_decoded_original) => undef, "Zip archive data, at least v1.0 to extract" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decompose_part: p002 - archive, unpacked
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decode_parts: level=2, #parts=1 : p004
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (map_full_type_to_short_type) => true, "ASCII text, with no line terminators" matches, result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) File-type of p004: ASCII text, with no line terminators; (asc)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) do_ascii: Decoding part p004
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) do_ascii: Decoding part p004 (0 items), uulib V0.5pl20
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) decompose_part: p004 - atomic
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Checking for banned types and filenames
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_banned_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (banned_filename), 1 matches for "email_address", results: "(constant:DEFAULT)"=>"DEFAULT"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) collect banned table[0]: email_address, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x8c720f4)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) starting banned checks - traversing message structure tree
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) check_for_banned (p003,p001) multipart/mixed | text/plain,.txt
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (check_bann:email_address) => undef, ["multipart/mixed","text/plain",".txt"] does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p001,L=1/1,M=text/plain,T=txt"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) check_for_banned (p003,p002,p004) multipart/mixed | application/octet-stream,.zip,lala.zip | .asc,lala.txt
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (check_bann:email_address) => false, ["multipart/mixed","application/octet-stream",".zip","lala.zip",".asc","lala.txt"] matches, result="0", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p002,L=1/2,M=application/octet-stream,T=zip,N=lala.zip | P=p004,L=1/2/1,T=asc,N=lala.txt", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) banned check: any=0, all=N (1)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (keep_decoded_original) => undef, "MAIL" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) files_to_scan: info: part p002 (zip) no longer present
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Using ClamAV-clamd: (built-in interface)
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Using (ClamAV-clamd) on dir: CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts\n
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ClamAV-clamd: Connecting to socket /var/run/clamav/clamd.ctl
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ClamAV-clamd: Sending CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts\n to UNIX socket /var/run/clamav/clamd.ctl
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ask_av (ClamAV-clamd) result: /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts/p004: Eicar-Test-Signature FOUND\n
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ask_av (ClamAV-clamd): /var/lib/amavis/tmp/amavis-20081230T122515-02034/parts INFECTED: Eicar-Test-Signature
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) virus_scan: (Eicar-Test-Signature), detected by 1 scanners: ClamAV-clamd
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_virus_checks) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (viruses_that_fake_sender) => false, "Eicar-Test-Signature" matches, result="0", matching_key="(?i-xsm:\\bEICAR\\b)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (spam_tag2_level) => true, "email_address" matches, result="4.6", matching_key="(constant:4.6)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (spam_tag3_level) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (spam_kill_level) => true, "email_address" matches, result="4.8", matching_key="(constant:4.8)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (bypass_spam_checks) => undef, "email_address" does not matchDec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (virus_lovers) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) do_notify_and_quarantine: ccat=Virus, (9,0)Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (virus_quarantine_to) => true, "email_address" matches, result="virus-quarantine", matching_key="(constant:virus-quarantine)"Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (virus_admin) => true, "email_address" matches, result="postmaster", matching_key="(constant:postmaster)"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (newvirus_admin) => undef, "email_address" does not match
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) local delivery: <email_address> -> <virus-quarantine>, mbx=/var/lib/amavis/virusmails/virus-YJ7XfYPF4UU6
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (local_domains) => true, "email_address" matches, result="1", matching_key=".viena.es"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup_ip_acl (publicnetworks): key="ip_address" matches "[::FFFF:0:0]/96", result=1
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) string_to_mime_entity: attaching original message headers
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) (about to connect to [127.0.0.1]:10025) SEND via SMTP: <> -> <postmaster>
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) AUTH not needed, user='', MTA offers 'LOGIN PLAIN'Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) response to RCPT TO for <postmaster>: "250 2.1.5 Ok"
Dec 30 12:26:04 hostname /usr/sbin/amavisd-new[2034]: (02034-02) response to DATA: "354 End data with <CR><LF>.<CR><LF>"
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) response to data end: "250 2.0.0 Ok: queued as EBEC218C049"Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) SEND via SMTP: <> -> <postmaster>, ENVID=AM..20081230T112604Z@hostname 250 2.6.0 Ok, id=02034-02, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as EBEC218C049
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup (warnvirusrecip) => undef, "email_address" does not match
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) ndn_needed=, exit=99, 254 2.7.1 Ok, discarded, id=02034-02 - VIRUS: Eicar-Test-Signature
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) lookup_ip_acl (publicnetworks): key="ip_address" matches "[::FFFF:0:0]/96", result=1
Dec 30 12:26:05 hostname /usr/sbin/amavisd-new[2034]: (02034-02) Blocked INFECTED (Eicar-Test-Signature), [ip_address] <email_address> -> <email_address>, quarantine: virus-YJ7XfYPF4UU6, Message-ID: <007701c96a71$81a14b90$84e3e2b0$@es>, mail_id: YJ7XfYPF4UU6, Hits: -, 516 ms
1) The second test is the same EICAR file, but RARed. Again, the log:
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Checking: 1FeDdByUwYmV <email_address> -> <email_address>
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_virus_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Extracting mime components
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Issued a new file name: p001Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Issued a new file name: p002
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Issued a new pseudo part: p003
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p003 1 Content-Type: multipart/mixed
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 149 bytes to remaining quota 735000 (out of 735000, (0%)) - by mime_decode
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p001 1/1 Content-Type: text/plain, size: 149 B, name:Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 141 bytes to remaining quota 734851 (out of 735000, (0%)) - by mime_decodeDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p002 1/2 Content-Type: application/octet-stream, size: 141 B, name: lala.rarDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) decode_parts: level=1, #parts=3 : p001, p002, p003Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (map_full_type_to_short_type) => true, "ISO-8859 text" matches, result="txt", matching_key="(?i-xsm:^ISO-8859.*\\btext\\b)"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) File-type of p001: ISO-8859 text; (txt)Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (map_full_type_to_short_type) => true, "RAR archive data, v1d, os: Win32" matches, result="rar", matching_key="(?i-xsm:^RAR archive\\b)"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) File-type of p002: RAR archive data, v1d, os: Win32; (rar)Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) decompose_part: p001 - atomicDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Expanding RAR archive p002Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 69 bytes to remaining quota 734710 (out of 735000, (0%)) - by do_unrar-pre
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) flatten_and_tidy_dir: processing directory "/var/lib/amavis/tmp/amavis-20081230T122544-02035/parts/rar"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Charging 0 bytes to remaining quota 734710 (out of 735000, (0%)) - by do_unrar
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (keep_decoded_original) => undef, "RAR archive data, v1d, os: Win32" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) decompose_part: p002 - archive, unpacked
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_header_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Checking for banned types and filenames
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (bypass_banned_checks) => undef, "email_address" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (banned_filename), 1 matches for "email_address", results: "(constant:DEFAULT)"=>"DEFAULT"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) collect banned table[0]: email_address, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x8c720f4)
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) starting banned checks - traversing message structure tree
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) check_for_banned (p003,p001) multipart/mixed | text/plain,.txt
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (check_bann:email_address) => undef, ["multipart/mixed","text/plain",".txt"] does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p001,L=1/1,M=text/plain,T=txt"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) check_for_banned (p003,p002) multipart/mixed | application/octet-stream,.rar,lala.rarDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (check_bann:email_address) => false, ["multipart/mixed","application/octet-stream",".rar","lala.rar"] matches, result="0", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) p.path email_address: "P=p003,L=1,M=multipart/mixed | P=p002,L=1/2,M=application/octet-stream,T=rar,N=lala.rar", matching_key="(?-xism:^\\.(zip|rar|arc|arj|zoo)$)"
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) banned check: any=0, all=N (1)
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) lookup (keep_decoded_original) => undef, "MAIL" does not match
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) files_to_scan: info: part p002 (rar) no longer presentDec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Using ClamAV-clamd: (built-in interface)
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) Using (ClamAV-clamd) on dir: CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts\n
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ClamAV-clamd: Connecting to socket /var/run/clamav/clamd.ctl
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ClamAV-clamd: Sending CONTSCAN /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts\n to UNIX socket /var/run/clamav/clamd.ctl
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ask_av (ClamAV-clamd) result: /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts: OK\n
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ask_av (ClamAV-clamd): /var/lib/amavis/tmp/amavis-20081230T122544-02035/parts CLEAN
Dec 30 12:27:12 hostname /usr/sbin/amavisd-new[2035]: (02035-02) ClamAV-clamd result: clean
It seems that amavis is recognizing the file types but something happens with RAR files, and its content is not scanned. Any help or suggestion would be apreciated. Thanks for your help and sorry for my english.