Subject: Handshake Failure, but it looks like SSL

From: Sam <[email-masked]>
Date: Sun, 14 Sep 2003 18:38:00 -0400

Hi all - 

I'm trying to get modssl working on a RedHat 8.0 box, which is running
modssl 2.0.40-11.7 and the apache httpd 2.0.40-11.7 (both from RPM).

There are several NBVH on port 80, and I one VirtualHost block set to port
443.

When I connect, I get the following:

$ openssl s_client -connect www.mydomain.com:443  -state -debug
CONNECTED(00000003)
SSL_connect:before/connect initialization
write to 08161508 [08161550] (124 bytes => 124 (0x7C))
0000 - 80 7a 01 03 01 00 51 00-00 00 20 00 00 16 00 00   .z....Q... .....
0010 - 13 00 00 0a 07 00 c0 00-00 66 00 00 05 00 00 04   .........f......
0020 - 03 00 80 01 00 80 08 00-80 00 00 65 00 00 64 00   ...........e..d.
0030 - 00 63 00 00 62 00 00 61-00 00 60 00 00 15 00 00   .c..b..a..`.....
0040 - 12 00 00 09 06 00 40 00-00 14 00 00 11 00 00 08   ......@.........
0050 - 00 00 06 00 00 03 04 00-80 02 00 80 7f 5f 29 d7   ............._).
0060 - eb 10 2c be a7 b8 42 b9-e5 86 7a b7 03 f0 e9 34   ..,...B...z....4
0070 - 47 04 1f 94 00 c4 83 c5-0a bb c5 d7               G...........
SSL_connect:SSLv2/v3 write client hello A
read from 08161508 [08166AB0] (7 bytes => 0 (0x0))
29523:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake
failure:s23_lib.c:226:
$ openssl s_client -connect localhost:443  -state -debug
CONNECTED(00000003)
SSL_connect:before/connect initialization
write to 08160670 [08160A40] (124 bytes => 124 (0x7C))
0000 - 80 7a 01 03 01 00 51 00-00 00 20 00 00 16 00 00   .z....Q... .....
0010 - 13 00 00 0a 07 00 c0 00-00 66 00 00 05 00 00 04   .........f......
0020 - 03 00 80 01 00 80 08 00-80 00 00 65 00 00 64 00   ...........e..d.
0030 - 00 63 00 00 62 00 00 61-00 00 60 00 00 15 00 00   .c..b..a..`.....
0040 - 12 00 00 09 06 00 40 00-00 14 00 00 11 00 00 08   ......@.........
0050 - 00 00 06 00 00 03 04 00-80 02 00 80 fc e7 8b 7d   ...............}
0060 - 38 97 d2 c0 73 10 26 93-6e 06 61 c2 84 cc dc 6f   8...s.&.n.a....o
0070 - fd d7 69 d9 e2 92 c1 55-e4 17 a0 a4               ..i....U....
SSL_connect:SSLv2/v3 write client hello A
read from 08160670 [08165FA0] (7 bytes => 0 (0x0))
29524:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake
failure:s23_lib.c:226:
$ openssl s_client -connect localhost:443  -state -debug
CONNECTED(00000003)
SSL_connect:before/connect initialization
write to 08160670 [08160A40] (124 bytes => 124 (0x7C))
0000 - 80 7a 01 03 01 00 51 00-00 00 20 00 00 16 00 00   .z....Q... .....
0010 - 13 00 00 0a 07 00 c0 00-00 66 00 00 05 00 00 04   .........f......
0020 - 03 00 80 01 00 80 08 00-80 00 00 65 00 00 64 00   ...........e..d.
0030 - 00 63 00 00 62 00 00 61-00 00 60 00 00 15 00 00   .c..b..a..`.....
0040 - 12 00 00 09 06 00 40 00-00 14 00 00 11 00 00 08   ......@.........
0050 - 00 00 06 00 00 03 04 00-80 02 00 80 ca 76 f2 09   .............v..
0060 - 0a c8 b1 ab 78 f3 c9 b3-a6 8d 34 4e 44 54 14 a5   ....x.....4NDT..
0070 - 2f 18 c0 7a 96 e4 21 c5-cd 90 b2 08               /..z..!.....
SSL_connect:SSLv2/v3 write client hello A
read from 08160670 [08165FA0] (7 bytes => 0 (0x0))
29525:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake
failure:s23_lib.c:226:

Note how they're different (slightly) and there's no human-readable text in
there.  In fact, when I connect to a working https server, I get a similar
result at the beginning.

($ openssl s_client -connect workingdomain.com:443  -state -debug
CONNECTED(00000003)
SSL_connect:before/connect initialization
write to 08161508 [08161550] (124 bytes => 124 (0x7C))
0000 - 80 7a 01 03 01 00 51 00-00 00 20 00 00 16 00 00   .z....Q... .....
0010 - 13 00 00 0a 07 00 c0 00-00 66 00 00 05 00 00 04   .........f......
0020 - 03 00 80 01 00 80 08 00-80 00 00 65 00 00 64 00   ...........e..d.
0030 - 00 63 00 00 62 00 00 61-00 00 60 00 00 15 00 00   .c..b..a..`.....
0040 - 12 00 00 09 06 00 40 00-00 14 00 00 11 00 00 08   ......@.........
0050 - 00 00 06 00 00 03 04 00-80 02 00 80 b3 30 11 07   .............0..
0060 - d2 7f 14 32 93 4d 4c 53-3c 5d 7d 30 d8 f0 91 a8   ...2.MLS<]}0....
0070 - 75 f6 41 b7 0c 69 58 7e-ac 6e 58 11               u.A..iX~.nX.
SSL_connect:SSLv2/v3 write client hello A
read from 08161508 [08166AB0] (7 bytes => 7 (0x7))
0000 - 16 03 01 00 4a 02                                 ....J.
0007 - <SPACES/NULS>
<snip handshake sequence>)

If I turn OFF the SSLEngine, I get the following:

$ openssl s_client -connect localhost:443 -state -debug
CONNECTED(00000003)
SSL_connect:before/connect initialization
write to 08160670 [08160A40] (124 bytes => 124 (0x7C))
0000 - 80 7a 01 03 01 00 51 00-00 00 20 00 00 16 00 00   .z....Q... .....
0010 - 13 00 00 0a 07 00 c0 00-00 66 00 00 05 00 00 04   .........f......
0020 - 03 00 80 01 00 80 08 00-80 00 00 65 00 00 64 00   ...........e..d.
0030 - 00 63 00 00 62 00 00 61-00 00 60 00 00 15 00 00   .c..b..a..`.....
0040 - 12 00 00 09 06 00 40 00-00 14 00 00 11 00 00 08   ......@.........
0050 - 00 00 06 00 00 03 04 00-80 02 00 80 1a 3b 1f c0   .............;..
0060 - 17 07 46 3e 56 6a cd ea-f4 8f b0 31 0c a1 e6 66   ..F>Vj.....1...f
0070 - ae c7 df 2b 80 af ca e1-98 db 3d 9d               ...+......=.
SSL_connect:SSLv2/v3 write client hello A
read from 08160670 [08165FA0] (7 bytes => 7 (0x7))
0000 - 0a 3c 3f 78 6d 6c                                 .<?xml
0007 - <SPACES/NULS>
SSL_connect:error in SSLv2/v3 read server hello A
28895:error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown
protocol:s23_clnt.c:460:

A different error, and you can see the beginning of the document peeking
through (<?xml...)

The SSL server's debug output to the error_log [with SSLEngine on] is
[Sun Sep 14 00:27:53 2003] [info] Connection to child 67 established (server
www.mydomain.com:443, client xxx.xxx.xxx.xxx)
[Sun Sep 14 00:27:53 2003] [info] Seeding PRNG with 136 bytes of entropy
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_kernel.c(1846): OpenSSL:
Handshake: start
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_kernel.c(1854): OpenSSL: Loop:
before/accept initialization
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(1027): OpenSSL: read
11/11 bytes from BIO#bogus %p[mem: bogus %p !!!@`!!@!!?!!
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(974):
+-------------------------------------------------------------------------+
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0000: 80 7a 01 03
01 00 51                             .z....Q          |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(1003): | 0011 -
<SPACES/NULS>
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(1005):
+-------------------------------------------------------------------------+
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(1027): OpenSSL: read
113/113 bytes from BIO#bogus %p[mem: bogus %p !!!@`!!@!!?!!
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(974):
+-------------------------------------------------------------------------+
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0000: 00 00 16 00
00 13 00 00-0a 07 00 c0 00 00 66 00  ..............f. |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0010: 00 05 00 00
04 03 00 80-01 00 80 08 00 80 00 00  ................ |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0020: 65 00 00 64
00 00 63 00-00 62 00 00 61 00 00 60  e..d..c..b..a..` |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0030: 00 00 15 00
00 12 00 00-09 06 00 40 00 00 14 00  ...........@.... |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0040: 00 11 00 00
08 00 00 06-00 00 03 04 00 80 02 00  ................ |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0050: 80 7f 5f 29
d7 eb 10 2c-be a7 b8 42 b9 e5 86 7a  .._)...,...B...z |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0060: b7 03 f0 e9
34 47 04 1f-94 00 c4 83 c5 0a bb c5  ....4G.......... |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(999): | 0070: d7
.                |
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_io.c(1005):
+-------------------------------------------------------------------------+
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_kernel.c(1854): OpenSSL: Loop:
SSLv3 read client hello A
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_kernel.c(1854): OpenSSL: Loop:
SSLv3 write server hello A
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_kernel.c(1854): OpenSSL: Loop:
SSLv3 write certificate A
[Sun Sep 14 00:27:53 2003] [debug] ssl_engine_kernel.c(1248): handing out
temporary 1024 bit DH key

Then the child segfaults, the browser complains of a dropped connection.

httpd.conf has:

NameVirtualHost xxx.xxx.xxx.xxx

<VirtualHost xxx.xxx.xxx.xxx:80>
ServerAdmin [email-masked]
ServerName www.domain.com
DocumentRoot /var/www/html
Include "/etc/httpd/conf/redirects.include.conf"
</VirtualHost>

<VirtualHost xxx.xxx.xxx.xxx:80>
ServerName subdomain.domain.com
DocumentRoot /home/subdomain/
</VirtualHost>
(repeat a few times with different subdomains)

ssl.conf, included above that, includes

LoadModule ssl_module modules/mod_ssl.so
Listen 443
AddType application/x-x509-ca-cert .crt
AddType application/x-pkcs7-crl    .crl
SSLPassPhraseDialog  builtin
SSLSessionCache         dbm:/var/cache/mod_ssl/scache
SSLSessionCacheTimeout  300
SSLMutex  file:logs/ssl_mutex
SSLRandomSeed startup builtin
SSLRandomSeed connect builtin
<VirtualHost _default_:443>
    #<VirtualHost xxx.xxx.xxx.xxx:443>  #this didn't help
    DocumentRoot /var/www/html
    ServerName www.domain.com:443
    ServerAdmin [email-masked]
    ErrorLog logs/ssl_error_log
    TransferLog logs/ssl_access_log
    LogLevel debug
    #SSLEngine off 
    SSLEngine on
    SSLCipherSuite 
ALL:!ADH:!EXPORT56:RC4+RSA:+HIGH:+MEDIUM:+LOW:-SSLv2:+EXP:+eNULL
    SSLCertificateFile /etc/httpd/conf/ssl.crt/server.crt
    SSLCertificateKeyFile /etc/httpd/conf/ssl.key/server.key
    <Files ~ "\.(cgi|shtml|phtml|php3?)$">
        SSLOptions +StdEnvVars
    </Files>    
    <Directory "/var/www/cgi-bin">
        SSLOptions +StdEnvVars
    </Directory>
    <Directory "/var/www/html">
        SSLOptions +StdEnvVars +OptRenegotiate
    </Directory>
    SetEnvIf User-Agent ".*MSIE.*" \
         nokeepalive ssl-unclean-shutdown \
         downgrade-1.0 force-response-1.0
    CustomLog logs/ssl_request_log \
          "%t %h %{SSL_PROTOCOL}x %{SSL_CIPHER}x \"%r\" %b"
</VirtualHost>     

So the big question is, does this ring a bell with anyone?  Seen something
like this before?  Any suggestions?  Am I missing something? I've been
around in circles on this one, I'm afraid.

Thanks in advance

Sam

---
Humans do it better

______________________________________________________________________
Apache Interface to OpenSSL (mod_ssl)                   www.modssl.org
User Support Mailing List                      [email-masked]
Automated List Manager                            [email-masked]

---

From: Kiyoshi Watanabe <[email-masked]>
Date: Thu, 25 Sep 2003 01:18:01 +0900 (JST)

OnHandshake Failure, but it looks like SSL, 
	Sam <[email-masked]> said:

Any help when you add -ssl3 command?

-Kiyoshi
Kiyoshi Watanabe