<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body text="#000000" bgcolor="#FFFFFF">
<font size="-1">I will just post the debug this way and hope it gets
through.<br>
-------------------------------------------------------------------------------------------------<br>
Jan 30 10:07:18.391 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: Net::Server: 2018/01/30-10:07:18
CONNECT TCP Peer: "[127.0.0.1]:49220" Local: "[127.0.0.1]:10024"<br>
Jan 30 10:07:18.392 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: loaded base policy bank<br>
Jan 30 10:07:18.393 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: lookup_ip_acl (inet_acl) arr.obj:
key="127.0.0.1" matches "127.0.0.1", result=1<br>
Jan 30 10:07:18.393 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: process_request: fileno sock=12,
STDIN=0, STDOUT=1<br>
Jan 30 10:07:18.394 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: get_deadline switch_to_my_time(new
request) - deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.394 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: prolong_timer switch_to_my_time(new
request): timer 288, was 0, deadline in 480.0 s<br>
Jan 30 10:07:18.395 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: process_request:
suggested_protocol="" on a TCP socket<br>
Jan 30 10:07:18.396 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) SMTP> 220 [127.0.0.1]
ESMTP amavisd-new service ready<br>
Jan 30 10:07:18.396 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:18.396 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 4: was busy,
5.5 ms, total idle 0.000 s, busy 0.005 s<br>
Jan 30 10:07:18.397 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp readline: read 42
bytes, new size: 42<br>
Jan 30 10:07:18.397 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 5: was idle,
0.4 ms, total idle 0.000 s, busy 0.005 s<br>
Jan 30 10:07:18.397 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) SMTP< EHLO
M1-2.mymailserver.com\r\n<br>
Jan 30 10:07:18.397 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx SMTP EHLO) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:18.397 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx SMTP EHLO): timer 288, was 480, deadline in
480.0 s<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-[127.0.0.1]<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-VRFY<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-PIPELINING<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-SIZE<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP>
250-ENHANCEDSTATUSCODES<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-8BITMIME<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-SMTPUTF8<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250-DSN<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250 XFORWARD
NAME ADDR PORT PROTO HELO IDENT SOURCE<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:18.398 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 6: was busy,
1.7 ms, total idle 0.000 s, busy 0.007 s<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp readline: read 145
bytes, new size: 145<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 5: was idle,
0.3 ms, total idle 0.001 s, busy 0.007 s<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP< XFORWARD
SOURCE=LOCAL\r\n<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline
in 480.0 s<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250 2.5.0 Ok
XFORWARD<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 6: was busy,
0.6 ms, total idle 0.001 s, busy 0.008 s<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 5: was idle,
0.1 ms, total idle 0.001 s, busy 0.008 s<br>
Jan 30 10:07:18.399 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP< MAIL
FROM:<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> SIZE=40267
BODY=8BITMIME\r\n<br>
Jan 30 10:07:18.400 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx SMTP MAIL) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:18.400 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx SMTP MAIL): timer 288, was 480, deadline in
480.0 s<br>
Jan 30 10:07:18.400 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) check_mail_begin_task:
task_count=1<br>
Jan 30 10:07:18.401 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) TempDir::prepare_dir:
created directory
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0<br>
Jan 30 10:07:18.401 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) TempDir::prepare_file:
creating file
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/email.txt<br>
Jan 30 10:07:18.401 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) TempDir::prepare_file:
layers: unix,perlio<br>
Jan 30 10:07:18.402 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_ip_acl
(client_ipaddr_policy) arr.obj: key="0.0.0.0", no match<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [debug_sender]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com">"skinny.body@ciaobbweb.com"</a> does not match<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) mesage size set to a
declared size 40267<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250 2.1.0 Sender
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> OK<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 6: was busy,
3.8 ms, total idle 0.001 s, busy 0.012 s<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 5: was idle,
0.1 ms, total idle 0.001 s, busy 0.012 s<br>
Jan 30 10:07:18.403 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP< RCPT
TO:<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a> <a class="moz-txt-link-abbreviated" href="mailto:ORCPT=rfc822;bob1@myorg.org\r\n">ORCPT=rfc822;bob1@myorg.org\r\n</a><br>
Jan 30 10:07:18.404 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx SMTP RCPT) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:18.404 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx SMTP RCPT): timer 288, was 480, deadline in
480.0 s<br>
Jan 30 10:07:18.404 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup => undef,
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a>, no lookup tables<br>
Jan 30 10:07:18.404 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250 2.1.5
Recipient <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a> OK<br>
Jan 30 10:07:18.404 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:18.404 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 6: was busy,
1.1 ms, total idle 0.001 s, busy 0.013 s<br>
Jan 30 10:07:18.405 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 5: was idle,
0.1 ms, total idle 0.001 s, busy 0.013 s<br>
Jan 30 10:07:18.405 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP< DATA\r\n<br>
Jan 30 10:07:18.405 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx SMTP DATA) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:18.405 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx SMTP DATA): timer 288, was 480, deadline in
480.0 s<br>
Jan 30 10:07:18.406 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP :10024
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0:
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> -> <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>
SIZE=40267 BODY=8BITMIME Received: from M1-2.mymailserver.com
([127.0.0.1]) by localhost (m1-2.mymailserver.com [127.0.0.1])
(amavisd-new, port 10024) with ESMTP for <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>;
Tue, 30 Jan 2018 10:07:18 -0600 (CST)<br>
Jan 30 10:07:18.406 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 354 End data
with <CR><LF>.<CR><LF><br>
Jan 30 10:07:18.406 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:18.406 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, receiving data<br>
Jan 30 10:07:18.437 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp copy: read 40199
bytes into buffer, new size: 40199<br>
Jan 30 10:07:18.438 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp copy: 6 bytes still
buffered at end<br>
Jan 30 10:07:18.438 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx data-end) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:18.438 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx data-end): timer 288, was 480, deadline in
480.0 s<br>
Jan 30 10:07:18.438 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP<
.<CR><LF><br>
Jan 30 10:07:18.439 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Actual message size 40190
B less than the declared 40267 B<br>
Jan 30 10:07:18.439 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
get_body_digest - deadline in 480.0 s, set to 30.000 s<br>
Jan 30 10:07:18.439 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline digest_pre -
deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.439 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer digest_pre:
timer 288, was 288, deadline in 480.0 s<br>
Jan 30 10:07:18.441 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) DNS resolver created, UDP
payload size 1220, NS: 192.168.3.150, 192.168.3.150<br>
Jan 30 10:07:18.441 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_body_digest: reading
header section from memory<br>
Jan 30 10:07:18.442 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_body_digest: feeding
header section to DKIM verifier<br>
Jan 30 10:07:18.442 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_body_digest: sending
h/b separator to DKIM<br>
Jan 30 10:07:18.443 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline digest_hdr -
deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.443 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer digest_hdr:
timer 288, was 288, deadline in 480.0 s<br>
Jan 30 10:07:18.443 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_body_digest: reading
mail body from memory, 0 DKIM signatures<br>
Jan 30 10:07:18.443 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline digest_body -
deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.443 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer digest_body:
timer 288, was 288, deadline in 480.0 s<br>
Jan 30 10:07:18.444 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_body_digest: message
size 40190, header+sep 811, body 39379<br>
Jan 30 10:07:18.444 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) body type
(8bit-MIMEtransport): labeled 8BITMIME unnecessarily (h=0, b=0)<br>
Jan 30 10:07:18.444 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) body hash:
c93cd5e827ff040d3cfc2ac612a2c8f6<br>
Jan 30 10:07:18.445 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ip_from_received: no IP
address in: by M1-2.mymailserver.com (Postfix, from userid
1001)\n\tid 5CDF7604E0; Tue, 30 Jan 2018 10:07:18 -0600 (CST)\n<br>
Jan 30 10:07:18.446 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ip_from_received:
192.140.22.179<br>
Jan 30 10:07:18.447 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_ip_acl
(public_nets) arr.obj: key="127.0.0.1" matches "!127.0.0.0/8",
result=0<br>
Jan 30 10:07:18.447 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_ip_acl
(public_nets) arr.obj: key="192.140.22.179" matches
"::ffff:0:0/96", result=1<br>
Jan 30 10:07:18.447 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) trace:
ESMTP://[127.0.0.1]:49220 < x < ESMTPS://192.140.22.179<br>
Jan 30 10:07:18.448 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) client IP address unknown,
fetched from Received: 127.0.0.1<br>
Jan 30 10:07:18.448 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Original mail size: 40190;
quota set to: 20095000 bytes (fmin=5, fmax=500, qmin=102400,
qmax=314572800)<br>
Jan 30 10:07:18.449 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Checking: viK49HCkVsDs
[127.0.0.1] <a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> ->
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a><br>
Jan 30 10:07:18.449 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) 2822.From:
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a><br>
Jan 30 10:07:18.449 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_acl(<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>)
matches key "myorg.org", result=1<br>
Jan 30 10:07:18.449 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [local_domains]
=> true, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> matches, result="1",
matching_key="myorg.org"<br>
Jan 30 10:07:18.449 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[bypass_virus_checks] => undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:18.450 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[bypass_banned_checks] => undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not
match<br>
Jan 30 10:07:18.450 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[bypass_spam_checks] => undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:18.451 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Extracting mime components
from a string<br>
Jan 30 10:07:18.456 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Issued a new file name:
p001<br>
Jan 30 10:07:18.460 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Issued a new file name:
p002<br>
Jan 30 10:07:18.461 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Issued a new pseudo part:
p003<br>
Jan 30 10:07:18.461 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) p003 1 Content-Type:
multipart/alternative<br>
Jan 30 10:07:18.462 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Charging 904 bytes to
remaining quota 20095000 (out of 20095000, (0%)) - by mime_decode<br>
Jan 30 10:07:18.462 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) p001 1/1 Content-Type:
text/plain, size: 904 B, name:<br>
Jan 30 10:07:18.462 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) reparenting p001 from p000
to p003<br>
Jan 30 10:07:18.462 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Charging 37480 bytes to
remaining quota 20094096 (out of 20095000, (0%)) - by mime_decode<br>
Jan 30 10:07:18.463 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) p002 1/2 Content-Type:
text/html, size: 37480 B, name:<br>
Jan 30 10:07:18.463 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) reparenting p002 from p000
to p003<br>
Jan 30 10:07:18.463 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline mime_decode -
deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.463 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer mime_decode:
timer 288, was 288, deadline in 480.0 s<br>
Jan 30 10:07:18.464 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline mime_decode-1
- deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.464 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
mime_decode-1: timer 288, was 288, deadline in 480.0 s<br>
Jan 30 10:07:18.464 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) decode_parts: level=1,
#parts=3 : p001, p002, p003<br>
Jan 30 10:07:18.464 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) running file(1) on 2
files, arglist size 23<br>
Jan 30 10:07:18.467 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_command: [4594]
/usr/bin/file p001 p002 </dev/null 2>&1<br>
Jan 30 10:07:18.482 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) result line from file(1):
p001: ASCII text, with very long lines\n<br>
Jan 30 10:07:18.483 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_re("ASCII text,
with very long lines") matches key "(?^i:^(ASCII|text)\\b)",
result="asc"<br>
Jan 30 10:07:18.483 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[map_full_type_to_short_type] => true, "ASCII text, with very
long lines" matches, result="asc",
matching_key="(?^i:^(ASCII|text)\\b)"<br>
Jan 30 10:07:18.483 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) File-type of p001: ASCII
text, with very long lines; (asc)<br>
Jan 30 10:07:18.484 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) result line from file(1):
p002: HTML document, ASCII text, with very long lines\n<br>
Jan 30 10:07:18.484 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_re("HTML document,
ASCII text, with very long lines") matches key "(?^i:\\btext\\b)",
result="asc"<br>
Jan 30 10:07:18.484 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[map_full_type_to_short_type] => true, "HTML document, ASCII
text, with very long lines" matches, result="asc",
matching_key="(?^i:\\btext\\b)"<br>
Jan 30 10:07:18.484 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) File-type of p002: HTML
document, ASCII text, with very long lines; (asc)<br>
Jan 30 10:07:18.485 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) decompose_part: p001 -
atomic<br>
Jan 30 10:07:18.485 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) decompose_part: p002 -
atomic<br>
Jan 30 10:07:18.485 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline parts_decode
- deadline in 480.0 s, set to 288.000 s<br>
Jan 30 10:07:18.485 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
parts_decode: timer 288, was 288, deadline in 480.0 s<br>
Jan 30 10:07:18.486 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[bypass_header_checks] => undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not
match<br>
Jan 30 10:07:18.486 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) check_header: 0, OK<br>
Jan 30 10:07:18.486 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[bypass_header_checks] => undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not
match<br>
Jan 30 10:07:18.486 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Checking for banned types
and filenames<br>
Jan 30 10:07:18.486 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (scalar) matches,
result="DEFAULT"<br>
Jan 30 10:07:18.487 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [banned_filename],
1 matches for <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a>, results:
"(constant:DEFAULT)"=>"DEFAULT"<br>
Jan 30 10:07:18.487 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) collect banned table[0]:
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>, tables:
DEFAULT=>Amavis::Lookup::RE=ARRAY(0x9335e2c)<br>
Jan 30 10:07:18.487 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) starting banned checks -
traversing message structure tree<br>
Jan 30 10:07:18.487 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) check_for_banned
(p003,p001) multipart/alternative | text/plain,.asc<br>
Jan 30 10:07:18.487 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) doing banned check for
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a> on multipart/alternative | text/plain,.asc<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
lookup_re(["multipart/alternative","text/plain",".asc"]), no
matches<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[<a class="moz-txt-link-abbreviated" href="mailto:check_bann:bob1@myorg.org">check_bann:bob1@myorg.org</a>] => undef,
["multipart/alternative","text/plain",".asc"] does not match<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[banned_namepath_re] => undef,
"P=p003\tL=1\tM=multipart/alternative\nP=p001\tL=1/1\tM=text/plain\tT=asc"
does not match<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) p.path <a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>:
"P=p003,L=1,M=multipart/alternative |
P=p001,L=1/1,M=text/plain,T=asc"<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) check_for_banned
(p003,p002) multipart/alternative | text/html,.asc<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) doing banned check for
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a> on multipart/alternative | text/html,.asc<br>
Jan 30 10:07:18.488 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
lookup_re(["multipart/alternative","text/html",".asc"]), no
matches<br>
Jan 30 10:07:18.489 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[<a class="moz-txt-link-abbreviated" href="mailto:check_bann:bob1@myorg.org">check_bann:bob1@myorg.org</a>] => undef,
["multipart/alternative","text/html",".asc"] does not match<br>
Jan 30 10:07:18.489 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[banned_namepath_re] => undef,
"P=p003\tL=1\tM=multipart/alternative\nP=p002\tL=1/2\tM=text/html\tT=asc"
does not match<br>
Jan 30 10:07:18.489 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) p.path <a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>:
"P=p003,L=1,M=multipart/alternative |
P=p002,L=1/2,M=text/html,T=asc"<br>
Jan 30 10:07:18.489 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) banned check: any=0, all=N
(1)<br>
Jan 30 10:07:18.489 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup_re("MAIL"), no
matches<br>
Jan 30 10:07:18.489 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[keep_decoded_original] => undef, "MAIL" does not match<br>
Jan 30 10:07:18.490 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Calling virus scanners, 2
files to scan in
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts<br>
Jan 30 10:07:18.490 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) invoking av-scanner
ClamAV-clamd<br>
Jan 30 10:07:18.490 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ask_daemon: proto=DFLT,
spawn=0, (ClamAV-clamd) /var/run/clamav/clamd.ctl<br>
Jan 30 10:07:18.490 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (ClamAV-clamd):
query template(1,1): CONTSCAN {}\n<br>
Jan 30 10:07:18.490 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline run_av_pre -
deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.490 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer run_av_pre:
timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline run_av_scan -
deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer run_av_scan:
timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av Using
(ClamAV-clamd): (code) CONTSCAN
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts\n<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal_connect_pre - deadline in 479.9 s, set to
288.000 s<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal_connect - deadline in 479.9 s, set to 10.000 s<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
ask_daemon_internal_connect: timer 10, was 288, deadline in 479.9
s<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ClamAV-clamd: Connecting
to socket /var/run/clamav/clamd.ctl<br>
Jan 30 10:07:18.491 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) new socket by
IO::Socket::UNIX to /var/run/clamav/clamd.ctl, timeout set to 10<br>
Jan 30 10:07:18.492 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) connected to
/var/run/clamav/clamd.ctl successfully<br>
Jan 30 10:07:18.492 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ClamAV-clamd: Sending
CONTSCAN
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts\n
to socket /var/run/clamav/clamd.ctl<br>
Jan 30 10:07:18.492 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=1, wr=1, timeout=10<br>
Jan 30 10:07:18.493 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: sending 73 chars<br>
Jan 30 10:07:18.493 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop sent 73>
CONTSCAN
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts\n<br>
Jan 30 10:07:18.493 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal_scan - deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.493 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
ask_daemon_internal_scan: timer 288, was 10, deadline in 479.9 s<br>
Jan 30 10:07:18.493 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=0, wr=0, timeout=287.998<br>
Jan 30 10:07:18.520 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:18.520 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 68 chars<
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts:
OK\n<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=0, wr=0, timeout=287.998<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read: got eof<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal - deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
ask_daemon_internal: timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline run_av_3 -
deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer run_av_3:
timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.521 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (ClamAV-clamd)
result:
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts:
OK\n<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (ClamAV-clamd):
CLEAN<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (ClamAV-clamd)
result: clean<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) invoking av-scanner AVG
Anti-Virus<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ask_daemon: proto=DFLT,
spawn=0, (AVG Anti-Virus) 127.0.0.1:54322<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (AVG Anti-Virus):
query template(1,1): SCAN {}\n<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline run_av_pre -
deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.522 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer run_av_pre:
timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline run_av_scan -
deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer run_av_scan:
timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av Using (AVG
Anti-Virus): (code) SCAN
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts\n<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal_connect_pre - deadline in 479.9 s, set to
288.000 s<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal_connect - deadline in 479.9 s, set to 10.000 s<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
ask_daemon_internal_connect: timer 10, was 288, deadline in 479.9
s<br>
Jan 30 10:07:18.523 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) AVG Anti-Virus: Connecting
to socket 127.0.0.1:54322<br>
Jan 30 10:07:18.524 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) new socket using
IO::Socket::IP to [127.0.0.1]:54322, timeout 10<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) connected to
[127.0.0.1]:54322 successfully<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) AVG Anti-Virus: Sending
SCAN
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts\n
to socket 127.0.0.1:54322<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=1, wr=1, timeout=10<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 128 chars<
220-AVG daemon mode scanner (AVG)\r\n220-Program version
13.0.3115\r\n220-Virus Database: Version 4793/15359
2018-01-30\r\n220 Ready\r\n<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: sending 69 chars<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop sent 69> SCAN
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts\n<br>
Jan 30 10:07:18.525 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal_scan - deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.526 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
ask_daemon_internal_scan: timer 288, was 10, deadline in 479.9 s<br>
Jan 30 10:07:18.526 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=0, wr=0, timeout=287.997<br>
Jan 30 10:07:18.541 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:18.541 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 8 chars<
200 ok\r\n<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=0, wr=0, timeout=287.997<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read: got eof<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
ask_daemon_internal - deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
ask_daemon_internal: timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline run_av_3 -
deadline in 479.9 s, set to 288.000 s<br>
Jan 30 10:07:18.542 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer run_av_3:
timer 288, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.543 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (AVG Anti-Virus)
result: 220-AVG daemon mode scanner (AVG)\r\n220-Program version
13.0.3115\r\n220-Virus Database: Version 4793/15359
2018-01-30\r\n220 Ready\r\n200 ok\r\n<br>
Jan 30 10:07:18.543 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (AVG Anti-Virus):
CLEAN<br>
Jan 30 10:07:18.543 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) run_av (AVG Anti-Virus)
result: clean<br>
Jan 30 10:07:18.543 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) wbl: checking sender
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a><br>
Jan 30 10:07:18.544 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[blacklist_recip<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>] => undef,
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:18.544 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[blacklist_sender<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a>,blacklist_sender]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com">"skinny.body@ciaobbweb.com"</a> does not match<br>
Jan 30 10:07:18.544 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[whitelist_recip<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>] => undef,
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:18.544 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
lookup_acl(<a class="moz-txt-link-abbreviated" href="mailto:skinny.body@ciaobbweb.com">skinny.body@ciaobbweb.com</a>), no match<br>
Jan 30 10:07:18.545 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[whitelist_sender<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a>,whitelist_sender]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com">"skinny.body@ciaobbweb.com"</a> does not match<br>
Jan 30 10:07:18.545 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) query_keys:
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>, bob1@, myorg.org, .myorg.org, .org, .<br>
Jan 30 10:07:18.545 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
lookup_hash(<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>) matches keys: "."=>ARRAY(0x9379398)<br>
Jan 30 10:07:18.545 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[score_recip<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>,score_sender], 1 matches for
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a>, results:
"."=>[Amavis::Lookup::RE=ARRAY(0x9378b64),{}]<br>
Jan 30 10:07:18.546 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
lookup_re(<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com">"skinny.body@ciaobbweb.com"</a>), no matches<br>
Jan 30 10:07:18.546 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[score_sender<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a>] => undef,
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com">"skinny.body@ciaobbweb.com"</a> does not match<br>
Jan 30 10:07:18.546 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) SpamControl: calling spam
scanner SpamAssassin<br>
Jan 30 10:07:18.546 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
spam_scan_sa_pre - deadline in 479.9 s, set to 476.000 s<br>
Jan 30 10:07:18.546 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
spam_scan_sa_pre: timer 476, was 288, deadline in 479.9 s<br>
Jan 30 10:07:18.547 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) SA user config: "",
username: "amavis", 0, (<a class="moz-txt-link-abbreviated" href="mailto:0)bob1@myorg.org">0)bob1@myorg.org</a><br>
Jan 30 10:07:18.547 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) calling SA parse (0), SA
vers 3.4.1, 3.004001, data as STRING_REF, recips_ind [0], user:
"amavis"<br>
Jan 30 10:07:18.547 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline SA check -
deadline in 479.9 s, set to 475.000 s<br>
Jan 30 10:07:18.551 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) CALLING SA check (0)<br>
Jan 30 10:07:19.102 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) DONE SA check (0)<br>
Jan 30 10:07:19.103 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline spam_scan_sa
- deadline in 479.3 s, set to 288.000 s<br>
Jan 30 10:07:19.103 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
spam_scan_sa: timer 288, was 476, deadline in 479.3 s<br>
Jan 30 10:07:19.103 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) spam_scan: score=0
autolearn=ham autolearn_force=no tests=[none] recips=0<br>
Jan 30 10:07:19.104 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline spam_scan -
deadline in 479.3 s, set to 288.000 s<br>
Jan 30 10:07:19.104 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer spam_scan:
timer 288, was 288, deadline in 479.3 s<br>
Jan 30 10:07:19.104 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_tag_level]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:19.104 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (scalar) matches,
result="5"<br>
Jan 30 10:07:19.104 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_tag2_level]
=> true, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> matches, result="5",
matching_key="(constant:5)"<br>
Jan 30 10:07:19.105 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_tag3_level]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:19.105 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (scalar) matches,
result="5"<br>
Jan 30 10:07:19.105 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_kill_level]
=> true, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> matches, result="5",
matching_key="(constant:5)"<br>
Jan 30 10:07:19.105 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) final_destiny (ccat=0) is
PASS, recip <a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a><br>
Jan 30 10:07:19.105 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) final_destiny PASS, recip
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a><br>
Jan 30 10:07:19.106 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) do_notify_and_quar:
ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll)
ccat_block=(), qar_mth=<br>
Jan 30 10:07:19.106 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) do_notify_and_quarantine:
not quarantining, q_method off<br>
Jan 30 10:07:19.106 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) skip admin notification,
no administrators<br>
Jan 30 10:07:19.106 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) do_notify_and_quarantine -
done<br>
Jan 30 10:07:19.106 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (opaque) matches,
result="smtp:[127.0.0.1]:10025"<br>
Jan 30 10:07:19.107 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [forward_method]
=> true, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> matches,
result="smtp:[127.0.0.1]:10025",
matching_key="(opaque:smtp:[127.0.0.1]:10025)"<br>
Jan 30 10:07:19.107 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) delivery method is 1,
recips: <a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a><br>
Jan 30 10:07:19.107 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (scalar) matches,
result="1"<br>
Jan 30 10:07:19.107 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[remove_existing_spam_headers] => true, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a>
matches, result="1", matching_key="(constant:1)"<br>
Jan 30 10:07:19.108 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_tag_level]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:19.108 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (scalar) matches,
result="5"<br>
Jan 30 10:07:19.108 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_tag2_level]
=> true, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> matches, result="5",
matching_key="(constant:5)"<br>
Jan 30 10:07:19.108 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup [spam_subject_tag]
=> undef, <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org">"bob1@myorg.org"</a> does not match<br>
Jan 30 10:07:19.108 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) headers CLUSTERING: NEW
CLUSTER <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>: score=0, tag=1, tag2=0, local=1,
bl=, s=, mangle=<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header encoded
(all-ASCII): X-Virus-Scanned: Debian amavisd-new at
M1-2.dettenwanger.com<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header: X-Virus-Scanned:
Debian amavisd-new at M1-2.dettenwanger.com\n<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header encoded
(all-ASCII): X-Spam-Flag: NO<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header: X-Spam-Flag: NO\n<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header encoded
(all-ASCII): X-Spam-Score: 0<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header: X-Spam-Score: 0\n<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header encoded
(all-ASCII): X-Spam-Level:<br>
Jan 30 10:07:19.109 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header: X-Spam-Level:\n<br>
Jan 30 10:07:19.110 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header encoded
(all-ASCII): X-Spam-Status: No,\n score=0\n required=5\n
tests=[none]\n autolearn=ham autolearn_force=no<br>
Jan 30 10:07:19.110 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header: X-Spam-Status: No,
score=0 required=5 tests=[none]\n\tautolearn=ham
autolearn_force=no\n<br>
Jan 30 10:07:19.110 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) fwd: scanner provided a
header field X-Spam-Checker-Version, inhibited by
%allowed_added_header_fields<br>
Jan 30 10:07:19.111 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header encoded
(all-ASCII): Received: from M1-2.mymailserver.com ([127.0.0.1])\n
by localhost (m1-2.mymailserver.com [127.0.0.1]) (amavisd-new,
port 10024)\n with ESMTP\n id viK49HCkVsDs\n for
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>;\n Tue, 30 Jan 2018 10:07:18 -0600 (CST)<br>
Jan 30 10:07:19.111 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) header: Received: from
M1-2.mymailserver.com ([127.0.0.1])\n\tby localhost
(m1-2.mymailserver.com [127.0.0.1]) (amavisd-new, port
10024)\n\twith ESMTP id viK49HCkVsDs for
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>;\n\tTue, 30 Jan 2018 10:07:18 -0600 (CST)\n<br>
Jan 30 10:07:19.111 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) headers CLUSTERING: done
all 1 recips in one go<br>
Jan 30 10:07:19.111 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) spam-tag,
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> -> <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>,
No, score=0 required=5 tests=[none] autolearn=ham
autolearn_force=no<br>
Jan 30 10:07:19.112 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) about to connect to
smtp:[127.0.0.1]:10025, viK49HCkVsDs FWD from
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> -> <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a><br>
Jan 30 10:07:19.112 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline fwd_init -
deadline in 479.3 s, set to 480.000 s<br>
Jan 30 10:07:19.112 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp session: setting up a
new session<br>
Jan 30 10:07:19.112 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) establish_or_refresh,
state: down<br>
Jan 30 10:07:19.112 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) new socket using
IO::Socket::IP to [127.0.0.1]:10025, timeout 35<br>
Jan 30 10:07:19.113 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) connected to
[127.0.0.1]:10025 successfully<br>
Jan 30 10:07:19.113 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=1,
flush=0, wr=0, timeout=35<br>
Jan 30 10:07:19.127 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:19.127 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 64 chars<
220 M1-2.mymailserver.com ESMTP Postfix (Ubuntu)\r\n<br>
Jan 30 10:07:19.127 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp greeting: 220
M1-2.mymailserver.com ESMTP Postfix (Ubuntu), dt: 14.6 ms<br>
Jan 30 10:07:19.127 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp cmd> EHLO
localhost<br>
Jan 30 10:07:19.127 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=1, wr=1, timeout=300<br>
Jan 30 10:07:19.128 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: sending 16 chars<br>
Jan 30 10:07:19.128 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop sent 16> EHLO
localhost\r\n<br>
Jan 30 10:07:19.128 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=1,
flush=0, wr=0, timeout=300<br>
Jan 30 10:07:19.128 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:19.128 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 158 chars<
250-M1-2.mymailserver.com\r\n250-PIPELINING\r\n250-SIZE
31457280\r\n250-VRFY\r\n250-ETRN\r\n250-STARTTLS\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250
DSN\r\n<br>
Jan 30 10:07:19.129 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp resp to EHLO: 250
M1-2.mymailserver.com\nPIPELINING\nSIZE
31457280\nVRFY\nETRN\nSTARTTLS\nENHANCEDSTATUSCODES\n8BITMIME\nDSN<br>
Jan 30 10:07:19.129 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) tls active=0, capable=1,
sec_level=0<br>
Jan 30 10:07:19.129 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Remote host presents
itself as: M1-2.mymailserver.com, handles DSN, PIPELINING,
8BITMIME<br>
Jan 30 10:07:19.130 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) AUTH not needed, user='',
MTA offers ''<br>
Jan 30 10:07:19.130 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp cmd> MAIL
FROM:<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> BODY=7BIT<br>
Jan 30 10:07:19.130 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) orcpt_encode rfc822,
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>, encode_for_smtp<br>
Jan 30 10:07:19.130 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp cmd> RCPT
TO:<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a> <a class="moz-txt-link-abbreviated" href="mailto:ORCPT=rfc822;bob1@myorg.org">ORCPT=rfc822;bob1@myorg.org</a><br>
Jan 30 10:07:19.131 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp cmd> DATA<br>
Jan 30 10:07:19.131 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=1, wr=1, timeout=120<br>
Jan 30 10:07:19.131 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: sending 107 chars<br>
Jan 30 10:07:19.131 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop sent 107> MAIL
FROM:<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> BODY=7BIT\r\nRCPT
TO:<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a> <a class="moz-txt-link-abbreviated" href="mailto:ORCPT=rfc822;bob1@myorg.org\r\nDATA\r\n">ORCPT=rfc822;bob1@myorg.org\r\nDATA\r\n</a><br>
Jan 30 10:07:19.131 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=1,
flush=0, wr=0, timeout=300<br>
Jan 30 10:07:19.136 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:19.136 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 65 chars<
250 2.1.0 Ok\r\n250 2.1.5 Ok\r\n354 End data with
<CR><LF>.<CR><LF>\r\n<br>
Jan 30 10:07:19.137 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp resp to MAIL (pip):
250 2.1.0 Ok<br>
Jan 30 10:07:19.137 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp resp to RCPT (pip)
(<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>): 250 2.1.5 Ok<br>
Jan 30 10:07:19.138 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp resp to DATA: 354 End
data with <CR><LF>.<CR><LF><br>
Jan 30 10:07:19.138 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) write_header: 1,
Amavis::Out::SMTP::Protocol=HASH(0xc13c210)<br>
Jan 30 10:07:19.138 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) deleted:
X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28)
on\n\tM1-2.mymailserver.com<br>
Jan 30 10:07:19.139 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=0,
flush=1, wr=1, timeout=180<br>
Jan 30 10:07:19.139 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: sending 40537
chars<br>
Jan 30 10:07:19.139 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop sent 40537>
X-Virus-Scanned: Debian amavisd-new at
M1-2.dettenwanger.com\r\nX-Spam-Flag: NO\r\nX-Spam-Score:
0\r\nX-Spam-Level:\r\nX-Spam-Status: No, score=0 required=5
tests=[none]\r\n\tautolearn=ham autolearn_force=no\r\nRe [...]<br>
Jan 30 10:07:19.140 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=1,
flush=0, wr=1, timeout=479.972<br>
Jan 30 10:07:19.140 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: sending 5 chars<br>
Jan 30 10:07:19.140 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop sent 5>
\r\n.\r\n<br>
Jan 30 10:07:19.140 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: needline=1,
flush=0, wr=0, timeout=479.972<br>
Jan 30 10:07:19.179 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop: receiving<br>
Jan 30 10:07:19.179 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rw_loop read 36 chars<
250 2.0.0 Ok: queued as 20E27604B4\r\n<br>
Jan 30 10:07:19.180 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) smtp resp to data-dot
(<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>): 250 2.0.0 Ok: queued as 20E27604B4, dt:
39.3 ms<br>
Jan 30 10:07:19.180 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Amavis::Out::SMTP::Session
close, keeping connection<br>
Jan 30 10:07:19.180 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
fwd-end-chkpnt - deadline in 479.3 s, set to 288.000 s<br>
Jan 30 10:07:19.180 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
fwd-end-chkpnt: timer 288, was 0, deadline in 479.3 s<br>
Jan 30 10:07:19.181 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) viK49HCkVsDs FWD from
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> -> <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>,
BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0
Ok: queued as 20E27604B4<br>
Jan 30 10:07:19.181 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline forwarding -
deadline in 479.3 s, set to 288.000 s<br>
Jan 30 10:07:19.181 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer forwarding:
timer 288, was 288, deadline in 479.3 s<br>
Jan 30 10:07:19.182 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) DSN: sender NOT credible,
SA: 0.000, <a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a><br>
Jan 30 10:07:19.182 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup: (scalar) matches,
result="7"<br>
Jan 30 10:07:19.182 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) lookup
[spam_dsn_cutoff_level_bysender] => true,
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com">"skinny.body@ciaobbweb.com"</a> matches, result="7",
matching_key="(constant:7)"<br>
Jan 30 10:07:19.182 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) dsn: from MTA 250
NonBlocking:CleanTag <a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> ->
<a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>: on_succ=0, on_dly=1, on_fail=1, never=0,
warn_sender=, DSN_passed_on=1, destiny=1, mta_resp: "250 2.0.0
from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as
20E27604B4"<br>
Jan 30 10:07:19.183 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) DSN: SUCC from MTA 250
NonBlocking:CleanTag, no DSN requested:
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> -> <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a><br>
Jan 30 10:07:19.183 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
delivery_status_notification: notif 0 bytes, suppressed: no<br>
Jan 30 10:07:19.183 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) one_response_for_all,
per_recip_capable: N, suppressed: N<br>
Jan 30 10:07:19.183 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) one_response_for_all
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a>: success, r=0,b=0,d=0,
ndn_needed=0, '250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250
2.0.0 Ok: queued as 20E27604B4'<br>
Jan 30 10:07:19.184 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) notif=N, suppressed=0,
ndn_needed=0, exit=0, 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025):
250 2.0.0 Ok: queued as 20E27604B4<br>
Jan 30 10:07:19.184 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
delivery-notification - deadline in 479.3 s, set to 288.000 s<br>
Jan 30 10:07:19.184 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
delivery-notification: timer 288, was 288, deadline in 479.3 s<br>
Jan 30 10:07:19.184 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) status counters:
InMsgsStatus{Relayed,RelayedUntagged,RelayedUntaggedInbound}<br>
Jan 30 10:07:19.184 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline snmp-counters
- deadline in 479.3 s, set to 288.000 s<br>
Jan 30 10:07:19.184 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
snmp-counters: timer 288, was 288, deadline in 479.3 s<br>
Jan 30 10:07:19.185 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) orcpt_encode rfc822,
<a class="moz-txt-link-abbreviated" href="mailto:bob1@myorg.org">bob1@myorg.org</a>, smtputf8<br>
Jan 30 10:07:19.190 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01)
oldest_public_ip_addr_from_received: 192.140.22.179<br>
Jan 30 10:07:19.193 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) Passed CLEAN
{RelayedInbound}, [127.0.0.1] [192.140.22.179]
<a class="moz-txt-link-rfc2396E" href="mailto:skinny.body@ciaobbweb.com"><skinny.body@ciaobbweb.com></a> -> <a class="moz-txt-link-rfc2396E" href="mailto:bob1@myorg.org"><bob1@myorg.org></a>,
Message-ID:
<a class="moz-txt-link-rfc2396E" href="mailto:WMjfAEt7u5.JzidMDB.5hAHoVX.IrH7cNEeIytd2@web2.ciaobbweb.com"><WMjfAEt7u5.JzidMDB.5hAHoVX.IrH7cNEeIytd2@web2.ciaobbweb.com></a>,
mail_id: viK49HCkVsDs, Hits: 0, size: 40190, queued_as:
20E27604B4, 801 ms<br>
Jan 30 10:07:19.193 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
main_log_entry - deadline in 479.2 s, set to 288.000 s<br>
Jan 30 10:07:19.193 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
main_log_entry: timer 288, was 288, deadline in 479.2 s<br>
Jan 30 10:07:19.193 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) TIMING-SA total 554 ms -
parse: 3.0 (0.5%), extract_message_metadata: 28 (5.1%),
get_uri_detail_list: 5 (0.9%), tests_pri_0: 263 (47.4%),
check_spf: 111 (19.9%), poll_dns_idle: 225 (40.6%), tests_pri_500:
130 (23.5%), learn: 125 (22.5%), b_learn: 119 (21.5%),
b_count_change: 67 (12.0%), get_report: 0.06 (0.0%)<br>
Jan 30 10:07:19.193 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) updating snmp variables in
BDB<br>
Jan 30 10:07:19.195 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline check done -
deadline in 479.2 s, set to 288.000 s<br>
Jan 30 10:07:19.195 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer check done:
timer 288, was 288, deadline in 479.2 s<br>
Jan 30 10:07:19.195 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) sending SMTP response:
"250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued
as 20E27604B4"<br>
Jan 30 10:07:19.195 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 250 2.0.0 from
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 20E27604B4<br>
Jan 30 10:07:19.196 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:19.196 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) TempDir::strip:
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0<br>
Jan 30 10:07:19.196 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) rmdir_recursively:
/var/lib/amavis/tmp/amavis-20180130T100718-03621-WTglx9E0/parts,
excl=1<br>
Jan 30 10:07:19.198 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) size: 40190, TIMING [total
807 ms] - SMTP greeting: 5 (1%)1, SMTP EHLO: 2.1 (0%)1, SMTP
pre-MAIL: 1.4 (0%)1, mkdir tempdir: 1.4 (0%)1, create email.txt:
0.4 (0%)1, SMTP pre-DATA-flush: 4.6 (1%)2, SMTP DATA: 32 (4%)6,
check_init: 0.6 (0%)6, digest_hdr: 3.4 (0%)6, digest_body_dkim:
1.5 (0%)7, collect_info: 3.7 (0%)7, mkdir parts: 2.4 (0%)7,
mime_decode: 13 (2%)9, get-file-type2: 22 (3%)12, parts_decode:
0.6 (0%)12, check_header: 1.0 (0%)12, AV-scan-1: 36 (4%)16,
AV-scan-2: 21 (3%)19, spam-wb-list: 3.0 (0%)19, SA msg read: 0.9
(0%)19, SA parse: 4.2 (1%)20, SA check: 551 (68%)88,
decide_mail_destiny: 3.8 (0%)89, notif-quar: 0.6 (0%)89,
fwd-connect: 23 (3%)92, fwd-mail-pip: 7 (1%)92, fwd-rcpt-pip: 0.5
(0%)93, fwd-data-chkpnt: 0.1 (0%)93, write-header: 1.1 (0%)93,
fwd-data-contents: 1.0 (0%)93, fwd-end-chkpnt: 41 (5%)98,
prepare-dsn: 2.7 (0%)98, report: 2.7 (0%)99, main_log_entry: 7
(1%)99, update_snmp: 1.7 (0%)100, SMTP pre-response: 0.4 (0%)100,
SMTP response: 0.5 (0%)100, unlink-2-files: 0.7 (0%)100, rundown:
0.9 (0%)100<br>
Jan 30 10:07:19.198 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 6: was busy,
793.3 ms, total idle 0.001 s, busy 0.806 s<br>
Jan 30 10:07:19.198 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, 5: was idle,
0.2 ms, total idle 0.001 s, busy 0.806 s<br>
Jan 30 10:07:19.198 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP< QUIT\r\n<br>
Jan 30 10:07:19.199 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) get_deadline
switch_to_my_time(rx SMTP QUIT) - deadline in 480.0 s, set to
288.000 s<br>
Jan 30 10:07:19.199 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) prolong_timer
switch_to_my_time(rx SMTP QUIT): timer 288, was 480, deadline in
480.0 s<br>
Jan 30 10:07:19.199 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) ESMTP> 221 2.0.0
[127.0.0.1] amavisd-new closing transmission channel<br>
Jan 30 10:07:19.199 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) switch_to_client_time 480
s, smtp response sent<br>
Jan 30 10:07:19.199 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) SMTP session over, timer
stopped<br>
Jan 30 10:07:19.202 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) exiting process_request<br>
Jan 30 10:07:19.202 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) idle_proc, bye: was busy,
4.1 ms, total idle 0.001 s, busy 0.810 s<br>
Jan 30 10:07:19.202 M1-2.mymailserver.com
/usr/sbin/amavisd-new[3621]: (03621-01) load: 100 %, total idle
0.001 s, busy 0.810 s<br>
<br>
</font>
</body>
</html>