After turning on recordio I was able to collect the following thread in the
log. I don't think it is telling us any more that before. It looks like it ends
successfully, but no email ever comes in.
2008-02-13 09:39:39.616490500 tcpserver: pid 633 from 207.5.72.226
2008-02-13 09:39:39.616698500 tcpserver: ok 633 qmail.ncbi.com:192.168.2.2:25
:207.5.72.226::21431
2008-02-13 09:39:39.670673500 633 > 220 qmail.ncbi.com - Welcome to Qmail
Toaster Ver. 1.4 SMTP Server ESMTP
2008-02-13 09:39:39.753246500 633 < EHLO EXHUB016-3.exch016.msoutlookonline.net
2008-02-13 09:39:39.753434500 633 > 250-qmail.ncbi.com - Welcome to Qmail
Toaster Ver. 1.4 SMTP Server
2008-02-13 09:39:39.753439500 633 > 250-STARTTLS
2008-02-13 09:39:39.753441500 633 > 250-PIPELINING
2008-02-13 09:39:39.753444500 633 > 250-8BITMIME
2008-02-13 09:39:39.753446500 633 > 250-SIZE 589299712
2008-02-13 09:39:39.753449500 633 > 250 AUTH LOGIN PLAIN CRAM-MD5
2008-02-13 09:39:39.834662500 633 < STARTTLS
2008-02-13 09:39:39.837111500 633 > 220 ready for tls
2008-02-13 09:39:39.916017500 633 <
2008-02-13 09:39:39.916022500 633 <
2008-02-13 09:39:39.917645500 633 >
2008-02-13 09:39:39.917654500 633 > NCB Management Services1
0 U
IT10U
mail.ncbi.com1"0+
2008-02-13 09:39:39.917658500 633 > *†H†÷
[EMAIL PROTECTED]
080205203652Z
090204203652Z0¡1
0 UUS10U Pennsylvania10U Trevose1 0 U
2008-02-13 09:39:39.917664500 633 > NCB Management Services1
0 U
IT10U
mail.ncbi.com1"0 *†H†÷
[EMAIL PROTECTED]
*†H†÷
2008-02-13 09:39:39.917690500 633 >
2008-02-13 09:39:39.917700500 633 > 0U Trevose1 0 U
2008-02-13 09:39:39.917717500 633 > NCB Management Services1
0 U
IT10U
mail.ncbi.com1"0 *†H†÷
[EMAIL PROTECTED]
2008-02-13 09:39:39.917858500 633 > ¯ž |ŽjÖkÎÜzEîìc*OïöÈ$K&XÊhòÔ
2008-02-13 09:39:40.248134500 633 <
2008-02-13 09:39:40.248141500 633 < ³Y±
2008-02-13 09:39:40.263867500 633 >
2008-02-13 09:39:40.343686500 633 <
2008-02-13 09:39:40.343914500 633 >
2008-02-13 09:39:40.423218500 633 <
2008-02-13 09:39:40.528547500 CHKUSER accepted sender: from <[EMAIL
PROTECTED]::> remote
<EXHUB016-3.exch016.msoutlookonline.net:unknown:207.5.72.226> rcpt <> : sender
accepted
2008-02-13 09:40:01.009272500 633 >
2008-02-13 09:40:01.092004500 633 <
2008-02-13 09:40:01.093085500 633 >
2008-02-13 09:40:01.093092500 633 > [EOF]
2008-02-13 09:40:01.093094500 tcpserver: end 633 status 0
From: Eric "Shubes" [mailto:[EMAIL PROTECTED]
Sent: Friday, January 25, 2008 11:24 PM
To: [email protected]
Subject: Re: [qmailtoaster] Delayed delivery
That would seem to me to indicate that the sender (exchange server) is finding
something it doesn't like, and is terminating the smtp session before sending,
or at least completing the message.
I'd try to determine from the exchange server side what the problem might be if
that's possible. That might not be feasible, and I honestly don't know much
about exchange server.
The only way I can think of to diagnose this from the qmail side would be to
turn on recordio during a time when you know a message is coming from that
server. recordio logs the details of the entire tcp (smtp in this case)
session, sort of like an strace logs each step of a program. It can create
quite a lot of log content in a relatively short time on a busy server, so you
probably don't want to leave it on for an extended period. It'd be best to
coordinate a test with someone at the sending domain. The recordio output (in
the standard smtp log) will tell you exactly what each side of the session says
to each other (i.e. who initiated the termination any why).
You can find examples of how to turn on recordio in the list archive.
Please let us know how things progress for you.
Raymond Webster wrote:
> and it's only 20 seconds later.
>
> -----Original Message-----
> From: Raymond Webster [mailto:[EMAIL PROTECTED]
> Sent: Friday, January 25, 2008 3:54 PM
> To: [email protected]
> Subject: RE: [qmailtoaster] Delayed delivery
>
> I did not see anything in the queue.
>
> I could not find the third handshake where we log a "accepted recpt : from"
> or the fourth log from simscan.
> I do see the end message with a status 0
>
> -----Original Message-----
> From: Eric "Shubes" [mailto:[EMAIL PROTECTED]
> Sent: Friday, January 25, 2008 1:35 PM
> To: [email protected]
> Subject: Re: [qmailtoaster] Delayed delivery
>
> grep won't show you everything that's in the log regarding a
> particular message. You need to look at all the messages adjacent to
> the one grep found. If you have qmailtoaster-plus installed (highly
> recommended), you can # qmlog -lc <IP> smtp That will put you into the
> log(s) at the point where it finds <IP>. You can then browse around
> from there and see what else is happening.
>
> All of the messages for a given (successful) email receipt will look
> something like this:
> 01-25 11:14:38 tcpserver: status: 1/100
> 01-25 11:14:38 tcpserver: pid 8223 from sender.i.p.address
> 01-25 11:14:38 tcpserver: ok 8223 qmhost:qmt.i.p.address:25
> :sender.i.p.address::34313
> 01-25 11:14:39 CHKUSER accepted sender: from
> <[EMAIL PROTECTED]::> remote
> <mta134.sender.domain.com:unknown:sender.i.p.address> rcpt <> : sender
> accepted
> 01-25 11:14:39 CHKUSER accepted rcpt: from
> <[EMAIL PROTECTED]::> remote
> <mta134.sender.domain.com:unknown:sender.i.p.address> rcpt
> <[EMAIL PROTECTED]> : found existing recipient
> 01-25 11:14:49 simscan:[8223]:CLEAN (-2.30/8.00):10.3207s:Email
> Subject:sender.i.p.address:[EMAIL PROTECTED]
> domain
> .com:[EMAIL PROTECTED]:
> 01-25 11:14:49 tcpserver: end 8223 status 0
> 01-25 11:14:49 tcpserver: status: 0/100
>
> I'm guessing that the delivery from exchange to qmail is unsuccessful.
> Do you see a
> tcpserver: end 16219 status 256
> ?
> What are the rest of the log messages for the email in question?
>
>
> P.S. I take it your toaster's queue is empty?
>
>
> Raymond Webster wrote:
>> This is what I found when greping for IP instead of domain name. I
>> did find four other instances of these exact lines at different times.
>> Should there be more communication with the outside server? If so is
>> it safe to say the delay message is from their side?
>>
>> 2008-01-24 16:34:50.326813500 tcpserver: pid 16219 from xxx.x.xx.xxx
>> 2008-01-24 16:34:50.326816500 tcpserver: ok 16219
>> qmail.ncbi.com:192.168.2.2:25 :xxx.x.xx.xxx::55690
>> 2008-01-24 16:34:50.871532500 CHKUSER accepted sender: from
>> <[EMAIL PROTECTED]::> remote
>> <EXHUB016-1.exch016.domain2.net:unknown:xxx.x.xx.xxx> rcpt <> :
>> sender accepted
>>
>> -----Original Message-----
>> From: Eric "Shubes" [mailto:[EMAIL PROTECTED]
>> Sent: Friday, January 25, 2008 11:37 AM
>> To: [email protected]
>> Subject: Re: [qmailtoaster] Delayed delivery
>>
>> Raymond Webster wrote:
>>> I have one outside client that cannot send mail to the toaster. He
>>> is sending from an Exchange2007 server. He gets a delayed delivery
>>> message to the email addresses he attempts so send within our domain.
>>>
>>> I have found this in the smtp log;
>>>
>>> CHKUSER accepted sender: from <[EMAIL PROTECTED] <mailto:[EMAIL
>>> PROTECTED]>::>
>>> remote <EXHUB016-1.exch016.domain.net:unknown:IPAddress> rcpt <> :
>>> sender accepted
>>>
>>> Why would this make his server report a delayed delivery?
>> This message is normal, and is a good thing.
>>
>> Can you tell if the delayed delivery message is initiated by the
>> qmail or change server?
>>
>> Is the message stuck in qmail queue? (I doubt it, but it's worth a
>> try) # qmailctl queue
>>
>> What are the rest of the messages in the smtp queue which correspond
>> to the one you've shown us? There should be more/others.
>>
>> --
>> -Eric 'shubes'
>>
--
-Eric 'shubes'
---------------------------------------------------------------------
QmailToaster hosted by: VR Hosted <http://www.vr.org>
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
---------------------------------------------------------------------
QmailToaster hosted by: VR Hosted <http://www.vr.org>
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
