--
Margrit Lottmann wrote on <Friday 02 August 2002 19:08>:
> I have some lines in our log file , which I don't understand:
> 2002-08-01 17:25:08 SMTP call from hauptpostamt.charite.de
> [193.175.66.220] dropped: too many unrecognized commands
> nevertheless the message was delivered to the receiver, but the sender
> host repeats the delivery because there wasn't a regular end of the
> connection
From our side (Postfix), we observed the follwing:
With one particular mail being sent to Margrit's Mailserver (I stil
have that in my queue), Exim would always close the connection while
Postfix is still sending the mail data (after "DATA").
I then created a tcpdump (attached) which clearly shows that Exim
must have gone back to the command mode, but Postfix keeps sending
data and Exim barfs.
At least we have no firewall abominations like CISCO PIX or other crap
in the network path.
--
Ralf Hildebrandt (Im Auftrag des Referat V A) Ralf.Hildebrandt@???
Charite Campus Virchow-Klinikum Tel. +49 (0)30-450 570-155
Referat V A - Kommunikationsnetze - Fax. +49 (0)30-450 570-916
"Debugging is anticipated with distaste, performed with reluctance,
and bragged about forever."-Anon.
--
Aug 2 09:50:50 hauptpostamt postfix/smtp[9400]: warning: no MX host for qmx.net has a valid A record
Aug 2 09:50:50 hauptpostamt postfix/smtp[9400]: A2D0815C016: to=<kanten@???>, relay=none, delay=63098, status=deferred (Name service error for name=ICE.QAX.net type=A: Host not found, try again)
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 220 mail.uni-magdeburg.de - ESMTP (EXIM 3.36) ready at Fri, 02 Aug 2002 09:52:22 +0200
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: > mail.uni-magdeburg.de[141.44.1.10]: EHLO hauptpostamt.charite.de
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 250-mail.uni-magdeburg.de Hello hauptpostamt.charite.de [193.175.66.220]
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 250-SIZE 20971520
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 250-PIPELINING
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 250 HELP
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: server features: 0xd size 20971520
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: Using ESMTP PIPELINING, TCP send buffer size is 4096
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: lookup charite.de type 15 flags 0
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: dns_query: charite.de (MX): OK
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: dns_get_answer: type MX for charite.de
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: > mail.uni-magdeburg.de[141.44.1.10]: MAIL FROM:<stefan.juettner@???> SIZE=149850
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: lookup Medizin.Uni-Magdeburg.DE type 15 flags 0
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: dns_query: Medizin.Uni-Magdeburg.DE (MX): OK
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: dns_get_answer: type MX for Medizin.Uni-Magdeburg.DE
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: dns_get_answer: type MX for Medizin.Uni-Magdeburg.DE
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: > mail.uni-magdeburg.de[141.44.1.10]: RCPT TO:<Michael.Vieth@???>
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: > mail.uni-magdeburg.de[141.44.1.10]: DATA
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 250 <stefan.juettner@???> is syntactically correct
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 250 <Michael.Vieth@???> verified
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: < mail.uni-magdeburg.de[141.44.1.10]: 354 Enter message, ending with "." on a line by itself
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: multipart / mixed
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: boundary = ----=_NextPart_000_000C_01C23965.5C6EF190
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: PUSH boundary ----=_NextPart_000_000C_01C23965.5C6EF190
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: multipart / alternative
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: boundary = ----=_NextPart_001_000D_01C23965.5C6EF190
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: PUSH boundary ----=_NextPart_001_000D_01C23965.5C6EF190
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: text / plain
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: 8bit
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: text / html
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: quoted-printable
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: POP boundary ----=_NextPart_001_000D_01C23965.5C6EF190
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: application / msword
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: header_token: base64
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: smtp_fputs: EOF
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: POP boundary ----=_NextPart_000_000C_01C23965.5C6EF190
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: connect to subsystem private/defer
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr nrequest = 0
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr flags = 0
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr queue_id = 8342115C009
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr recipient = Michael.Vieth@???
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr reason = lost connection with mail.uni-magdeburg.de[141.44.1.10] while sending message body
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: private/defer socket: wanted attribute: status
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: input attribute name: status
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: input attribute value: 0
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: private/defer socket: wanted attribute: (list terminator)
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: input attribute name: (end)
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: 8342115C009: to=<Michael.Vieth@???>, relay=mail.uni-magdeburg.de[141.44.1.10], delay=70599, status=deferred (lost connection with mail.uni-magdeburg.de[141.44.1.10] while sending message body)
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: flush_add: site Medizin.Uni-Magdeburg.DE id 8342115C009
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: connect to subsystem public/flush
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr request = add
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr site = Medizin.Uni-Magdeburg.DE
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: send attr queue_id = 8342115C009
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: public/flush socket: wanted attribute: status
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: input attribute name: status
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: input attribute value: 4
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: public/flush socket: wanted attribute: (list terminator)
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: input attribute name: (end)
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: flush_add: site Medizin.Uni-Magdeburg.DE id 8342115C009 status 4
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: name_mask: resource
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: name_mask: software
Aug 2 09:52:22 hauptpostamt postfix/smtp[9400]: name_mask: 2bounce
--
[ Content of type application/x-gunzip deleted ]
--
