Thanks Adreas
On 10-09-2014 13:23, A. Schulze wrote:
Joerg Rohrer:
Any ideas were i could start debugging?
set $log_level = 5;
if impossible ( too much log ) try @debug_sender_maps or
@debug_recipient_maps
Andreas
Below the relevant part.
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) Extracting mime
components from a string
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) Issued a new file name:
p001
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) Charging 4518 bytes to
remaining quota 2751500 (out of 2751500, (0%)) - by mime_decode
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) p001 1 Content-Type:
text/plain, size: 4518 B, name:
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) get_deadline mime_decode
- deadline in 480.0 s, set to 336.000 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) prolong_timer
mime_decode: timer 336, was 336, deadline in 480.0 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) get_deadline
mime_decode-1 - deadline in 480.0 s, set to 336.000 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) prolong_timer
mime_decode-1: timer 336, was 336, deadline in 480.0 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) decode_parts: level=1,
#parts=1 : p001
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) running file(1) on 1
files, arglist size 18
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) run_command: [8841]
/usr/bin/file p001 </dev/null 2>&1
Sep 10 15:21:00 alpha amavis[8841]: (08825-01) open_on_specific_fd:
target fd0 closing, to become < /dev/null
Sep 10 15:21:00 alpha amavis[8841]: (08825-01) open_on_specific_fd:
target fd1 closing, to become (65) &=15
Sep 10 15:21:00 alpha amavis[8841]: (08825-01) open_on_specific_fd:
target fd1 dup2 from fd15 (65) &=15
Sep 10 15:21:00 alpha amavis[8841]: (08825-01) open_on_specific_fd:
source fd15 closed
Sep 10 15:21:00 alpha amavis[8841]: (08825-01) open_on_specific_fd:
target fd2 closing, to become (65) &1
Sep 10 15:21:00 alpha amavis[8841]: (08825-01) open_on_specific_fd:
target fd2 dup2 from fd1 (65) &1
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) result line from file(1):
p001: Python script, UTF-8 Unicode text executable\n
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) lookup_re("Python script,
UTF-8 Unicode text executable") matches key "(?^i:\bexecutable\b)",
result="exe"
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) lookup
[map_full_type_to_short_type] => true, "Python script, UTF-8 Unicode
text executable" matches, result="exe",
matching_key="(?^i:\134bexecutable\134b)"
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) File-type of p001: Python
script, UTF-8 Unicode text executable; (exe)
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) Check whether p001 is a
self-extracting archive
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) Unzipping p001
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) do_unzip: ok, exe is not
a zip sfx: AZ_FORMAT_ERROR (3)
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) Expanding RAR archive
p001
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) get_deadline do_unrar_pre
- deadline in 479.9 s, set to 336.000 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) prolong_timer
do_unrar_pre: timer 336, was 336, deadline in 479.9 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) run_command: [8842]
/usr/bin/unrar v -c- -p- -idcdp --
/mnt/amavis/amavis-20140910T152100-08825-y8EH73zE/parts/p001 </dev/null
2>&1
Sep 10 15:21:00 alpha amavis[8842]: (08825-01) open_on_specific_fd:
target fd0 closing, to become < /dev/null
Sep 10 15:21:00 alpha amavis[8842]: (08825-01) open_on_specific_fd:
target fd1 closing, to become (65) &=15
Sep 10 15:21:00 alpha amavis[8842]: (08825-01) open_on_specific_fd:
target fd1 dup2 from fd15 (65) &=15
Sep 10 15:21:00 alpha amavis[8842]: (08825-01) open_on_specific_fd:
source fd15 closed
Sep 10 15:21:00 alpha amavis[8842]: (08825-01) open_on_specific_fd:
target fd2 closing, to become (65) &1
Sep 10 15:21:00 alpha amavis[8842]: (08825-01) open_on_specific_fd:
target fd2 dup2 from fd1 (65) &1
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) get_deadline do_unrar -
deadline in 479.9 s, set to 336.000 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) prolong_timer do_unrar:
timer 336, was 336, deadline in 479.9 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) do_executable: not a RAR
sfx, ignoring: do_unrar:
/mnt/amavis/amavis-20140910T152100-08825-y8EH73zE/parts/p001 is not RAR
archive at (eval 147) line 901.
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) do_executable: not an ARJ
sfx, ignoring: do_unrar:
/mnt/amavis/amavis-20140910T152100-08825-y8EH73zE/parts/p001 is not RAR
archive at (eval 147) line 901.
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) decompose_part: p001 -
atomic
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) get_deadline parts_decode
- deadline in 479.9 s, set to 336.000 s
Sep 10 15:21:00 alpha amavis[8825]: (08825-01) prolong_timer
parts_decode: timer 336, was 336, deadline in 479.9 s
Regards
Jörg
