Hi Folks
I have been working on this for a while now. It relates to a "sender
verify callout" failure when sending from Courier-MTA to a machine
mailhost.planetdomain.com running Exim. I captured some ethereal traces
on port 25 of the dialogue between the two machines, and initially
concluded that our machine was too slow in responding. However the
dialogue shows what appears to me to be very strange behaviours. I have
attached a typical dialogue below. 210.50.3.210 is the offending
machine. Missing lines are for unrelated transactions.
The dialogue proceeds down to line 38 as normal. Then another machine
210.50.196.49 takes over to perform a callout. This is a SYN/ACK
sequence, followed by silence for 30 seconds at which point the remote
machine decides Courier-MTA is not going to respond and terminates the
dialogue. Then Courier-MTA responds, exactly 30.009 seconds after the
SYN/ACK sequence. This is not a coincidence, I have checked a few other
transactions and found that Courier responds immediately after the
remote machine starts to terminate, and very close to 30 seconds after
the SYN/ACK sequence, as if it were waiting for something else from the
remote machine.
The thing that really puzzles me is that on a normal dialogue for
incoming mail, Courier-MTA responds quite quickly, around 0.1 seconds
after the SYN/ACK sequence. If Courier-MTA is really holding off during
a callout, why would it distimguish between the callout (from another IP
address) and a normal incoming mail.
Can someone enlighten me about this please. There is something I am
missing here. Could there be transactions on other ports, or DNS lookups
that I have not captured?
cheers, Ken Sarkies
# tethereal -w tcpdump.14 -f 'port 25'
# tethereal -t a -r tcpdump.14
22 15:31:51.260527 192.168.1.2 -> 210.50.3.210 TCP 38039 > smtp [SYN]
Seq=0 Ack=0 Win=5840 Len=0 MSS=1460 TSV=541916666 TSER=0 WS=2
23 15:31:51.301861 210.50.3.210 -> 192.168.1.2 TCP smtp > 38039 [SYN,
ACK] Seq=0 Ack=1 Win=5792 Len=0 MSS=1460 TSV=181986792 TSER=541916666 WS=0
24 15:31:51.301931 192.168.1.2 -> 210.50.3.210 TCP 38039 > smtp [ACK]
Seq=1 Ack=1 Win=5840 Len=0 TSV=541916707 TSER=181986792
30 15:32:01.333298 210.50.3.210 -> 192.168.1.2 SMTP Response: 220
yarra.planetdomain.com ESMTP Exim 4.50 Tue, 16 Aug 2005 16:01:58 +1000
31 15:32:01.333420 192.168.1.2 -> 210.50.3.210 TCP 38039 > smtp [ACK]
Seq=1 Ack=77 Win=5840 Len=0 TSV=541926741 TSER=181987795
32 15:32:01.333994 192.168.1.2 -> 210.50.3.210 SMTP Command: EHLO
mail.trinity.asn.au
33 15:32:01.372807 210.50.3.210 -> 192.168.1.2 TCP smtp > 38039 [ACK]
Seq=77 Ack=27 Win=5792 Len=0 TSV=181987799 TSER=541926742
34 15:32:01.377490 210.50.3.210 -> 192.168.1.2 SMTP Response:
250-yarra.planetdomain.com Hello eth6119.sa.adsl.internode.on.net
[150.101.232.230]
35 15:32:01.378126 192.168.1.2 -> 210.50.3.210 SMTP Command: MAIL
FROM:<[EMAIL PROTECTED]> SIZE=949
36 15:32:01.429483 210.50.3.210 -> 192.168.1.2 SMTP Response: 250 OK
37 15:32:01.429745 192.168.1.2 -> 210.50.3.210 SMTP Command: RCPT
TO:<[EMAIL PROTECTED]>
38 15:32:01.504612 210.50.3.210 -> 192.168.1.2 TCP smtp > 38039 [ACK]
Seq=199 Ack=106 Win=5792 Len=0 TSV=181987813 TSER=541926838
39 15:32:01.775235 210.50.196.49 -> 192.168.1.2 TCP 55410 > smtp
[SYN] Seq=0 Ack=0 Win=5840 Len=0 MSS=1460 TSV=181987839 TSER=0 WS=0
40 15:32:01.775341 192.168.1.2 -> 210.50.196.49 TCP smtp > 55410
[SYN, ACK] Seq=0 Ack=1 Win=5792 Len=0 MSS=1460 TSV=541927183
TSER=181987839 WS=2
41 15:32:01.808899 210.50.196.49 -> 192.168.1.2 TCP 55410 > smtp
[ACK] Seq=1 Ack=1 Win=5840 Len=0 TSV=181987843 TSER=541927183
42 15:32:31.806732 210.50.196.49 -> 192.168.1.2 TCP 55410 > smtp
[FIN, ACK] Seq=1 Ack=1 Win=5840 Len=0 TSV=181990843 TSER=541927183
43 15:32:31.807732 192.168.1.2 -> 210.50.196.49 TCP smtp > 55410
[ACK] Seq=1 Ack=2 Win=5792 Len=0 TSV=541957224 TSER=181990843
44 15:32:31.809601 210.50.3.210 -> 192.168.1.2 SMTP Response: 451
Could not complete sender verify callout
45 15:32:31.817001 192.168.1.2 -> 210.50.196.49 SMTP Response: 220
Courier-MTA, Holy Trinity Church Adelaide
46 15:32:31.817595 192.168.1.2 -> 210.50.196.49 TCP smtp > 55410
[FIN, ACK] Seq=48 Ack=2 Win=5792 Len=0 TSV=541957233
TSER=181990843
47 15:32:31.849727 192.168.1.2 -> 210.50.3.210 TCP 38039 > smtp [ACK]
Seq=106 Ack=245 Win=5840 Len=0 TSV=541957266 TSER=181990843
Sander Holthaus - Orange XL wrote:
[EMAIL PROTECTED] wrote:
Ken Sarkies writes:
Aug 8 08:36:40 hta21 courieresmtp:
id=0012ED09.42F5FD34.00000A25,from=<[EMAIL PROTECTED]>,a
ddr=<[EMAIL PROTECTED]>:
451 Could not complete sender verify callout
followed by deferred. There are no other related entries here or in
syslog. The recipient can mail us and knows of no other mailer that
has problems with his address. The recipient's domain is directed to
a machine mailhost.planetdomain.com managed by a large ISP (iPrimus),
who incidentally use other mailhosts for their subscribed user base.
I thought initially that the remote machine could not callout the
sender here. However if we mail the same person through MSX it goes
without a hitch. My dim understanding of sender verify callout is
that the remote machine tries to start up a dummy mail delivery to
the sender and aborts after authentication occurs. As port 25 is
forwarded to the Courier server, we should see the same problem
regardless of which mailer we use.
Is this maillog entry saying that Courier cannot get an
authentication for the user on the remote machine?
No, it means that when Courier sends the recipient's address
to the remote machine, the remote machine replies responds
with "451 Could not complete sender verify callout".
That's all that this log entry means. Not a thing more. Not a thing
less.
Why the remote machine sends this response is something that
only the remote machine's administrator can figure out.
Actually not in this case. I think this is a standard error message from
Exim, if the remote machine is configured to verify senders (e.g. callout or
dialout). If you are seeing this message in Courier's logs, it means that
Courier is trying to send an email with a sender that cannot be confirmed.
Why it cannot be confirmed can be for various reasons, but take a look a
close look at your logs and configuration.
What sort of tests can I use to track down the problem further? Is
there for example a way to change Courier's level of logging to see
the dialogue between the machines?
The above log entry tells you exactly how the dialogue went.
-------------------------------------------------------
SF.Net email is Sponsored by the Better Software Conference & EXPO
September 19-22, 2005 * San Francisco, CA * Development Lifecycle Practices
Agile & Plan-Driven Development * Managing Projects & Teams * Testing & QA
Security * Process Improvement & Measurement * http://www.sqe.com/bsce5sf
_______________________________________________
courier-users mailing list
[email protected]
Unsubscribe: https://lists.sourceforge.net/lists/listinfo/courier-users
