I'm having trouble getting STARTTLS to work. SMTPS on port 465 works fine, so I think this is a combination problem between OpenSSL's STARTTLS, and qpsmtpd.
In specific, the output of '220 Go ahead with TLS' is still processing when the
SSL_accept call fires, and the SSL initiation gets mangled.
s_client is in the wrong, because it didn't wait for the 220 output to complete
before starting the transaction. qpsmtpd is in the wrong because it gets
confused.
From my qpsmtpd log:
@4000000044977a361761f064 27621 250 AUTH PLAIN LOGIN CRAM-MD5
@4000000044977a361773f5ac 27621 dispatching STARTTLS
@4000000044977a361776d40c 27621 running plugin (unrecognized_command): tls
@4000000044977a3617788d74 27621 220 Go ahead with TLS
@4000000044977a3617cc6e1c TLS failed: Could not create SSL socket: Transport
endpoint is not connected at ./plugins/tls line 146, <STDIN> line 2.
@4000000044977a3617cc7dbc
@4000000044977a361826bb4c 27621 Plugin tls, hook unrecognized_command returned
DENY, TLS Negotiation Failed
This is caused by:
# openssl s_client -starttls smtp -host localhost -port 25 -crlf -state -msg
-debug
CONNECTED(00000003)
read from 005707C0 [0056A080] (8192 bytes => 90 (0x5A))
0000 - 32 32 30 20 6d 61 69 6c-2e 69 73 6f 68 75 6e 74 220 mail.isohunt
0010 - 2e 63 6f 6d 20 45 53 4d-54 50 20 71 70 73 6d 74 .com ESMTP qpsmt
0020 - 70 64 20 30 2e 33 33 2d-64 65 76 20 72 65 61 64 pd 0.33-dev read
0030 - 79 3b 20 73 65 6e 64 20-75 73 20 79 6f 75 72 20 y; send us your
0040 - 6d 61 69 6c 2c 20 62 75-74 20 6e 6f 74 20 79 6f mail, but not yo
0050 - 75 72 20 73 70 61 6d 2e-0d 0a ur spam...
write to 005707C0 [7FFFFF9D85C0] (21 bytes => 21 (0x15))
0000 - 45 48 4c 4f 20 73 6f 6d-65 2e 68 6f 73 74 2e 6e EHLO some.host.n
0010 - 61 6d 65 0d 0a ame..
read from 005707C0 [0056A080] (8192 bytes => 47 (0x2F))
0000 - 32 35 30 2d 6d 61 69 6c-2e 69 73 6f 68 75 6e 74 250-mail.isohunt
0010 - 2e 63 6f 6d 20 48 69 20-6c 6f 63 61 6c 68 6f 73 .com Hi localhos
0020 - 74 20 5b 31 32 37 2e 30-2e 30 2e 31 5d 0d 0a t [127.0.0.1]..
write to 005707C0 [7FFFFF9D85C0] (10 bytes => 10 (0xA))
0000 - 53 54 41 52 54 54 4c 53-0d 0a STARTTLS..
read from 005707C0 [00568070] (8192 bytes => 75 (0x4B))
0000 - 32 35 30 2d 50 49 50 45-4c 49 4e 49 4e 47 0d 0a 250-PIPELINING..
0010 - 32 35 30 2d 38 42 49 54-4d 49 4d 45 0d 0a 32 35 250-8BITMIME..25
0020 - 30 2d 53 54 41 52 54 54-4c 53 0d 0a 32 35 30 20 0-STARTTLS..250
0030 - 41 55 54 48 20 50 4c 41-49 4e 20 4c 4f 47 49 4e AUTH PLAIN LOGIN
0040 - 20 43 52 41 4d 2d 4d 44-35 0d 0a CRAM-MD5..
SSL_connect:before/connect initialization
write to 005707C0 [005713F0] (148 bytes => 148 (0x94))
0000 - 80 92 01 03 01 00 69 00-00 00 20 00 00 39 00 00 ......i... ..9..
0010 - 38 00 00 35 00 00 16 00-00 13 00 00 0a 07 00 c0 8..5............
0020 - 00 00 33 00 00 32 00 00-2f 00 00 07 05 00 80 03 ..3..2../.......
0030 - 00 80 00 00 66 00 00 05-00 00 04 01 00 80 08 00 ....f...........
0040 - 80 00 00 63 00 00 62 00-00 61 00 00 15 00 00 12 ...c..b..a......
0050 - 00 00 09 06 00 40 00 00-65 00 00 64 00 00 60 00 [EMAIL PROTECTED]
0060 - 00 14 00 00 11 00 00 08-00 00 06 04 00 80 00 00 ................
0070 - 03 02 00 80 4a 15 20 26-93 f6 e9 d0 b5 f7 cc b1 ....J. &........
0080 - 72 2a 88 44 14 34 09 2c-1c ed bc 67 e0 75 49 1d r*.D.4.,...g.uI.
0090 - d5 11 cf 7d ...}
>>> SSL 2.0 [length 0092], CLIENT-HELLO
01 03 01 00 69 00 00 00 20 00 00 39 00 00 38 00
00 35 00 00 16 00 00 13 00 00 0a 07 00 c0 00 00
33 00 00 32 00 00 2f 00 00 07 05 00 80 03 00 80
00 00 66 00 00 05 00 00 04 01 00 80 08 00 80 00
00 63 00 00 62 00 00 61 00 00 15 00 00 12 00 00
09 06 00 40 00 00 65 00 00 64 00 00 60 00 00 14
00 00 11 00 00 08 00 00 06 04 00 80 00 00 03 02
00 80 4a 15 20 26 93 f6 e9 d0 b5 f7 cc b1 72 2a
88 44 14 34 09 2c 1c ed bc 67 e0 75 49 1d d5 11
cf 7d
SSL_connect:SSLv2/v3 write client hello A
read from 005707C0 [00576950] (7 bytes => 7 (0x7))
0000 - 32 32 30 20 47 6f 220 Go
0007 - <SPACES/NULS>
SSL_connect:error in SSLv2/v3 read server hello A
27620:error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown
protocol:s23_clnt.c:601:
If I try to force TLSv1, I get a different error.
openssl s_client -starttls smtp -host localhost -port 25 -crlf -state -msg
-debug -tls1
CONNECTED(00000003)
read from 005705C0 [0056A080] (8192 bytes => 90 (0x5A))
0000 - 32 32 30 20 6d 61 69 6c-2e 69 73 6f 68 75 6e 74 220 mail.isohunt
0010 - 2e 63 6f 6d 20 45 53 4d-54 50 20 71 70 73 6d 74 .com ESMTP qpsmt
0020 - 70 64 20 30 2e 33 33 2d-64 65 76 20 72 65 61 64 pd 0.33-dev read
0030 - 79 3b 20 73 65 6e 64 20-75 73 20 79 6f 75 72 20 y; send us your
0040 - 6d 61 69 6c 2c 20 62 75-74 20 6e 6f 74 20 79 6f mail, but not yo
0050 - 75 72 20 73 70 61 6d 2e-0d 0a ur spam...
write to 005705C0 [7FFFFFA4E530] (21 bytes => 21 (0x15))
0000 - 45 48 4c 4f 20 73 6f 6d-65 2e 68 6f 73 74 2e 6e EHLO some.host.n
0010 - 61 6d 65 0d 0a ame..
read from 005705C0 [0056A080] (8192 bytes => 47 (0x2F))
0000 - 32 35 30 2d 6d 61 69 6c-2e 69 73 6f 68 75 6e 74 250-mail.isohunt
0010 - 2e 63 6f 6d 20 48 69 20-6c 6f 63 61 6c 68 6f 73 .com Hi localhos
0020 - 74 20 5b 31 32 37 2e 30-2e 30 2e 31 5d 0d 0a t [127.0.0.1]..
write to 005705C0 [7FFFFFA4E530] (10 bytes => 10 (0xA))
0000 - 53 54 41 52 54 54 4c 53-0d 0a STARTTLS..
read from 005705C0 [00568070] (8192 bytes => 75 (0x4B))
0000 - 32 35 30 2d 50 49 50 45-4c 49 4e 49 4e 47 0d 0a 250-PIPELINING..
0010 - 32 35 30 2d 38 42 49 54-4d 49 4d 45 0d 0a 32 35 250-8BITMIME..25
0020 - 30 2d 53 54 41 52 54 54-4c 53 0d 0a 32 35 30 20 0-STARTTLS..250
0030 - 41 55 54 48 20 50 4c 41-49 4e 20 4c 4f 47 49 4e AUTH PLAIN LOGIN
0040 - 20 43 52 41 4d 2d 4d 44-35 0d 0a CRAM-MD5..
SSL_connect:before/connect initialization
write to 005705C0 [0057AF60] (102 bytes => 102 (0x66))
0000 - 16 03 01 00 61 01 00 00-5d 03 01 44 97 7a 83 a2 ....a...]..D.z..
0010 - 63 69 ec f3 45 e1 57 88-6d 15 4c a9 d8 4e 7c ea ci..E.W.m.L..N|.
0020 - fb c3 c6 7e ca 51 06 f2-a2 ab 3e 00 00 36 00 39 ...~.Q....>..6.9
0030 - 00 38 00 35 00 16 00 13-00 0a 00 33 00 32 00 2f .8.5.......3.2./
0040 - 00 07 00 66 00 05 00 04-00 63 00 62 00 61 00 15 ...f.....c.b.a..
0050 - 00 12 00 09 00 65 00 64-00 60 00 14 00 11 00 08 .....e.d.`......
0060 - 00 06 00 03 01 .....
0066 - <SPACES/NULS>
>>> TLS 1.0 Handshake [length 0061], ClientHello
01 00 00 5d 03 01 44 97 7a 83 a2 63 69 ec f3 45
e1 57 88 6d 15 4c a9 d8 4e 7c ea fb c3 c6 7e ca
51 06 f2 a2 ab 3e 00 00 36 00 39 00 38 00 35 00
16 00 13 00 0a 00 33 00 32 00 2f 00 07 00 66 00
05 00 04 00 63 00 62 00 61 00 15 00 12 00 09 00
65 00 64 00 60 00 14 00 11 00 08 00 06 00 03 01
00
SSL_connect:SSLv3 write client hello A
read from 005705C0 [00576750] (5 bytes => 5 (0x5))
0000 - 32 32 30 20 47 220 G
write to 005705C0 [00580910] (7 bytes => 7 (0x7))
0000 - 15 32 30 00 02 02 46 .20...F
>>> ??? [length 0002]
02 46
SSL3 alert write:fatal:protocol version
SSL_connect:error in SSLv3 read server hello A
27626:error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version
number:s3_pkt.c:286:
But the contents of the qpsmtpd log are the same:
@4000000044977a8d0d3b795c 27627 running plugin (unrecognized_command): tls
@4000000044977a8d0d3b7d44 27627 220 Go ahead with TLS
@4000000044977a8d0d860f1c TLS failed: Could not create SSL socket: Transport
endpoint is not connected at ./plugins/tls line 146, <STDIN> line 2.
@4000000044977a8d0d8622a4
@4000000044977a8d0d8622a4 27627 Plugin tls, hook unrecognized_command returned
DENY, TLS Negotiation Failed
@4000000044977a8d0d86268c 27627 500 TLS Negotiation Failed
@4000000044977a8e0b7b79dc 27520 cleaning up after 27627
--
Robin Hugh Johnson
E-Mail : [EMAIL PROTECTED]
GnuPG FP : 11AC BA4F 4778 E3F6 E4ED F38E B27B 944E 3488 4E85
pgpIX0RXwT4Yv.pgp
Description: PGP signature
