opensmtpd

[mikie]

Hello
I am using v6 enabled opensmtpd as my mailserver. When I try the administrator test I see "500 .5.0.0 Pipelining not supported" in the maillog. I know that pipelining will be coming soonish but was wondering if there was any way around this?

thanks

mike

[kasperd]

The code sending the email from HE isn't so advanced that it even knows what pipelining means. What it does is just fire off a bunch of commands, without even checking the status codes. If any of the SMTP commands fails, the certification test will still proceed sending the body of the email, which the receiving server will interpret as syntactically invalid SMTP commands.

I guess what your mail server notices is that it receives multiple lines of commands without having responded to the first. If you aren't using pipelining, the sender isn't allowed to send another SMTP command before the previous has been responded to. Because the interpretation of the next command depends on the previous result.

When I was going through that test myself I experienced a couple of bugs related to what you see. One of them got fixed.

If you can save a dump of the TCP packets, I can take a look on it, to confirm that you are really seeing the bug, which I suspect you are seeing. But I am quite convinced this is due to a bug in the test.

[mikie]

Seems reasonable, I (now) know from rfc2920 that pipelining or lack of it shouldn't be causing the problem.
I'll get a tcpdump later today.

[kasperd]

I looked at the dump you send me. The dump you send me was with truncated packets, so the exact point where the problem happened was missing. If you are saving using the tcpdump command, packets will be truncated by default. You need to pass the -s0 argument to tcpdump to disable truncation.

What I could see was that the problem happened later during the SMTP session, than I had thought.

Though the server ignores the reply it gets, it does wait for a reply after the EHLO, MAIL, RCPT, and DATA commands. So everything proceeded without problems that far. The server then starts sending the body of the email. At this point it is sending more data per packet, but the truncated packets are the same size, so I am missing more information about what is being send.

I see two TCP packets with parts of the email body. The first packet is just acknowledged at the TCP layer (as expected). The second packet triggers the 500 reply from your mail server at the SMTP layer.

What is at the end of that second TCP packet is unknown to me. But it must have included the end of the email marker (a line with just a single . character). What is interesting is what comes after that line.

I tried manually sending two messages using a telnet command. If I simply type the lines one at a time, the mail server accepts the mail. But if I paste the entire mail content and another SMTP command after that into the telnet command in one go, then I got the 500 error saying pipelining isn't supported.

I think what happens is that the sending code isn't waiting for a reply after the message body and sends another SMTP command immediately. And they end up in the same TCP packet. And your mail server is reading both the data and the next SMTP command in a single read system call. Thus it ends up with the SMTP command in the buffer intended for mail data, and your mail server isn't prepared to deal with that.

I think you should file a ticket with HE, and let them know, that they need to wait for a reply after the end of the message data, before sending another command. I don't know what the command is, because that was left out by truncation. But I am guessing a RSET or a QUIT command.

Since their code is already able to wait for a reply after each of the preceding commands, I think it cannot be much work for them to do that after the end of data as well.

[kcochran]

We send the '.\r\n' and wait for output.  I'm curious as to if there's anything in the buffer sent between the ACK for the DATA command and the end of message period.

[kasperd]

I'm curious as to if there's anything in the buffer sent between the ACK for the DATA command and the end of message period.

That cannot be definitively answered from the tcpdump I have seen, because the packets were truncated.

The packet with the 354 response from the server had 50 bytes of TCP payload, but due to truncation only 30 bytes of that was in the pcap file, I received.

The 30 bytes, which I did receive, were

354 Enter mail, end with "." o

I guess the full version was

354 Enter mail, end with "." on a line by itself\r\n

If that is correct, then there was no data in the buffer at that point. No more data is sent from the server to the client before the 500 error code.

I can't see the \r\n.\r\n sequence ending the email, because that was in a TCP packet with 277 bytes of payload of which only the first 30 bytes were in the pcap file. Those 30 bytes were

Message-ID: <50a420cc0f1da.135

A pcap file where the packets are not truncated would definitely help figure out what is happening, since the missing bytes of those two packets are important.

[kasperd]

The packet with the 354 response from the server had 50 bytes of TCP payload, but due to truncation only 30 bytes of that was in the pcap file, I received.

The 30 bytes, which I did receive, were

354 Enter mail, end with "." o

I guess the full version was

354 Enter mail, end with "." on a line by itself\r\n

If that is correct, then there was no data in the buffer at that point.

That guess could easily be verified. I just did a TCP session to the same address manually and found that my guess was correct. I also verified, that the checksum matched by appending those missing 20 bytes to the packet.

So, there wasn't anything send from the server to the client between the 354 reply and the 500 reply. I have a pcap file, where I have reconstructed that one packet. All the other packets are of course still truncated. Would that file be any help, or would you rather wait for mikie to rerun tcpdump with -s0?

[kasperd]

We send the '.\r\n' and wait for output.

How do you handle multiline replies? Could the two ends get out of sync in a way that cause you to wait for the reply for the previous command?

[kcochran]

How do you handle multiline replies? Could the two ends get out of sync in a way that cause you to wait for the reply for the previous command?

We could handle them better, and should now in more places.  If anything, it may be that we're getting a multi-line in a spot where we were previously just waiting for ANY data, so it's possible the script was sending when the other side wasn't finished, which could make it think we were trying to pipeline.

[mikie]

So this is getting a bit odd now.,
now when i run the test it fails with "DATA failed" displayed on the page.
turns out that tcpdump on OpenBSD wont use snaplength of 0 so i set it to my MTU
now i see the conversation which seems to go ok to DATA, smtpd replies with
   S: 354 Enter mail, end with "." on a line by itself
the next 2 packets are from ipv6.he.net and they are tcp, the first being an ack, the next being a FIN, ACK after a timeout

20   3.077168   <he.net address>    <my ipv6 address>   TCP   86   52663 > smtp [ACK] Seq=79 Ack=291


831   63.402339   <he.net address>    <my ipv6 address>   TCP   86   52663 > smtp [FIN, ACK] Seq=79 Ack=291 Win=6848 Len=0 TSval=3846859633 TSecr=3631281716

i then see my box ACKing packet 20, then FIN ACKing and then a final ACK from he.net

I have verified that smtpd is still running OK on both ipv6 and v4 using both telnet (v6) and from gmail.

Has the script been changed in the last 24 hours?

pcap sent to Kasper

[mikie]

fixed
thank you