I am looking for some ideas at what might be causing a problem.  I am
using Synapse 1.1.1 on HP-UX 11.23 with JDK1.6.

I am trying to configure an Apache 2.0 web server to sit in front of
Synapse (ProxyPass and ProxyPassReverse).  Mod_proxy to proxy requests
to synapse.  Mod_ssl to secure the apache->synapse communication.
There are 2 proxy services defined in synapse.  One for http and one
for https, but they are both proxying the sample stock quote service
from the synapse samples.  I use SOAPUI to send SOAP requests to
apache which proxies them to the http or https synapse port.  Synapse
works for either http or https, with or without the apache proxy.
It's just when SSL is used between apache and synapse that there is
some sort of 10 second SSL handshake delay.  I have also configured
the apache to proxy to other servers with self-signed certificates and
there is no delay.  It seems to be related to the SSL implementation
in the Axis2, but I am not sure.

I see that when I secure the apache to synapse connection with ssl I
get about 10 seconds of errors (about 2 per second) in the synapse log
that indicate that the ssl is not handshaking quickly and causing a
delay:
Synapse log:
2008-03-12 13:25:06,072 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] TRACE
ServerHandler New incoming connection
2008-03-12 13:25:06,093 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [rw]; ready ops: [w]][SSL
handshake status: NOT_HANDSHAKING][0][0][53][0]: Clear event [w]
2008-03-12 13:25:06,093 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
ServerHandler HTTP connection [localhost/127.0.0.1:63557]: Response
ready
2008-03-12 13:25:06,094 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1490][0][0][0]: 39 bytes read
2008-03-12 13:25:06,094 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1490][0][0][0]: 0 bytes read
2008-03-12 13:25:06,094 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1421][0][0][0]: 35 bytes read
2008-03-12 13:25:06,094 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1421][0][0][0]: 0 bytes read
2008-03-12 13:25:07,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1320][0][0][0]: 72 bytes read
2008-03-12 13:25:07,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1320][0][0][0]: 0 bytes read
2008-03-12 13:25:08,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1235][0][0][0]: 46 bytes read
2008-03-12 13:25:08,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1235][0][0][0]: 0 bytes read
2008-03-12 13:25:09,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1182][0][0][0]: 18 bytes read
2008-03-12 13:25:09,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1182][0][0][0]: 0 bytes read
2008-03-12 13:25:10,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1113][0][0][0]: 31 bytes read
2008-03-12 13:25:10,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1113][0][0][0]: 0 bytes read
2008-03-12 13:25:11,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1028][0][0][0]: 47 bytes read
2008-03-12 13:25:11,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][1028][0][0][0]: 0 bytes read
2008-03-12 13:25:12,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][943][0][0][0]: 49 bytes read
2008-03-12 13:25:12,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][943][0][0][0]: 0 bytes read
2008-03-12 13:25:13,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][890][0][0][0]: 21 bytes read
2008-03-12 13:25:13,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][890][0][0][0]: 0 bytes read
2008-03-12 13:25:14,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
SSLIOSession I/O session 19 [interested ops: [r]; ready ops: [r]][SSL
handshake status: NOT_HANDSHAKING][853][0][0][0]: 2 bytes read
2008-03-12 13:25:14,091 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
ServerHandler HTTP connection [localhost/127.0.0.1:63557]: POST
/soap/StockQuoteComplex HTTP/1.1
2008-03-12 13:25:14,092 [xx.x.x.xx-xxxxxxx] [I/O dispatcher 7] DEBUG
headers >> POST /soap/StockQuoteComplex HTTP/1.1

Apache log:
[Wed Mar 12 13:25:06 2008] [debug] ssl_engine_kernel.c(1835): OpenSSL:
Loop: SSLv3 read finished A
[Wed Mar 12 13:25:06 2008] [debug] ssl_engine_kernel.c(1831): OpenSSL:
Handshake: done
[Wed Mar 12 13:25:06 2008] [info] Connection: Client IP: 127.0.0.1,
Protocol: TLSv1, Cipher: DHE-RSA-AES256-SHA (256/256 bits)
[Wed Mar 12 13:25:10 2008] [info] Connection to child 4 established
(server xx.x.x.xxx:443, client xx.x.x.xxx)
[Wed Mar 12 13:25:10 2008] [info] Seeding PRNG with 144 bytes of entropy
[Wed Mar 12 13:25:10 2008] [debug] ssl_engine_kernel.c(1827): OpenSSL:
Handshake: start
[Wed Mar 12 13:25:10 2008] [debug] ssl_engine_kernel.c(1835): OpenSSL:
Loop: before/accept initialization
[Wed Mar 12 13:25:10 2008] [debug] ssl_engine_io.c(1703): OpenSSL: I/O
error, 11 bytes expected to read on BIO#600000000049d020 [mem:
6000000000580020]
[Wed Mar 12 13:25:10 2008] [debug] ssl_engine_kernel.c(1864): OpenSSL:
Exit: error in SSLv2/v3 read client hello A
[Wed Mar 12 13:25:10 2008] [info] (232)Connection reset by peer: SSL
handshake interrupted by system [Hint: Stop button pressed in
browser?!]
[Wed Mar 12 13:25:10 2008] [info] Connection to child 4 closed with
abortive shutdown(server xx.x.x.xxx:443, client xx.x.x.xxx)
[Wed Mar 12 13:25:15 2008] [info] Connection to child 73 established
(server xx.x.x.xxx:443, client xx.x.x.xxx)
[Wed Mar 12 13:25:15 2008] [info] Seeding PRNG with 144 bytes of entropy
[Wed Mar 12 13:25:15 2008] [debug] ssl_engine_kernel.c(1827): OpenSSL:
Handshake: start
[Wed Mar 12 13:25:15 2008] [debug] ssl_engine_kernel.c(1835): OpenSSL:
Loop: before/accept initialization
[Wed Mar 12 13:25:15 2008] [debug] ssl_engine_io.c(1703): OpenSSL: I/O
error, 11 bytes expected to read on BIO#6000000000628aa0 [mem:
60000000006a0020]
[Wed Mar 12 13:25:15 2008] [debug] ssl_engine_kernel.c(1864): OpenSSL:
Exit: error in SSLv2/v3 read client hello A
[Wed Mar 12 13:25:15 2008] [info] (232)Connection reset by peer: SSL
handshake interrupted by system [Hint: Stop button pressed in
browser?!]
[Wed Mar 12 13:25:15 2008] [info] Connection to child 73 closed with
abortive shutdown(server xx.x.x.xxx:443, client xx.x.x.xxx)
[Wed Mar 12 13:25:19 2008] [debug] ssl_engine_io.c(1692): OpenSSL:
read 5/5 bytes from BIO#600000000045d140 [mem: 6000000000655c80] (BIO
dump follows)

Any ideas what is causing the SSL delay for synapse?  I can confirm
that apache likes the synapse certificate cipher, that openssl
supports the cipher, and that apache accepts the certificate.  I am
not sure what else I can look at.
~john

Reply via email to