Hi:
As the subject says, I configure the postfix with the wrong smtp
transport and try to send a email with that transport using command as
following:
postsuper -H ALL; postfix flush; sleep 1; postsuper -h ALL;
In my thought, it couldn't be sent out with the wrong transport.
But when I repeat the command some times, the letter disappeared.
After I examine the maillog file, I find it's qmgr who delete the
file and so smtp report a error for the missing letter later.
I restart the smptd, clean-up, trivial-rewrite, qmgr, smtp with
-vvv option and find that qmgr processes the letter but doesn't send
it to smtp for I hold the letter. When it's released and flushed,
qmgr processes it twice, deletes the letter(I don't know why, Does
qmgr think all recipients have finished already?) and sends the two
same recipients to smtp process. Obviously, smtp fails to find the
letter and reports a error log.
Detailed info is as following, If some other info is required,
please notice me.
Thanks a lot.
Jun 5 11:29:38 mx postfix/smtpd[21495]: CCAC33008614: client=mx[127.0.0.1]
Jun 5 11:29:38 mx postfix/cleanup[21498]: CCAC33008614:
message-id=<20090605032938.ccac33008...@mx.helloworld.com.cn>
Jun 5 11:29:38 mx postfix/qmgr[21489]: scan_dir_next: found CCAC33008614
Jun 5 11:29:38 mx postfix/qmgr[21489]: qmgr_active_feed: incoming/CCAC33008614
Jun 5 11:29:38 mx postfix/qmgr[21489]: qmgr_message_alloc: active CCAC33008614
Jun 5 11:29:38 mx postfix/qmgr[21489]: CCAC33008614: recipient
limit 5000
Jun 5 11:29:38 mx postfix/qmgr[21489]: CCAC33008614:
from=<sen...@helloworld.com.cn>, size=546, nrcpt=1 (queue active)
Jun 5 11:29:38 mx postfix/qmgr[21489]: dir_forest: CCAC33008614 -> C/
Jun 5 11:30:07 mx postfix/qmgr[21489]: qmgr_peer_select: CCAC33008614
retry 4.4.1 delivery temporarily suspended: connect to
220.181.12.163[220.181.12.163]:25: Connection timed out (1 of 1)
Jun 5 11:30:07 mx postfix/qmgr[21489]: qmgr_job_retire: CCAC33008614
Jun 5 11:30:07 mx postfix/qmgr[21489]: send attr queue_id = CCAC33008614
Jun 5 11:30:07 mx postfix/error[21505]: input attribute value:
CCAC33008614
Jun 5 11:30:07 mx postfix/error[21505]: warning: open active
CCAC33008614: No such file or directory
Jun 5 11:30:07 mx postfix/qmgr[21489]: qmgr_active_done: CCAC33008614
Jun 5 11:30:07 mx postfix/qmgr[21489]: qmgr_job_free:
CCAC33008614 slow163
Jun 5 11:30:07 mx postfix/qmgr[21489]: qmgr_job_free: CCAC33008614 retry
Jun 5 11:33:31 mx postfix/postsuper[21577]: CCAC33008614:
released from hold
Jun 5 11:33:31 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:31 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:31 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:33:31 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:31 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:31 mx postfix/qmgr[21525]: CCAC33008614: recipient
limit 5000
Jun 5 11:33:31 mx postfix/qmgr[21525]: CCAC33008614:
from=<sen...@helloworld.com.cn>, size=546, nrcpt=1 (queue active)
Jun 5 11:33:31 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:31 mx postfix/qmgr[21525]: qmgr_peer_select: CCAC33008614
slow163 [220.181.12.163]:25 (1 of 1)
Jun 5 11:33:31 mx postfix/qmgr[21525]: qmgr_job_retire: CCAC33008614
Jun 5 11:33:31 mx postfix/qmgr[21525]: send attr queue_id = CCAC33008614
Jun 5 11:33:31 mx postfix/smtp[21582]: input attribute value:
CCAC33008614
Jun 5 11:33:31 mx postfix/smtp[21582]: deliver_request_get: file
active/CCAC33008614
Jun 5 11:33:32 mx postfix/postsuper[21583]: CCAC33008614: placed on hold
Jun 5 11:33:32 mx postfix/postsuper[21584]: CCAC33008614:
released from hold
Jun 5 11:33:32 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:32 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:32 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:33:32 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:32 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:32 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:32 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:32 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:43 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:43 mx postfix/qmgr[21525]: qmgr_active_feed:
incoming/CCAC33008614
Jun 5 11:33:43 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:43 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:43 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:43 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:44 mx postfix/postsuper[21592]: CCAC33008614: placed on hold
Jun 5 11:33:44 mx postfix/postsuper[21593]: CCAC33008614:
released from hold
Jun 5 11:33:44 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:44 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:44 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:33:44 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:44 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:44 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:44 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:44 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:50 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:50 mx postfix/qmgr[21525]: qmgr_active_feed:
incoming/CCAC33008614
Jun 5 11:33:50 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:50 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:50 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:50 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:51 mx postfix/postsuper[21601]: CCAC33008614: placed on hold
Jun 5 11:33:51 mx postfix/postsuper[21602]: CCAC33008614:
released from hold
Jun 5 11:33:51 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:51 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:51 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:33:51 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:51 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:51 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:51 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:51 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:54 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:54 mx postfix/qmgr[21525]: qmgr_active_feed:
incoming/CCAC33008614
Jun 5 11:33:54 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:54 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:54 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:54 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:55 mx postfix/postsuper[21610]: CCAC33008614: placed on hold
Jun 5 11:33:55 mx postfix/postsuper[21611]: CCAC33008614:
released from hold
Jun 5 11:33:55 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:55 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:55 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:33:55 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:55 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:55 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:55 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:55 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:58 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:58 mx postfix/qmgr[21525]: qmgr_active_feed:
incoming/CCAC33008614
Jun 5 11:33:58 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:58 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:58 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:58 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:33:59 mx postfix/postsuper[21619]: CCAC33008614: placed on hold
Jun 5 11:33:59 mx postfix/postsuper[21620]: CCAC33008614:
released from hold
Jun 5 11:33:59 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:33:59 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:59 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:33:59 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:33:59 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:33:59 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:33:59 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:33:59 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_active_feed:
incoming/CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: CCAC33008614: skipped, still
being delivered
Jun 5 11:34:01 mx postfix/qmgr[21525]: wakeup CCAC33008614 after 60 secs
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_active_defer:
defer CCAC33008614
Jun 5 11:34:01 mx postfix/smtp[21582]: send attr queue_id = CCAC33008614
Jun 5 11:34:01 mx postfix/smtp[21582]: CCAC33008614:
to=<aa...@163.com>, relay=none, delay=263, delays=233/0.12/30/0,
dsn=4.4.1, status=deferred (connect to
220.181.12.163[220.181.12.163]:25: Connection timed out)
Jun 5 11:34:01 mx postfix/smtp[21582]: flush_add: site 163.com
id CCAC33008614
Jun 5 11:34:01 mx postfix/smtp[21582]: flush_add: site 163.com id
CCAC33008614 status 4
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_active_done: CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_job_free:
CCAC33008614 slow163
Jun 5 11:34:01 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_active_feed:
incoming/CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:34:01 mx postfix/qmgr[21525]: CCAC33008614: recipient
limit 5000
Jun 5 11:34:01 mx postfix/qmgr[21525]: CCAC33008614:
from=<sen...@helloworld.com.cn>, size=546, nrcpt=1 (queue active)
Jun 5 11:34:01 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:34:02 mx postfix/postsuper[21631]: CCAC33008614: placed on hold
Jun 5 11:34:02 mx postfix/postsuper[21632]: CCAC33008614:
released from hold
Jun 5 11:34:02 mx postfix/qmgr[21525]: scan_dir_next: found CCAC33008614
Jun 5 11:34:02 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:34:02 mx postfix/qmgr[21525]: qmgr_active_feed:
deferred/C/CCAC33008614
Jun 5 11:34:02 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:34:02 mx postfix/qmgr[21525]: qmgr_message_alloc:
active CCAC33008614
Jun 5 11:34:02 mx postfix/qmgr[21525]: CCAC33008614: recipient
limit 5000
Jun 5 11:34:02 mx postfix/qmgr[21525]: CCAC33008614:
from=<sen...@helloworld.com.cn>, size=546, nrcpt=1 (queue active)
Jun 5 11:34:02 mx postfix/qmgr[21525]: dir_forest: CCAC33008614 -> C/
Jun 5 11:34:02 mx postfix/qmgr[21525]: qmgr_active_done: CCAC33008614
Jun 5 11:34:02 mx postfix/qmgr[21525]: CCAC33008614: removed
Jun 5 11:34:06 mx postfix/qmgr[21525]: qmgr_peer_select: CCAC33008614
slow163 [220.181.12.163]:25 (1 of 1)
Jun 5 11:34:06 mx postfix/qmgr[21525]: qmgr_job_retire: CCAC33008614
Jun 5 11:34:06 mx postfix/qmgr[21525]: send attr queue_id = CCAC33008614
Jun 5 11:34:06 mx postfix/smtp[21582]: input attribute value:
CCAC33008614
Jun 5 11:34:06 mx postfix/smtp[21582]: warning: open active
CCAC33008614: No such file or directory
Jun 5 11:34:06 mx postfix/qmgr[21525]: qmgr_active_done: CCAC33008614
Jun 5 11:34:06 mx postfix/qmgr[21525]: qmgr_job_free:
CCAC33008614 slow163
