(a bit more info) It seems do_unrar isn't being called at all for .rar
files. Using standard unrar switches from amavisd, I get the following:
# unrar v -c- -p- -idcdp virus.rar
Archive virus.rar
Pathname/Comment
Size Packed Ratio Date Time Attr CRC
Meth Ver
-------------------------------------------------------------------------------
Invoice_86612331.doc.exe
70656 64539 91% 20-10-08 16:20 .....A. CAAF5477
m3b 2.9
-------------------------------------------------------------------------------
1 70656 64539 91%
I should be seeing do_unrar being called if I send a message with this
attached (and unrar is found during amavisd startup), but my logs don't
show any sort of logging from do_unrar (I should see something at
loglevel 4 from:
ll(4) && do_log(4, "Expanding RAR archive %s", $part->base_name);
Thoughts on what is going on here? Banned filenames in other archive
formats are getting caught fine.
This is amavisd-new-2.6.1 (20080629).
jonathan wrote:
> It seems that amavisd isn't properly looking inside of "rar" attachments
> in our configuration. The unrar binary is detected on startup as the
> application to deal with rar archives, but nothing is (seemingly) done
> with these archives when a message passes through the system.
>
> I can successfully unrar stuff using the binary on the command line
> (unrar e <filename>), and other archive utilities seem to be working
> well. Problem seems to occur with numerous versions of amavisd-new
> (2.3.2, 2.5.2, 2.6.1).
>
> Thoughts on what I should be looking at here? Any help greatly appreciated.
>
> Log snippit from message containing test.rar (which contains a (banned)
> .exe file):
>
> Oct 23 13:31:23 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> p002 1/2 Content-Type: application/octet-stream, size: 64622 B, name:
> test.rar
> Oct 23 13:31:23 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> reparenting p002 from p000 to p003
> Oct 23 13:31:23 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> prolong_timer mime_decode: remaining time = 480 s
> Oct 23 13:31:23 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> prolong_timer mime_decode-1: remaining time = 480 s
> Oct 23 13:31:23 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> decode_parts: level=1, #parts=3 : p001, p002, p003
> Oct 23 13:31:23 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> running file(1) on 2 files, arglist size 23
> Oct 23 13:31:24 iscan1 amavis[22336]: [ID 702911 local1.info] (22296-01)
> open_on_specific_fd: target fd0 closing, to become < /dev/null
> Oct 23 13:31:24 iscan1 amavis[22336]: [ID 702911 local1.info] (22296-01)
> open_on_specific_fd: target fd2 closing, to become > &1
> Oct 23 13:31:24 iscan1 amavis[22336]: [ID 702911 local1.info] (22296-01)
> open_on_specific_fd: target fd2 dup2 from fd1 > &1
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> run_command: [22336] /usr/bin/file p001 p002 </dev/null 2>&1
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> result line from file(1): p001:\t\tascii text
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup_re("ascii text") matches key "(?i-xsm:^(ASCII|text)\b)", result="asc"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (map_full_type_to_short_type) => true, "ascii text" matches,
> result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> File-type of p001: ascii text; (asc)
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> result line from file(1): p002:\t\tdata
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup_re("data") matches key "(?-xism:^dataz)", result="dat"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (map_full_type_to_short_type) => true, "data" matches,
> result="dat", matching_key="(?-xism:^data\\z)"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> File-type of p002: data; (dat)
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> do_ascii: Decoding part p001
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> do_ascii: Setting sigaction handler, was 0
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> timer set to 320 s (was 480 s)
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> do_ascii: Decoding part p001 (0 items), uulib V0.5pl20
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> prolong_timer do_ascii: timer set to 480 s
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> decompose_part: p001 - atomic
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> decompose_part: p002 - atomic
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> prolong_timer parts_decode: remaining time = 480 s
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> query_keys: [EMAIL PROTECTED], jengbrec@, -----.ca, -----.ca, -----.ca,
> .ca, .
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup_hash([EMAIL PROTECTED]), no matches
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (bypass_header_checks) => undef, "[EMAIL PROTECTED]" does not match
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> check_header: 0, OK
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> query_keys: [EMAIL PROTECTED], jengbrec@, -----.ca, .-----.ca,
> .ryerson.ca, .ca, .
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup_hash([EMAIL PROTECTED]), no matches
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (bypass_header_checks) => undef, "[EMAIL PROTECTED]" does not match
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> Checking for banned types and filenames
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup: (scalar) matches, result="DEFAULT"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (banned_filename), 1 matches for "[EMAIL PROTECTED]", results:
> "(constant:DEFAULT)"=>"DEFAULT"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> collect banned table[0]: [EMAIL PROTECTED], tables:
> DEFAULT=>Amavis::Lookup::RE=ARRAY(0xd910dc)
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> starting banned checks - traversing message structure tree
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> check_for_banned (p003,p001) multipart/mixed | text/plain,.asc
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> doing banned check for [EMAIL PROTECTED] on multipart/mixed |
> text/plain,.asc
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup_re(["multipart/mixed","text/plain",".asc"]), no matches
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (check_bann:[EMAIL PROTECTED]) => undef,
> ["multipart/mixed","text/plain",".asc"] does not match
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> p.path [EMAIL PROTECTED]: "P=p003,L=1,M=multipart/mixed |
> P=p001,L=1/1,M=text/plain,T=asc"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> check_for_banned (p003,p002) multipart/mixed |
> application/octet-stream,.dat,test.rar
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> doing banned check for [EMAIL PROTECTED] on multipart/mixed |
> application/octet-stream,.dat,test.rar
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup_re(["multipart/mixed","application/octet-stream",".dat","test.rar"]),
> no matches
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> lookup (check_bann:[EMAIL PROTECTED]) => undef,
> ["multipart/mixed","application/octet-stream",".dat","test.rar"] does
> not match
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> p.path [EMAIL PROTECTED]: "P=p003,L=1,M=multipart/mixed |
> P=p002,L=1/2,M=application/octet-stream,T=dat,N=test.rar"
> Oct 23 13:31:24 iscan1 amavis[22296]: [ID 702911 local1.info] (22296-01)
> banned check: any=0, all=N (1)
>
> -------------------------------------------------------------------------
> This SF.Net email is sponsored by the Moblin Your Move Developer's challenge
> Build the coolest Linux based applications with Moblin SDK & win great prizes
> Grand prize is a trip for two to an Open Source event anywhere in the world
> http://moblin-contest.org/redirect.php?banner_id=100&url=/
> _______________________________________________
> AMaViS-user mailing list
> [email protected]
> https://lists.sourceforge.net/lists/listinfo/amavis-user
> AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3
> AMaViS-HowTos:http://www.amavis.org/howto/
>
-------------------------------------------------------------------------
This SF.Net email is sponsored by the Moblin Your Move Developer's challenge
Build the coolest Linux based applications with Moblin SDK & win great prizes
Grand prize is a trip for two to an Open Source event anywhere in the world
http://moblin-contest.org/redirect.php?banner_id=100&url=/
_______________________________________________
AMaViS-user mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/amavis-user
AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3
AMaViS-HowTos:http://www.amavis.org/howto/
