amavis is listening on port 10024...
w/0.93 $ echo "Test message" | smtpclient -S localhost -P 10024 my@email.com
SMTPclient: unexpected reply: 451 4.5.0 Error in processing, id=31584-01,
parts_decode_ext FAILED: parsing file(1) results - missing last 1 results at
(eval 44) line 154.
downgrade to 0.90...
w/0.90 $ echo "Test message" | smtpclient -S localhost -P 10024 my@email.com
SMTPclient: delivery: 250 2.6.0 Ok, id=00481-01, from MTA([127.0.0.1]:10025):
250 Ok: queued as 11EE6304B1
In amavisd's log:
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: Net::Server:
2006/04/07-11:51:12 CONNECT TCP Peer: "127.0.0.1:54576" Local:
"127.0.0.1:10024"
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: loaded base
policy bank
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: lookup_ip_acl
(inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: prolong_timer
after new request - timer reset: remaining time = 300 s
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 6741.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: process_request:
suggested_protocol="" on TCP
Use of uninitialized value in string eq at /usr/sbin/amavisd line 6757.
Use of uninitialized value in string eq at /usr/sbin/amavisd line 6757.
Use of uninitialized value in string eq at /usr/sbin/amavisd line 6769.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
190.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
190.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
190.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
220 [127.0.0.1] ESMTP amavisd-new service ready
Use of uninitialized value in sprintf at /usr/sbin/amavisd line 1311.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 4: was busy, 5.0 ms, total idle 0.000 s, busy 0.005 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.7 ms, total idle 0.001 s, busy 0.005 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
HELO cloud.cs.berkeley.edu\r\n
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
250 [127.0.0.1]
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 1.1 ms, total idle 0.001 s, busy 0.006 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.006 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
MAIL FROM: <root@cloud.cs.berkeley.edu>\r\n
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after MAIL FROM received - timer reset: remaining time = 300 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
check_mail_begin_task: task_count=1
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prepare_tempdir: creating directory
/var/amavis/tmp/amavis-20060407T115112-01521
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prepare_tempdir: creating file
/var/amavis/tmp/amavis-20060407T115112-01521/email.txt
Use of uninitialized value in string ne at (eval 39) line 399, <GEN4> line 2.
Use of uninitialized value in split at (eval 39) line 435, <GEN4> line 2.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
250 2.1.0 Sender root@cloud.cs.berkeley.edu OK
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) lookup
(debug_sender) => undef, "root@cloud.cs.berkeley.edu" does not match
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 4.3 ms, total idle 0.001 s, busy 0.010 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.010 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
RCPT TO: <my@email.com>\r\n
Use of uninitialized value in string ne at (eval 39) line 505, <GEN4> line 3.
Use of uninitialized value in numeric gt (>) at (eval 39) line 519, <GEN4> line
3.
Use of uninitialized value in numeric gt (>) at (eval 39) line 519, <GEN4> line
3.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
250 2.1.5 Recipient my@email.com OK
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 1.2 ms, total idle 0.001 s, busy 0.012 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.012 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 300 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
DATA\r\n
Use of uninitialized value in string ne at (eval 39) line 226, <GEN4> line 4.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after DATA received - timer reset: remaining time = 300 s
Use of uninitialized value in string eq at (eval 39) line 559, <GEN4> line 4.
Use of uninitialized value in string eq at (eval 39) line 559, <GEN4> line 4.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
SMTP::10024 /var/amavis/tmp/amavis-20060407T115112-01521:
<root@cloud.cs.berkeley.edu> -> <my@email.com> Received: from
cloud.cs.berkeley.edu ([127.0.0.1]) by localhost (mail.outersquare.org
[127.0.0.1]) (amavisd-new, port 10024) with SMTP id 01521-01 for
<my@email.com>; Fri, 7 Apr 2006 11:51:12 -0700 (PDT)
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
354 End data with <CR><LF>.<CR><LF>
Use of uninitialized value in numeric eq (==) at (eval 39) line 575, <GEN4>
line 4.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
.\r\n
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
setting body type: 7BIT (0,0)
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) body
hash: 33fed2341aa0242c069aa645e36c0f9e
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Original mail size: 104; quota set to: 102400 bytes
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 6975, <GEN5> line 4.
Use of uninitialized value in string eq at /usr/sbin/amavisd line 7004, <GEN5>
line 4.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Checking: lIdlHBtZeNO6 <root@cloud.cs.berkeley.edu> -> <my@email.com>
Use of uninitialized value in string ne at /usr/sbin/amavisd line 2226, <GEN5>
line 4.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
query_keys: my@email.com, my@, email.com, .email.com, .com, .
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 2260, <GEN5> line 4.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
lookup_hash(my@email.com), no matches
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) lookup
(bypass_virus_checks) => undef, "my@email.com" does not match
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Extracting mime components
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) Issued
a new file name: p001
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
Charging 13 bytes to remaining quota 102400 (out of 102400, (0%)) - by
mime_decode
Use of uninitialized value in concatenation (.) or string at /usr/sbin/amavisd
line 5518.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) p001 1
Content-Type: text/plain, size: 13 B, name:
Use of uninitialized value in string ne at /usr/sbin/amavisd line 5539.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after mime_decode-1: remaining time = 300 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
decode_parts: level=1, #parts=1 : p001
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1527]: (01521-01)
run_command: child process [1527]: Error closing main::stdin: Bad file
descriptor at /usr/sbin/amavisd line 1872.\n
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
run_command: [1527] /usr/bin/file p001 </dev/null 2>&1
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
TROUBLE in check_mail: parts_decode_ext FAILED: parsing file(1) results -
missing last 1 results at (eval 44) line 154.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
sending SMTP response: "451 4.5.0 Error in processing, id=01521-01,
parts_decode_ext FAILED: parsing file(1) results - missing last 1 results at
(eval 44) line 154."
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
451 4.5.0 Error in processing, id=01521-01, parts_decode_ext FAILED: parsing
file(1) results - missing last 1 results at (eval 44) line 154.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) timer
stopped after DATA end
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
PRESERVING EVIDENCE in /var/amavis/tmp/amavis-20060407T115112-01521
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) TIMING
[total 42 ms] - SMTP HELO: 7 (16%)16, SMTP pre-MAIL: 1 (3%)19, mkdir tempdir: 1
(3%)22, create email.txt: 1 (1%)23, SMTP DATA: 6 (14%)37, body_digest: 1
(3%)40, gen_mail_id: 1 (2%)42, mkdir parts: 1 (1%)43, mime_decode: 9 (22%)65,
rundown: 15 (35%)100
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 6: was busy, 29.6 ms, total idle 0.001 s, busy 0.041 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, 5: was idle, 0.4 ms, total idle 0.002 s, busy 0.041 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
prolong_timer after reading SMTP command: remaining time = 0 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP<
QUIT\r\n
Use of uninitialized value in string ne at (eval 39) line 226, <GEN4> line 11.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
243, <GEN4> line 11.
Use of uninitialized value in concatenation (.) or string at (eval 39) line
243, <GEN4> line 11.
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) SMTP>
221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
post_process_request_hook: timer stopped
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01)
idle_proc, bye: was busy, 3.2 ms, total idle 0.002 s, busy 0.044 s
Apr 7 11:51:12 mail.outersquare.org /usr/sbin/amavisd[1521]: (01521-01) load:
96 %, total idle 0.002 s, busy 0.044 s
Filehandle STDIN reopened as LOCK only for output at
/usr/lib64/perl5/vendor_perl/5.8.8/Net/Server/PreForkSimple.pm line 244.