OSEC

Neohapsis is currently accepting applications for employment. For more information, please visit our website www.neohapsis.com or email hr@neohapsis.com
Mail Looping Problem?

From: Chris Richards (gizmogiz-works.com)
Date: Fri Mar 07 2008 - 09:03:52 CST


I've been experimenting with an application that takes mail deliver via
the transport PIPE mechanism. Somehow, I've created a problem where I
have an e-mail cascade of some kind, and I'm not understanding what I'm
getting in the PostFix logs.

There are some errors about virtual_alias_maps, and there are some
errors relating messages being rejected for bad formatting, and then the
rejections are getting rejected or something. The original culprit was
an e-mail sent from vision1media_AT_vision1media_DOT_com to
jeff_AT_vision1media_DOT_com. Now, I'm getting messages from
vision1_AT_aoaforums_DOT_com also, which was a test user I created, and
then stopped using.

I've deleted the jeff and vision1 mail accounts from my sql database for
the moment, and I've disabled the transport I wrote, so that I could at
least send this message to the list and hopefull get some responses.

The system is Postfix 2.4.6 with PostGrey 1.31, Amavisd-new 2.5.2
(SpamAssassin and ClamAV), and Courier-Imap 4.0.6. user and transport
information is maintained in a MySQL database, based on the Virtual
MAILBOX example with separate domains and non-UNIX accounts at
http://www.postfix.org/VIRTUAL_README.html#virtual_mailbox.

The platform is Gentoo Linux running 2.6.23-r7 kernel. This system has
been running fine until today when I started trying to route messages
through my application.

Here is a chunk of the log, ending with where I stopped PostFix:

Mar 7 08:22:25 [amavis] (28294-01-194) SEND via SMTP: <> ->
<vision1aoaforums.com>,ENVID=AM..20080307T142225Zaoaforums.com 250
2.6.0 Ok, id=28294-01-194, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok:
queued as 3340B7408C
Mar 7 08:22:25 [amavis] (28294-01-194) Blocked MTA-BLOCKED,
<vision1aoaforums.com> -> <MAILER-DAEMONaoaforums.com>, quarantine:
badh-xMVtGaBGHHpS, Message-ID:
<20080307140551.AB1ED7B1FEaoaforums.com>, mail_id: xMVtGaBGHHpS, Hits:
-0.112, size: 597, 394 ms
Mar 7 08:22:25 [amavis] (28294-01-194) Not-Delivered,
<vision1aoaforums.com> -> <MAILER-DAEMONaoaforums.com>, quarantine
xMVtGaBGHHpS, Message-ID: <20080307140551.AB1ED7B1FEaoaforums.com>,
Hits: -0.112
Mar 7 08:22:25 [amavis] (28294-01-194) TIMING [total 399 ms] - SMTP
pre-DATA-flush: 1 (0%)0, SMTP DATA: 33 (8%)9, check_init: 0 (0%)9,
digest_hdr: 0 (0%)9, digest_body: 0 (0%)9, gen_mail_id: 0 (0%)9,
mime_decode: 3 (1%)10, get-file-type1: 5 (1%)11, decompose_part: 0
(0%)11, parts_decode: 0 (0%)11, check_header: 1 (0%)11, spam-wb-list: 1
(0%)12, SA parse: 1 (0%)12, SA check: 300 (75%)87, update_cache: 3
(1%)88, decide_mail_destiny: 1 (0%)88, open-mbx: 2 (1%)89, write-header:
0 (0%)89, save-to-local-mailbox: 0 (0%)89, fwd-connect: 3 (1%)89,
fwd-mail-pip: 1 (0%)90, fwd-rcpt-pip: 0 (0%)90, fwd-data-chkpnt: 0
(0%)90, fwd-end-chkpnt: 1 (0%)90, prepare-dsn: 8 (2%)92, fwd-connect: 1
(0%)92, fwd-mail-pip: 1 (0%)92, fwd-rcpt-pip: 0 (0%)92, fwd-data-chkpnt:
0 (0%)92, write-header: 0 (0%)92, fwd-data-contents: 3 (1%)93,
fwd-end-chkpnt: 19 (5%)98, main_log_entry: 5 (1%)99, SMTP pre-response:
0 (0%)99, SMTP response: 0 (0%)99, unlink-1-files: 3 (1%)100, rundown: 0
(0%)100
Mar 7 14:22:25 [postfix/smtp] AB1ED7B1FE:
to=<MAILER-DAEMONaoaforums.com>, relay=127.0.0.1[127.0.0.1]:10024,
conn_use=194, delay=994, delays=0.07/993/0/0.4, dsn=5.1.1,
status=bounced (host 127.0.0.1[127.0.0.1] said: 550 5.1.1 Failed,
id=28294-01-194, from MTA([127.0.0.1]:10025): 550 5.1.1
<MAILER-DAEMONaoaforums.com>: Recipient address rejected: User unknown
(in reply to end of DATA command))
Mar 7 08:22:25 [postfix/cleanup] 3E7D274091:
message-id=<20080307142225.3E7D274091aoaforums.com>
Mar 7 08:22:25 [amavis] (28294-01-195) ESMTP::10024
/var/run/amavis/tmp/amavis-20080307T081752-28294:
<vision1aoaforums.com> -> <MAILER-DAEMONaoaforums.com> SIZE=598
Received: from aoaforums.com ([127.0.0.1]) by localhost (aoaforums.com
[127.0.0.1]) (amavisd-new, port 10024) with ESMTP for
<MAILER-DAEMONaoaforums.com>; Fri, 7 Mar 2008 08:22:25 -0600 (CST)
Mar 7 08:22:25 [postfix/bounce] AB1ED7B1FE: sender non-delivery
notification: 3E7D274091
Mar 7 08:22:25 [postfix/qmgr] 3E7D274091: from=<>, size=2636, nrcpt=1
(queue active)
Mar 7 08:22:25 [postfix/qmgr] AB1ED7B1FE: removed
Mar 7 08:22:25 [amavis] (28294-01-195) Checking: 6wc4lo5KwjtX
<vision1aoaforums.com> -> <MAILER-DAEMONaoaforums.com>
Mar 7 08:22:25 [amavis] (28294-01-195) cached
8137126a6c6e14e0aa02cbfe0a0fd967 from <vision1aoaforums.com> (1,0)
Mar 7 08:22:25 [amavis] (28294-01-195) p001 1 Content-Type: text/html,
size: 143 B, name:
Mar 7 08:22:25 [amavis] (28294-01-195) check_header: 3, Improper use of
control character (char 0D hex): MIME_Version: 1.0\\r\\n
Mar 7 08:22:25 [amavis] (28294-01-195) check_header: 3, Improper use of
control character (char 0D hex): Content-type: text/html;
charset=iso-8859-1\\r\\n
Mar 7 08:22:25 [amavis] (28294-01-195) check_header: 3, Improper use of
control character (char 0D hex): Sender: vision1mediavision1media.com\\r\\n
Mar 7 08:22:25 [amavis] (28294-01-195) check_header: 3, Improper use of
control character (char 0D hex): From: Vision1Media
<vision1mediavision1media.com>\\r\\n
Mar 7 08:22:25 [postfix/pickup] 4C4629D467: uid=1011 from=<vision1>
Mar 7 08:22:25 [postfix/cleanup] 4C4629D467:
message-id=<20080307142225.4C4629D467aoaforums.com>
Mar 7 08:22:25 [postfix/qmgr] 4C4629D467: from=<vision1aoaforums.com>,
size=604, nrcpt=1 (queue active)
Mar 7 08:22:25 [postfix/pickup] 55FB72941C: uid=1011 from=<vision1>
Mar 7 08:22:25 [postfix/cleanup] 55FB72941C:
message-id=<20080307142225.55FB72941Caoaforums.com>
Mar 7 08:22:25 [postfix/pipe] 3340B7408C: to=<vision1aoaforums.com>,
relay=v1m, delay=0.15, delays=0.02/0/0/0.12, dsn=2.0.0, status=sent
(delivered via v1m service)
Mar 7 08:22:25 [postfix/qmgr] 3340B7408C: removed
Mar 7 08:22:25 [postfix/pickup] 6100C294E7: uid=1011 from=<vision1>
Mar 7 08:22:25 [postfix/qmgr] 55FB72941C: from=<vision1aoaforums.com>,
size=609, nrcpt=1 (queue active)
Mar 7 08:22:25 [postfix/cleanup] 6100C294E7:
message-id=<20080307142225.6100C294E7aoaforums.com>
Mar 7 08:22:25 [postfix/qmgr] 6100C294E7: from=<vision1aoaforums.com>,
size=598, nrcpt=1 (queue active)
Mar 7 08:22:25 [postfix/pickup] 6A8332CAE6: uid=1011 from=<vision1>
Mar 7 08:22:25 [postfix/cleanup] 6A8332CAE6:
message-id=<20080307142225.6A8332CAE6aoaforums.com>
Mar 7 08:22:25 [postfix/pipe] 3E7D274091: to=<vision1aoaforums.com>,
relay=v1m, delay=0.18, delays=0.04/0/0/0.15, dsn=2.0.0, status=sent
(delivered via v1m service)
Mar 7 08:22:25 [postfix/qmgr] 3E7D274091: removed
Mar 7 08:22:25 [postfix/qmgr] 6A8332CAE6: from=<vision1aoaforums.com>,
size=599, nrcpt=1 (queue active)
Mar 7 08:22:27 [amavis] (28309-01-179) local delivery: <> ->
<bad-header-quarantine>, mbx=/var/virusmails/badh-XGIXuM8aWK9m
Mar 7 08:22:27 [amavis] (28309-01-179) SPAM-TAG,
<vision1aoaforums.com> -> <postmasteraoaforums.com>, No, score=0.632
required=5 tests=[AWL=-0.372, BAYES_05=-1.11, HTML_MESSAGE=0.001,
HTML_MIME_NO_HTML_TAG=0.097, MIME_HEADER_CTYPE_ONLY=0.56,
MIME_HTML_ONLY=1.457, NO_RELAYS=-0.001]
Mar 7 08:22:27 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:27 [postfix/smtpd] CFF9A2CAE4: client=localhost[127.0.0.1]
Mar 7 08:22:27 [postfix/cleanup] CFF9A2CAE4:
message-id=<20080307140550.F211E7B1FFaoaforums.com>
Mar 7 08:22:27 [postfix/smtpd] disconnect from localhost[127.0.0.1]
Mar 7 08:22:27 [postfix/qmgr] CFF9A2CAE4: from=<vision1aoaforums.com>,
size=1463, nrcpt=1 (queue active)
Mar 7 08:22:27 [amavis] (28309-01-179) FWD via SMTP:
<vision1aoaforums.com> -> <postmasteraoaforums.com>,BODY=7BIT 250
2.6.0 Ok, id=28309-01-179, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok:
queued as CFF9A2CAE4
Mar 7 08:22:27 [amavis] (28309-01-179) Passed BAD-HEADER,
<vision1aoaforums.com> -> <postmasteraoaforums.com>, quarantine:
badh-XGIXuM8aWK9m, Message-ID:
<20080307140550.F211E7B1FFaoaforums.com>, mail_id: XGIXuM8aWK9m, Hits:
0.632, size: 603, queued_as: CFF9A2CAE4, 5158 ms
Mar 7 08:22:27 [amavis] (28309-01-179) Passed, <vision1aoaforums.com>
-> <postmasteraoaforums.com>, quarantine XGIXuM8aWK9m, Message-ID:
<20080307140550.F211E7B1FFaoaforums.com>, Hits: 0.632
Mar 7 08:22:27 [amavis] (28309-01-179) TIMING [total 5160 ms] - SMTP
pre-DATA-flush: 1 (0%)0, SMTP DATA: 37 (1%)1, check_init: 0 (0%)1,
digest_hdr: 0 (0%)1, digest_body: 0 (0%)1, gen_mail_id: 0 (0%)1,
mime_decode: 3 (0%)1, get-file-type1: 6 (0%)1, decompose_part: 0 (0%)1,
parts_decode: 0 (0%)1, check_header: 1 (0%)1, spam-wb-list: 1 (0%)1, SA
parse: 1 (0%)1, SA check: 5074 (98%)99, update_cache: 3 (0%)99,
decide_mail_destiny: 1 (0%)99, open-mbx: 2 (0%)99, write-header: 0
(0%)99, save-to-local-mailbox: 0 (0%)99, fwd-connect: 3 (0%)100,
fwd-mail-pip: 1 (0%)100, fwd-rcpt-pip: 0 (0%)100, fwd-data-chkpnt: 0
(0%)100, write-header: 0 (0%)100, fwd-data-contents: 0 (0%)100,
fwd-end-chkpnt: 16 (0%)100, prepare-dsn: 1 (0%)100, main_log_entry: 5
(0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100,
unlink-1-files: 0 (0%)100, rundown: 0 (0%)100
Mar 7 14:22:27 [postfix/smtp] F211E7B1FF:
to=<postmasteraoaforums.com>, relay=127.0.0.1[127.0.0.1]:10024,
conn_use=179, delay=997, delays=0.07/992/0/5.2, dsn=2.0.0, status=sent
(250 2.0.0 Ok: queued as CFF9A2CAE4)
Mar 7 08:22:27 [postfix/qmgr] F211E7B1FF: removed
Mar 7 08:22:27 [amavis] (28309-01-180) ESMTP::10024
/var/run/amavis/tmp/amavis-20080307T081750-28309:
<vision1aoaforums.com> -> <jeffvision1media.com> SIZE=599 Received:
from aoaforums.com ([127.0.0.1]) by localhost (aoaforums.com
[127.0.0.1]) (amavisd-new, port 10024) with ESMTP for
<jeffvision1media.com>; Fri, 7 Mar 2008 08:22:27 -0600 (CST)
Mar 7 08:22:27 [postfix/virtual] CFF9A2CAE4:
to=<postmasteraoaforums.com>, relay=virtual, delay=0.04,
delays=0.02/0/0/0.03, dsn=5.1.1, status=bounced (unknown user:
"postmasteraoaforums.com")
Mar 7 08:22:27 [amavis] (28309-01-180) Checking: Vlp47ay4olH6
<vision1aoaforums.com> -> <jeffvision1media.com>
Mar 7 08:22:27 [amavis] (28309-01-180) p001 1 Content-Type: text/html,
size: 162 B, name:
Mar 7 08:22:27 [postfix/cleanup] E13772CAE8:
message-id=<20080307142227.E13772CAE8aoaforums.com>
Mar 7 08:22:27 [amavis] (28309-01-180) check_header: 3, Improper use of
control character (char 0D hex): MIME_Version: 1.0\\r\\n
Mar 7 08:22:27 [amavis] (28309-01-180) check_header: 3, Improper use of
control character (char 0D hex): Content-type: text/html;
charset=iso-8859-1\\r\\n
Mar 7 08:22:27 [amavis] (28309-01-180) check_header: 3, Improper use of
control character (char 0D hex): Sender: vision1mediavision1media.com\\r\\n
Mar 7 08:22:27 [amavis] (28309-01-180) check_header: 3, Improper use of
control character (char 0D hex): From: Vision1Media
<vision1mediavision1media.com>\\r\\n
Mar 7 08:22:27 [postfix/bounce] CFF9A2CAE4: sender non-delivery
notification: E13772CAE8
Mar 7 08:22:27 [postfix/qmgr] E13772CAE8: from=<>, size=3253, nrcpt=1
(queue active)
Mar 7 08:22:27 [postfix/qmgr] CFF9A2CAE4: removed
Mar 7 08:22:28 [postfix/pickup] 0325D2CAE4: uid=1011 from=<vision1>
Mar 7 08:22:28 [postfix/cleanup] 0325D2CAE4:
message-id=<20080307142228.0325D2CAE4aoaforums.com>
Mar 7 08:22:28 [postfix/qmgr] 0325D2CAE4: from=<vision1aoaforums.com>,
size=598, nrcpt=1 (queue active)
Mar 7 08:22:28 [postfix/pickup] 0B541301DE: uid=1011 from=<vision1>
Mar 7 08:22:28 [postfix/cleanup] 0B541301DE:
message-id=<20080307142228.0B541301DEaoaforums.com>
Mar 7 08:22:28 [postfix/pipe] E13772CAE8: to=<vision1aoaforums.com>,
relay=v1m, delay=0.16, delays=0.05/0/0/0.11, dsn=2.0.0, status=sent
(delivered via v1m service)
Mar 7 08:22:28 [postfix/qmgr] E13772CAE8: removed
Mar 7 08:22:28 [postfix/qmgr] 0B541301DE: from=<vision1aoaforums.com>,
size=599, nrcpt=1 (queue active)
Mar 7 08:22:28 [amavis] (28309-01-180) local delivery: <> ->
<bad-header-quarantine>, mbx=/var/virusmails/badh-Vlp47ay4olH6
Mar 7 08:22:28 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:28 [postfix/smtpd] 717293004F: client=localhost[127.0.0.1]
Mar 7 08:22:28 [postfix/cleanup] 717293004F:
message-id=<20080307140551.BFC0ECAC9Baoaforums.com>
Mar 7 08:22:28 [postfix/smtpd] disconnect from localhost[127.0.0.1]
Mar 7 08:22:28 [postfix/qmgr] 717293004F: from=<vision1aoaforums.com>,
size=1195, nrcpt=1 (queue active)
Mar 7 08:22:28 [amavis] (28309-01-180) FWD via SMTP:
<vision1aoaforums.com> -> <jeffvision1media.com>,BODY=7BIT 250 2.6.0
Ok, id=28309-01-180, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued
as 717293004F
Mar 7 08:22:28 [amavis] (28309-01-180) Passed BAD-HEADER,
<vision1aoaforums.com> -> <jeffvision1media.com>, quarantine:
badh-Vlp47ay4olH6, Message-ID:
<20080307140551.BFC0ECAC9Baoaforums.com>, mail_id: Vlp47ay4olH6, Hits:
0.633, size: 598, queued_as: 717293004F, 614 ms
Mar 7 08:22:28 [amavis] (28309-01-180) Passed, <vision1aoaforums.com>
-> <jeffvision1media.com>, quarantine Vlp47ay4olH6, Message-ID:
<20080307140551.BFC0ECAC9Baoaforums.com>, Hits: 0.633
Mar 7 14:22:28 [postfix/smtp] BFC0ECAC9B: to=<jeffvision1media.com>,
relay=127.0.0.1[127.0.0.1]:10024, conn_use=180, delay=997,
delays=0.12/996/0/0.62, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as
717293004F)
Mar 7 08:22:28 [postfix/qmgr] BFC0ECAC9B: removed
Mar 7 08:22:28 [amavis] (28309-01-180) TIMING [total 616 ms] - SMTP
pre-DATA-flush: 1 (0%)0, SMTP DATA: 39 (6%)7, check_init: 0 (0%)7,
digest_hdr: 0 (0%)7, digest_body: 0 (0%)7, gen_mail_id: 0 (0%)7,
mime_decode: 3 (0%)7, get-file-type1: 6 (1%)8, decompose_part: 0 (0%)8,
parts_decode: 0 (0%)8, check_header: 1 (0%)8, AV-scan-1: 1 (0%)9,
AV-scan-2: 51 (8%)17, spam-wb-list: 1 (0%)17, SA parse: 1 (0%)17, SA
check: 473 (77%)94, update_cache: 3 (0%)94, decide_mail_destiny: 1
(0%)95, open-mbx: 3 (0%)95, write-header: 0 (0%)95,
save-to-local-mailbox: 0 (0%)95, fwd-connect: 2 (0%)95, fwd-mail-pip: 1
(0%)96, fwd-rcpt-pip: 0 (0%)96, fwd-data-chkpnt: 0 (0%)96, write-header:
0 (0%)96, fwd-data-contents: 0 (0%)96, fwd-end-chkpnt: 21 (3%)99,
prepare-dsn: 0 (0%)99, main_log_entry: 5 (1%)100, SMTP pre-response: 0
(0%)100, SMTP response: 0 (0%)100, unlink-1-files: 0 (0%)100, rundown: 0
(0%)100
Mar 7 08:22:28 [amavis] (28309-01-181) ESMTP::10024
/var/run/amavis/tmp/amavis-20080307T081750-28309:
<vision1aoaforums.com> -> <jeffvision1media.com> SIZE=599 Received:
from aoaforums.com ([127.0.0.1]) by localhost (aoaforums.com
[127.0.0.1]) (amavisd-new, port 10024) with ESMTP for
<jeffvision1media.com>; Fri, 7 Mar 2008 08:22:28 -0600 (CST)
Mar 7 08:22:28 [postfix/virtual] 717293004F:
to=<jeffvision1media.com>, relay=virtual, delay=0.03,
delays=0.02/0/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)
Mar 7 08:22:28 [postfix/qmgr] 717293004F: removed
Mar 7 08:22:28 [amavis] (28309-01-181) Checking: Bjrigjkx74hz
<vision1aoaforums.com> -> <jeffvision1media.com>
Mar 7 08:22:28 [amavis] (28309-01-181) p001 1 Content-Type: text/html,
size: 162 B, name:
Mar 7 08:22:28 [amavis] (28309-01-181) check_header: 3, Improper use of
control character (char 0D hex): MIME_Version: 1.0\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-181) check_header: 3, Improper use of
control character (char 0D hex): Content-type: text/html;
charset=iso-8859-1\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-181) check_header: 3, Improper use of
control character (char 0D hex): Sender: vision1mediavision1media.com\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-181) check_header: 3, Improper use of
control character (char 0D hex): From: Vision1Media
<vision1mediavision1media.com>\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-181) local delivery: <> ->
<bad-header-quarantine>, mbx=/var/virusmails/badh-Bjrigjkx74hz
Mar 7 08:22:28 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:28 [postfix/smtpd] D9F2B3004F: client=localhost[127.0.0.1]
Mar 7 08:22:28 [postfix/cleanup] D9F2B3004F:
message-id=<20080307140551.C970BCAC9Caoaforums.com>
Mar 7 08:22:28 [postfix/smtpd] disconnect from localhost[127.0.0.1]
Mar 7 08:22:28 [postfix/qmgr] D9F2B3004F: from=<vision1aoaforums.com>,
size=1195, nrcpt=1 (queue active)
Mar 7 08:22:28 [amavis] (28309-01-181) FWD via SMTP:
<vision1aoaforums.com> -> <jeffvision1media.com>,BODY=7BIT 250 2.6.0
Ok, id=28309-01-181, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued
as D9F2B3004F
Mar 7 08:22:28 [amavis] (28309-01-181) Passed BAD-HEADER,
<vision1aoaforums.com> -> <jeffvision1media.com>, quarantine:
badh-Bjrigjkx74hz, Message-ID:
<20080307140551.C970BCAC9Caoaforums.com>, mail_id: Bjrigjkx74hz, Hits:
0.633, size: 598, queued_as: D9F2B3004F, 426 ms
Mar 7 08:22:28 [amavis] (28309-01-181) Passed, <vision1aoaforums.com>
-> <jeffvision1media.com>, quarantine Bjrigjkx74hz, Message-ID:
<20080307140551.C970BCAC9Caoaforums.com>, Hits: 0.633
Mar 7 14:22:28 [postfix/smtp] C970BCAC9C: to=<jeffvision1media.com>,
relay=127.0.0.1[127.0.0.1]:10024, conn_use=181, delay=997,
delays=0.11/997/0/0.43, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as
D9F2B3004F)
Mar 7 08:22:28 [postfix/qmgr] C970BCAC9C: removed
Mar 7 08:22:28 [amavis] (28309-01-181) TIMING [total 428 ms] - SMTP
pre-DATA-flush: 1 (0%)0, SMTP DATA: 33 (8%)8, check_init: 0 (0%)8,
digest_hdr: 0 (0%)8, digest_body: 0 (0%)8, gen_mail_id: 0 (0%)8,
mime_decode: 3 (1%)9, get-file-type1: 6 (1%)10, decompose_part: 0
(0%)10, parts_decode: 0 (0%)10, check_header: 1 (0%)11, AV-scan-1: 1
(0%)11, AV-scan-2: 52 (12%)23, spam-wb-list: 1 (0%)23, SA parse: 1
(0%)23, SA check: 291 (68%)91, update_cache: 3 (1%)92,
decide_mail_destiny: 1 (0%)92, open-mbx: 2 (1%)93, write-header: 0
(0%)93, save-to-local-mailbox: 0 (0%)93, fwd-connect: 3 (1%)93,
fwd-mail-pip: 1 (0%)94, fwd-rcpt-pip: 0 (0%)94, fwd-data-chkpnt: 0
(0%)94, write-header: 0 (0%)94, fwd-data-contents: 0 (0%)94,
fwd-end-chkpnt: 21 (5%)99, prepare-dsn: 1 (0%)99, main_log_entry: 5
(1%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100,
unlink-1-files: 0 (0%)100, rundown: 0 (0%)100
Mar 7 08:22:28 [amavis] (28309-01-182) ESMTP::10024
/var/run/amavis/tmp/amavis-20080307T081750-28309:
<vision1aoaforums.com> -> <postmasteraoaforums.com> SIZE=604 Received:
from aoaforums.com ([127.0.0.1]) by localhost (aoaforums.com
[127.0.0.1]) (amavisd-new, port 10024) with ESMTP for
<postmasteraoaforums.com>; Fri, 7 Mar 2008 08:22:28 -0600 (CST)
Mar 7 08:22:28 [postfix/virtual] D9F2B3004F:
to=<jeffvision1media.com>, relay=virtual, delay=0.05,
delays=0.02/0/0/0.02, dsn=2.0.0, status=sent (delivered to maildir)
Mar 7 08:22:28 [postfix/qmgr] D9F2B3004F: removed
Mar 7 08:22:28 [amavis] (28309-01-182) Checking: IJHkgliCm2Ia
<vision1aoaforums.com> -> <postmasteraoaforums.com>
Mar 7 08:22:28 [amavis] (28309-01-182) cached
2f133d05794bce2c6ce4779973e7f049 from <vision1aoaforums.com> (1,0)
Mar 7 08:22:28 [amavis] (28309-01-182) p001 1 Content-Type: text/html,
size: 139 B, name:
Mar 7 08:22:28 [amavis] (28309-01-182) check_header: 3, Improper use of
control character (char 0D hex): MIME_Version: 1.0\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-182) check_header: 3, Improper use of
control character (char 0D hex): Content-type: text/html;
charset=iso-8859-1\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-182) check_header: 3, Improper use of
control character (char 0D hex): Sender: vision1mediavision1media.com\\r\\n
Mar 7 08:22:28 [amavis] (28309-01-182) check_header: 3, Improper use of
control character (char 0D hex): From: Vision1Media
<vision1mediavision1media.com>\\r\\n
Mar 7 08:22:29 [amavis] (28309-01-182) local delivery: <> ->
<bad-header-quarantine>, mbx=/var/virusmails/badh-IJHkgliCm2Ia
Mar 7 08:22:29 [amavis] (28309-01-182) SPAM-TAG,
<vision1aoaforums.com> -> <postmasteraoaforums.com>, No, score=0.633
required=5 tests=[AWL=-0.371, BAYES_05=-1.11, HTML_MESSAGE=0.001,
HTML_MIME_NO_HTML_TAG=0.097, MIME_HEADER_CTYPE_ONLY=0.56,
MIME_HTML_ONLY=1.457, NO_RELAYS=-0.001]
Mar 7 08:22:29 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:29 [postfix/smtpd] 33F0A31430: client=localhost[127.0.0.1]
Mar 7 08:22:29 [postfix/cleanup] 33F0A31430:
message-id=<20080307140552.16E127641Eaoaforums.com>
Mar 7 08:22:29 [postfix/qmgr] 04233507ED:
from=<???????????|radio1navigator.lv>, size=39783, nrcpt=1 (queue active)
Mar 7 08:22:29 [postfix/smtpd] disconnect from localhost[127.0.0.1]
Mar 7 08:22:29 [postfix/qmgr] 33F0A31430: from=<vision1aoaforums.com>,
size=1463, nrcpt=1 (queue active)
Mar 7 08:22:29 [amavis] (28309-01-182) FWD via SMTP:
<vision1aoaforums.com> -> <postmasteraoaforums.com>,BODY=7BIT 250
2.6.0 Ok, id=28309-01-182, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok:
queued as 33F0A31430
Mar 7 08:22:29 [amavis] (28309-01-182) Passed BAD-HEADER,
<vision1aoaforums.com> -> <postmasteraoaforums.com>, quarantine:
badh-IJHkgliCm2Ia, Message-ID:
<20080307140552.16E127641Eaoaforums.com>, mail_id: IJHkgliCm2Ia, Hits:
0.633, size: 603, queued_as: 33F0A31430, 346 ms
Mar 7 08:22:29 [amavis] (28309-01-182) Passed, <vision1aoaforums.com>
-> <postmasteraoaforums.com>, quarantine IJHkgliCm2Ia, Message-ID:
<20080307140552.16E127641Eaoaforums.com>, Hits: 0.633
Mar 7 14:22:29 [postfix/smtp] 16E127641E:
to=<postmasteraoaforums.com>, relay=127.0.0.1[127.0.0.1]:10024,
conn_use=182, delay=997, delays=0.1/997/0/0.35, dsn=2.0.0, status=sent
(250 2.0.0 Ok: queued as 33F0A31430)
Mar 7 08:22:29 [amavis] (28309-01-182) TIMING [total 348 ms] - SMTP
pre-DATA-flush: 1 (0%)0, SMTP DATA: 34 (10%)10, check_init: 0 (0%)10,
digest_hdr: 0 (0%)10, digest_body: 0 (0%)10, gen_mail_id: 0 (0%)10,
mime_decode: 3 (1%)11, get-file-type1: 6 (2%)13, decompose_part: 0
(0%)13, parts_decode: 0 (0%)13, check_header: 1 (0%)14, spam-wb-list: 1
(0%)14, SA parse: 1 (0%)14, SA check: 232 (67%)81, update_cache: 3
(1%)82, decide_mail_destiny: 1 (0%)82, open-mbx: 2 (1%)83, write-header:
0 (0%)83, save-to-local-mailbox: 0 (0%)83, fwd-connect: 3 (1%)84,
fwd-mail-pip: 1 (0%)84, fwd-rcpt-pip: 0 (0%)84, fwd-data-chkpnt: 0
(0%)84, write-header: 0 (0%)84, fwd-data-contents: 0 (0%)84,
fwd-end-chkpnt: 50 (14%)98, prepare-dsn: 1 (0%)98, main_log_entry: 5
(1%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100,
unlink-1-files: 0 (0%)100, rundown: 0 (0%)100
Mar 7 08:22:29 [postfix/cleanup] warning: mysql query failed: Illegal
mix of collations (latin1_swedish_ci,IMPLICIT) and
(utf8_general_ci,COERCIBLE) for operation '='
Mar 7 08:22:29 [postfix/cleanup] warning: 4029031438:
virtual_alias_maps map lookup problem for ???????????|radio1navigator.lv
Mar 7 08:22:29 [postfix/qmgr] 4DD982F03C:
from=<Tannh?userbonnetbonbon.net>, size=6580, nrcpt=1 (queue active)
Mar 7 08:22:29 [postfix/qmgr] 16E127641E: removed
Mar 7 08:22:29 [postfix/qmgr] 04233507ED: status=deferred (bounce failed)
Mar 7 08:22:29 [postfix/qmgr] 04233507ED:
from=<???????????|radio1navigator.lv>, status=expired, returned to sender
Mar 7 08:22:29 [postfix/cleanup] warning: mysql query failed: Illegal
mix of collations (latin1_swedish_ci,IMPLICIT) and
(utf8_general_ci,COERCIBLE) for operation '='
Mar 7 08:22:29 [postfix/cleanup] warning: 501CBA4071:
virtual_alias_maps map lookup problem for Tannh?userbonnetbonbon.net
Mar 7 08:22:29 [postfix/cleanup] warning: 58B70A407B:
virtual_alias_maps map lookup problem for ???????????|radio1navigator.lv
Mar 7 08:22:29 [postfix/qmgr] 90DE39F16E:
from=<???????|rina24pochta.ru>, size=39773, nrcpt=1 (queue active)
Mar 7 08:22:29 [postfix/qmgr] 4DD982F03C: status=deferred (bounce failed)
Mar 7 08:22:29 [postfix/qmgr] 4DD982F03C:
from=<Tannh?userbonnetbonbon.net>, status=expired, returned to sender
Mar 7 08:22:29 [postfix/qmgr] 04233507ED: status=deferred (bounce failed)
Mar 7 08:22:29 [postfix/cleanup] warning: 60500BCC6D:
virtual_alias_maps map lookup problem for Tannh?userbonnetbonbon.net
Mar 7 08:22:29 [amavis] (28309-01-183) ESMTP::10024
/var/run/amavis/tmp/amavis-20080307T081750-28309:
<vision1aoaforums.com> -> <jeffvision1media.com> SIZE=609 Received:
from aoaforums.com ([127.0.0.1]) by localhost (aoaforums.com
[127.0.0.1]) (amavisd-new, port 10024) with ESMTP for
<jeffvision1media.com>; Fri, 7 Mar 2008 08:22:29 -0600 (CST)
Mar 7 08:22:29 [postfix/cleanup] warning: 60445A4071:
virtual_alias_maps map lookup problem for ???????|rina24pochta.ru
Mar 7 08:22:29 [amavis] (28309-01-183) Checking: 4e7ezodC1Kju
<vision1aoaforums.com> -> <jeffvision1media.com>
Mar 7 08:22:29 [postfix/qmgr] ED0118602F:
from=<webmasteraoaforums.com>, size=1156, nrcpt=1 (queue active)
Mar 7 08:22:29 [amavis] (28309-01-183) p001 1 Content-Type: text/html,
size: 172 B, name:
Mar 7 08:22:29 [postfix/qmgr] 90DE39F16E: status=deferred (bounce failed)
Mar 7 08:22:29 [postfix/qmgr] 90DE39F16E:
from=<???????|rina24pochta.ru>, status=expired, returned to sender
Mar 7 08:22:29 [postfix/qmgr] 4DD982F03C: status=deferred (bounce failed)
Mar 7 08:22:29 [postfix/cleanup] warning: 6BC449D29F:
virtual_alias_maps map lookup problem for ???????|rina24pochta.ru
Mar 7 08:22:29 [postfix/qmgr] 90DE39F16E: status=deferred (bounce failed)
Mar 7 08:22:29 [postfix/virtual] 33F0A31430:
to=<postmasteraoaforums.com>, relay=virtual, delay=0.23,
delays=0.05/0.06/0/0.12, dsn=5.1.1, status=bounced (unknown user:
"postmasteraoaforums.com")
Mar 7 08:22:29 [postfix/cleanup] warning: 6D0D99D2A7:
virtual_alias_maps map lookup problem for vision1aoaforums.com
Mar 7 08:22:29 [postfix/qmgr] 33F0A31430: status=deferred (bounce failed)
Mar 7 08:22:29 [amavis] (28309-01-183) check_header: 3, Improper use of
control character (char 0D hex): MIME_Version: 1.0\\r\\n
Mar 7 08:22:29 [amavis] (28309-01-183) check_header: 3, Improper use of
control character (char 0D hex): Content-type: text/html;
charset=iso-8859-1\\r\\n
Mar 7 08:22:29 [amavis] (28309-01-183) check_header: 3, Improper use of
control character (char 0D hex): Sender: vision1mediavision1media.com\\r\\n
Mar 7 08:22:29 [amavis] (28309-01-183) check_header: 3, Improper use of
control character (char 0D hex): From: Vision1Media
<vision1mediavision1media.com>\\r\\n
Mar 7 08:22:29 [postfix/smtp] connect to
smyrnacable.net[66.116.125.128]: Connection refused (port 25)
Mar 7 08:22:29 [postfix/smtp] ED0118602F: to=<dabhprsmyrnacable.net>,
relay=none, delay=29793, delays=29792/0.04/0.12/0, dsn=4.4.1,
status=deferred (connect to smyrnacable.net[66.116.125.128]: Connection
refused)
Mar 7 08:22:29 [amavis] (28309-01-183) local delivery: <> ->
<bad-header-quarantine>, mbx=/var/virusmails/badh-4e7ezodC1Kju
Mar 7 08:22:29 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:29 [postfix/smtpd] CA6F29D2A7: client=localhost[127.0.0.1]
Mar 7 08:22:29 [postfix/cleanup] warning: CA6F29D2A7:
virtual_alias_maps map lookup problem for jeffvision1media.com
Mar 7 08:22:30 [amavis] (28294-01-195) local delivery: <> ->
<bad-header-quarantine>, mbx=/var/virusmails/badh-6wc4lo5KwjtX
Mar 7 08:22:30 [amavis] (28294-01-195) SPAM-TAG,
<vision1aoaforums.com> -> <MAILER-DAEMONaoaforums.com>, No,
score=-0.112 required=5 tests=[AWL=0.373, BAYES_00=-2.599,
HTML_MESSAGE=0.001, HTML_MIME_NO_HTML_TAG=0.097,
MIME_HEADER_CTYPE_ONLY=0.56, MIME_HTML_ONLY=1.457, NO_RELAYS=-0.001]
Mar 7 08:22:30 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:30 [postfix/smtpd] NOQUEUE: reject: RCPT from
localhost[127.0.0.1]: 550 5.1.1 <MAILER-DAEMONaoaforums.com>: Recipient
address rejected: User unknown; from=<vision1aoaforums.com>
to=<MAILER-DAEMONaoaforums.com> proto=ESMTP helo=<localhost>
Mar 7 08:22:30 [amavis] (28294-01-195) smtp resp to RCPT (pip)
(<MAILER-DAEMONaoaforums.com>): 550 5.1.1 Failed, id=28294-01-195, from
MTA([127.0.0.1]:10025): 550 5.1.1 <MAILER-DAEMONaoaforums.com>:
Recipient address rejected: User unknown
Mar 7 08:22:30 [amavis] (28294-01-195) Negative SMTP resp to DATA: 554
5.5.1 Error: no valid recipients
Mar 7 08:22:30 [postfix/smtpd] disconnect from localhost[127.0.0.1]
Mar 7 08:22:30 [amavis] (28294-01-195) (!)FWD via SMTP:
<vision1aoaforums.com> -> <MAILER-DAEMONaoaforums.com>,BODY=7BIT 550
5.6.0 Failed, id=28294-01-195, from MTA([127.0.0.1]:10025): 550 5.1.1
Failed, id=28294-01-195, from MTA([127.0.0.1]:10025): 550 5.1.1
<MAILER-DAEMONaoaforums.com>: Recipient address rejected: User unknown
Mar 7 08:22:30 [amavis] (28294-01-195) DSN: NOTIFICATION:
Action:failed, RELAYED 550 MTA-Rejected, <vision1aoaforums.com> ->
<MAILER-DAEMONaoaforums.com>
Mar 7 08:22:30 [postfix/smtpd] connect from localhost[127.0.0.1]
Mar 7 08:22:30 [postfix/smtpd] 602A5AF04C: client=localhost[127.0.0.1]
Mar 7 08:22:30 [postfix/cleanup] warning: 602A5AF04C:
virtual_alias_maps map lookup problem for vision1aoaforums.com
Mar 7 08:22:38 [postfix/smtpd] warning: 121.246.32.146: address not
listed for hostname 121.246.32.146.dynamic-pune.vsnl.net.in
Mar 7 08:22:38 [postfix/smtpd] connect from unknown[121.246.32.146]
Mar 7 08:23:11 [postfix/smtpd] connect from unknown[58.47.34.164]
Mar 7 08:23:23 [postfix/postfix-script] stopping the Postfix mail system
Mar 7 08:23:23 [postfix/master] terminating on signal 15
Mar 7 08:23:23 [amavis] (28309-01-183) smtp resp to MAIL (pip):
Mar 7 08:23:23 [amavis] (28309-01-183) Negative SMTP resp to DATA:
Mar 7 08:23:23 [amavis] (28309-01-183) Negative SMTP resp. to QUIT:
Mar 7 08:23:23 [amavis] (28309-01-183) (!)FWD via SMTP:
<vision1aoaforums.com> -> <jeffvision1media.com>,BODY=7BIT
Mar 7 08:23:23 [amavis] (28309-01-183) (!!)TROUBLE in check_mail, but
must continue (1): delivery-notification FAILED: Assert failed: 0, 2,
at /usr/sbin/amavisd line 6848, <GEN8> line 10434.
Mar 7 08:23:23 [amavis] (28294-01-195) smtp resp to MAIL (pip):
Mar 7 08:23:23 [amavis] (28294-01-195) Negative SMTP resp to DATA:
Mar 7 08:23:23 [amavis] (28294-01-195) Negative SMTP resp. to QUIT:
Mar 7 08:23:23 [amavis] (28294-01-195) (!)SEND via SMTP: <> ->
<vision1aoaforums.com>,ENVID=AM..20080307T142230Zaoaforums.com
Mar 7 08:23:23 [amavis] (28294-01-195) (!!)TROUBLE in check_mail, but
must continue (1): delivery-notification FAILED: temporarily unable to
send DSN to <vision1aoaforums.com>: 451 4.5.0 Bad SMTP response code???
"" at /usr/sbin/amavisd line 9389, <GEN8> line 10757.
Mar 7 08:23:23 [amavis] (28294-01-195) (!)PRESERVING EVIDENCE in
/var/run/amavis/tmp/amavis-2008

Here is postconf -n
alias_database = hash:/etc/mail/aliases
alias_maps = mysql:/etc/postfix/mysql-aliases.cf
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:127.0.0.1:10024
daemon_directory = /usr/lib/postfix
home_mailbox = .maildir/
html_directory = /usr/share/doc/postfix-2.4.6-r2/html
inet_interfaces = all
local_recipient_maps = $alias_maps $virtual_mailbox_maps unix:passwd.byname
local_transport = local
mail_owner = postfix
mailbox_command_maps = mysql:/etc/postfix/mysql-mailbox-commands.cf
mailbox_size_limit = 100000000
mailq_path = /usr/bin/mailq
manpage_directory = /usr/share/man
message_size_limit = 50000000
mydestination = localhost
mydomain = aoaforums.com
myhostname = aoaforums.com
mynetworks = 209.85.27.5/32, 127.0.0.0/8
newaliases_path = /usr/bin/newaliases
queue_directory = /var/spool/postfix
readme_directory = /usr/share/doc/postfix-2.3.6/readme
relocated_maps = mysql:/etc/postfix/mysql-relocated.cf
sample_directory = /etc/postfix
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
show_user_unknown_table_name = no
smtp_tls_note_starttls_offer = yes
smtp_tls_session_cache_database =
btree:/var/spool/postfix/smtp_tls_session_cache
smtpd_etrn_restrictions = permit_mynetworks, permit_tls_clientcerts,
reject_unauth_destination reject_unauth_destination,
reject_invalid_hostname,
        reject_unauth_pipelining, reject_non_fqdn_sender,
reject_unknown_sender_domain, reject_non_fqdn_recipient,
reject_unknown_recipient_domaincheck_policy_service inet:127.0.0.1:10030
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, permit_tls_clientcerts,
reject_non_fqdn_helo_hostname, reject_invalid_helo_hostname,
reject_unauth_pipelining, permit
smtpd_recipient_restrictions = permit_mynetworks,
permit_tls_clientcerts,reject_unauth_destination
reject_unauth_destination, reject_invalid_hostname,
reject_unauth_pipelining, reject_non_fqdn_sender,
reject_unknown_sender_domain, reject_non_fqdn_recipient,
reject_unknown_recipient_domain check_policy_service inet:127.0.0.1:10030
smtpd_tls_CApath = /etc/ssl/certs
smtpd_tls_cert_file = /etc/postfix/postfix.crt
smtpd_tls_key_file = /etc/postfix/postfix.key
smtpd_tls_security_level = may
smtpd_tls_session_cache_database =
btree:/var/spool/postfix/smtpd_tls_session_cache
strict_rfc821_envelopes = yes
transport_maps = mysql:/etc/postfix/mysql-transport.cf
unknown_local_recipient_reject_code = 550
virtual_alias_maps = mysql:/etc/postfix/mysql-virtual.cf
virtual_gid_maps = static:100
virtual_mailbox_base = /
virtual_mailbox_domains = mysql:/etc/postfix/mysql-transport.cf
virtual_mailbox_maps = mysql:/etc/postfix/mysql-virtual-maps.cf
virtual_minimum_uid = 1000
virtual_uid_maps = static:1006

Here's my master.cf
smtp inet n - n - - smtpd
466 inet n - n - - smtpd
  -o smtpd_tls_security_level=encrypt
  -o smtpd_tls_req_ccert=yes
  -o relay_clientcerts=mysql:/etc/postfix/mysql-relay-clientcerts.cf
  -o smtpd_tls_req_ccert=yes
pickup fifo n - n 60 1 pickup
cleanup unix n - n - 0 cleanup
qmgr fifo n - n 300 1 qmgr
tlsmgr unix - - n 1000? 1 tlsmgr
rewrite unix - - n - - trivial-rewrite
bounce unix - - n - 0 bounce
defer unix - - n - 0 bounce
trace unix - - n - 0 bounce
verify unix - - n - 1 verify
flush unix n - n 1000? 0 flush
proxymap unix - - n - - proxymap
smtp unix - - n - - smtp
relay unix - - n - - smtp
        -o fallback_relay=
showq unix n - n - - showq
error unix - - n - - error
discard unix - - n - - discard
local unix - n n - - local
virtual unix - n n - - virtual
lmtp unix - - n - - lmtp
anvil unix - - n - 1 anvil
scache unix - - n - 1 scache
maildrop unix - n n - - pipe
  flags=DRhu user=vmail argv=/usr/local/bin/maildrop -d ${recipient}
old-cyrus unix - n n - - pipe
  flags=R user=cyrus argv=/usr/lib/cyrus/deliver -e -m ${extension} ${user}
cyrus unix - n n - - pipe
  flags=hu user=cyrus argv=/usr/lib/cyrus/deliver -e -r ${sender} -m
${extension} ${user}
virt-cyrus unix - n n - - pipe
  flags=hu user=cyrus argv=/usr/lib/cyrus/deliver -e -r ${sender} -m
${recipient} ${user}
uucp unix - n n - - pipe
  flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail
($recipient)
ifmail unix - n n - - pipe
  flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp unix - n n - - pipe
  flags=Fq. user=foo argv=/usr/local/sbin/bsmtp -f $sender $nexthop
$recipient
smtp-amavis unix - - y - 2 smtp
   -o smtp_data_done_timeout=1200
localhost:10025 inet n - n - - smtpd
   -o content_filter=
   -o mynetworks=127.0.0.0/8
   -o smtpd_milters=inet:127.0.0.1:10035
#Temporarilly disable this service
#v1m unix - n n - - pipe
# directory=/home/vmail/vision1media.com/vision1media user=vision1
argv=/usr/bin/php ./domessage.php

Any help would be greatly appreciated. Any other information you need,
just ask.