Jun 1 19:44:48 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: Net::Server: Child Preforked (634) Jun 1 19:44:48 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: BerkeleyDB-based Amavis::Cache not available, using memory-based local cache Jun 1 19:44:48 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: storage and lookups will use the same connection to SQL Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: Net::Server: 2009/06/01-19:44:52 CONNECT TCP Peer: "127.0.0.1:60679" Local: "127.0.0.1:10024" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: loaded base policy bank Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: loaded policy bank "STRIKE" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: lookup_ip_acl (inet_acl): key="127.0.0.1" matches "127.0.0.0/8", result=1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: process_request: fileno sock=13, STDIN=0, STDOUT=1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: switch_to_my_time 90 s, new request Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: process_request: suggested_protocol="" on TCP Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, smtp response sent Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 4: was busy, 3.8 ms, total idle 0.000 s, busy 0.004 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.000 s, busy 0.004 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) SMTP< EHLO strike.wu.ac.at\r\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_my_time 90 s, SMTP EHLO received Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-[127.0.0.1] Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-VRFY Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-PIPELINING Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-SIZE Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-ENHANCEDSTATUSCODES Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-8BITMIME Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250-DSN Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250 XFORWARD NAME ADDR PROTO HELO Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, smtp response sent Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 6: was busy, 1.2 ms, total idle 0.000 s, busy 0.005 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.000 s, busy 0.005 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP< XFORWARD NAME=monty.wu-wien.ac.at ADDR=137.208.16.200 HELO=monty.wu-wien.ac.at PROTO=ESMTP\r\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_my_time 90 s, SMTP XFORWARD received Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250 2.5.0 Ok XFORWARD Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, smtp response sent Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 6: was busy, 0.6 ms, total idle 0.000 s, busy 0.006 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.000 s, busy 0.006 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP< MAIL FROM: SIZE=38909\r\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_my_time 90 s, SMTP MAIL received Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) check_mail_begin_task: task_count=1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) TempDir::prepare: creating directory /var/spool/amavisd/tmp/amavis-20090601T194452-00634 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) TempDir::prepare_file: creating file /var/spool/amavisd/tmp/amavis-20090601T194452-00634/email.txt Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) TempDir::prepare_file: layers: unix,perlio Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_ip_acl (mynetworks): key="137.208.16.200" matches "137.208.0.0/16", result=1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) loaded policy bank "MYNETS" over "STRIKE" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (debug_sender) => undef, "miraclest44@maxintegration.com" does not match Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250 2.1.0 Sender OK Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, smtp response sent Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 6: was busy, 2.6 ms, total idle 0.000 s, busy 0.008 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.008 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP< RCPT TO: ORCPT=rfc822;nadezda@nowhere.at\r\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_my_time 90 s, SMTP RCPT received Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_acl(nadezda@nowhere.at) matches key ".nowhere.at", result=1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (local_domains) => true, "nadezda@nowhere.at" matches, result="1", matching_key=".nowhere.at" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) query_keys: nadezda@nowhere.at, nadezda, @nowhere.at, @.nowhere.at, @.at, @. Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql "nadezda@nowhere.at", query args: "nadezda@nowhere.at", "nadezda", "@nowhere.at", "@.nowhere.at", "@.at", "@." Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql select: SELECT *, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql begin, nontransaction Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Connecting to SQL database server Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) connect_to_sql: trying 'DBI:mysql:database=amavis;host=127.0.0.1' Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) connect_to_sql: 'DBI:mysql:database=amavis;host=127.0.0.1' succeeded Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql: preparing and executing: SELECT *, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql, "nadezda@nowhere.at" no match Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql_field(message_size_limit), "nadezda@nowhere.at" no matching records Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (message_size_limit) => undef, "nadezda@nowhere.at" does not match Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 250 2.1.5 Recipient OK Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, smtp response sent Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 6: was busy, 4.2 ms, total idle 0.001 s, busy 0.012 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.012 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP< DATA\r\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_my_time 90 s, SMTP DATA received Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP:[127.0.0.1]:10024 /var/spool/amavisd/tmp/amavis-20090601T194452-00634: -> SIZE=38909 Received: from strike.wu.ac.at ([127.0.0.1]) by localhost (strike.wu-wien.ac.at [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for ; Mon, 1 Jun 2009 19:44:52 +0200 (CEST) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP> 354 End data with . Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, smtp response sent Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_client_time 1200 s, receiving data Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) switch_to_my_time 90 s, data-end received Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) ESMTP< . Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Actual message size 39093 B greater than the declared 38909 B Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql_field(local), "nadezda@nowhere.at" no matching records Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_acl(nadezda@nowhere.at) matches key ".nowhere.at", result=1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (local_domains) => true, "nadezda@nowhere.at" matches, result="1", matching_key=".nowhere.at" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) body type: unlabeled, good (h=0, b=0) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) body hash: 0978fe1dcdd012e53d53d7be1849a1d0 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Original mail size: 39093; quota set to: 19546500 bytes Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql begin, nontransaction Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql: preparing and executing: SELECT id FROM maddr WHERE email=? Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) save_info_preliminary: 1190947, miraclest44@maxintegration.com, exists Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql begin, nontransaction Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql: executing clause: SELECT id FROM maddr WHERE email=? Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) save_info_preliminary 3Q8B2U1KDrvN, recip id: 56, nadezda@nowhere.at, exists Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql begin transaction Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql: preparing and executing: INSERT INTO msgs (mail_id, secret_id, am_id, time_num, time_iso, sid, policy, client_addr, size, host) VALUES (?,?,?,?,?,?,?,?,?,?) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) sql commit Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Checking: 3Q8B2U1KDrvN STRIKE/MYNETS [137.208.16.200] -> Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) 2822.From: Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql_field(bypass_virus_checks), "nadezda@nowhere.at" no matching records Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) query_keys: nadezda@nowhere.at, nadezda@, nowhere.at, .nowhere.at, .at, . Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_hash(nadezda@nowhere.at), no matches Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (bypass_virus_checks) => undef, "nadezda@nowhere.at" does not match Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Extracting mime components Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Issued a new file name: p001 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Issued a new file name: p002 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) mime_decode_preamble: 2 lines Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Issued a new pseudo part: p003 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) p003 1 Content-Type: multipart/mixed Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Charging 461 bytes to remaining quota 19546500 (out of 19546500, (0%)) - by mime_decode Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) p001 1/1 Content-Type: text/plain, size: 461 B, name: Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) reparenting p001 from p000 to p003 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Charging 27154 bytes to remaining quota 19546039 (out of 19546500, (0%)) - by mime_decode Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) p002 1/2 Content-Type: application/zip, size: 27154 B, name: ecard.zip Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) reparenting p002 from p000 to p003 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer mime_decode: remaining time = 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer mime_decode-1: remaining time = 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) decode_parts: level=1, #parts=3 : p001, p002, p003 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) run_command: [642] /usr/bin/file p001 p002 &1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) result line from file(1): p001: ASCII English text\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_re("ASCII English text") matches key "(?i-xsm:^(ASCII|text)\b)", result="asc" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (map_full_type_to_short_type) => true, "ASCII English text" matches, result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) File-type of p001: ASCII English text; (asc) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) result line from file(1): p002: Zip archive data, at least v2.0 to extract\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_re("Zip archive data, at least v2.0 to extract") matches key "(?i-xsm:^Zip archive\b)", result="zip" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (map_full_type_to_short_type) => true, "Zip archive data, at least v2.0 to extract" matches, result="zip", matching_key="(?i-xsm:^Zip archive\\b)" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) File-type of p002: Zip archive data, at least v2.0 to extract; (zip) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_ascii: Decoding part p001 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_ascii: Setting sigaction handler, was 0 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) timer set to 60 s (was 90 s) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_ascii: Decoding part p001 (0 items), uulib V0.5pl20 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer do_ascii: timer set to 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) decompose_part: p001 - atomic Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Unzipping p002 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Issued a new file name: p004 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Charging 32768 bytes to remaining quota 19518885 (out of 19546500, (0%)) - by do_unzip Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_re("Zip archive data, at least v2.0 to extract"), no matches Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (keep_decoded_original) => undef, "Zip archive data, at least v2.0 to extract" does not match Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) decompose_part: deleting /var/spool/amavisd/tmp/amavis-20090601T194452-00634/parts/p002 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) decompose_part: p002 - archive, unpacked Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) decode_parts: level=2, #parts=1 : p004 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) run_command: [643] /usr/bin/file p004 &1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) result line from file(1): p004: PE32 executable for MS Windows (GUI) Intel 80386 32-bit\n Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_re("PE32 executable for MS Windows (GUI) Intel 80386 32-bit") matches key "(?-xism:\bexecutable for MS Windows\b)", result=["exe","exe-ms"] Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (map_full_type_to_short_type) => true, "PE32 executable for MS Windows (GUI) Intel 80386 32-bit" matches, result=["exe","exe-ms"], matching_key="(?-xism:\\bexecutable for MS Windows\\b)" Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) File-type of p004: PE32 executable for MS Windows (GUI) Intel 80386 32-bit; (exe, exe-ms) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Check whether p004 is a self-extracting archive Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Unzipping p004 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_unzip: ok, exe is not a zip sfx: AZ_FORMAT_ERROR (3) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Expanding RAR archive p004 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) timer set to 60 s (was 90 s) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) run_command: [645] /usr/bin/rar v -c- -p- -av- -idcdp -- /var/spool/amavisd/tmp/amavis-20090601T194452-00634/parts/p004 &1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer do_unrar: timer set to 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_executable: not a RAR sfx, ignoring: do_unrar: /var/spool/amavisd/tmp/amavis-20090601T194452-00634/parts/p004 is not RAR archive at (eval 89) line 834. at (eval 89) line 877. Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Expanding LHA archive p004 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) timer set to 60 s (was 90 s) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) run_command: [646] /usr/bin/lha lq /var/spool/amavisd/tmp/amavis-20090601T194452-00634/parts/p004.exe &1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_lha: skip: [unknown] 16776960 0.0% Nov 30 1979 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer do_lha: timer set to 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_executable: not a LHA sfx, ignoring: do_lha: (LHa: Warning: Checksum error (LHarc file?) Inappropriate ioctl for device, LHa: Fatal error: Unknown level header: Inappropriate ioctl for device) exit 1 at (eval 89) line 920. at (eval 89) line 933. Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) Expanding ARJ archive p004 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) timer set to 60 s (was 90 s) Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) run_command: [655] /usr/bin/arj l /var/spool/amavisd/tmp/amavis-20090601T194452-00634/parts/p004.arj &1 Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer do_unarj: timer set to 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) do_executable: not an ARJ sfx, ignoring: do_unarj: not an ARJ archive? exit 9 at (eval 89) line 1092. at (eval 89) line 1154. Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) decompose_part: p004 - atomic Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) prolong_timer parts_decode: remaining time = 90 s Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_sql_field(bypass_header_checks), "nadezda@nowhere.at" no matching records Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) query_keys: nadezda@nowhere.at, nadezda@, nowhere.at, .nowhere.at, .at, . Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup_hash(nadezda@nowhere.at), no matches Jun 1 19:44:52 strike.wu-wien.ac.at /usr/sbin/amavisd[634]: (00634-01) lookup (bypass_header_checks) => undef, "nadezda@nowhere.at" does not match