Hello Asanka, just so you know we are getting a similar problem and spent last 8 hours trying to work it out. We get multiple NOT_HANDSHAKING issues after a Web Service succesfully processes the request (looking at the service server logs) but the responce never gets back to Synapse. This only happens on our production and staging systems. The Script works fine on Integration. We cannot find any differences ? Due to the proxy issue (previous post) we had to deploy into a machine within the proxied network as a work around. However the next problem is this.... I will post more details later.
Kim asankha wrote: > > John > > Whats your exact Java version? Can you share "java -version", can you > also just try JDK 1.5.0_13 etc to see if this problem still remains? >> 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:*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 >> > Note the time from 13:25:06 to 13:25:14 where Synapse reports this > error. Can you also try the debug options at > http://java.sun.com/j2se/1.5.0/docs/guide/security/jsse/JSSERefGuide.html#Debug > > and the -Djavax.net/debug=all in particular, which would dump a lot of > handshake information, which may help us to figure out the problem >> 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) >> > It seems like Apache opened multiple connections to Synapse? that failed > after a few seconds each? Its going to be a bit difficult for me to try > to reproduce this as it may take some time to setup Apache etc, and I am > scheduled to be traveling for a week from Sunday.. So it would be great > for me to have any material that could help me reproduce this issue > quickly.. even Apache configs, and any self signed certs etc (which can > be shared.. you can mail these directly to me privately > > asankha > > -- View this message in context: http://www.nabble.com/Using-SSL-between-Apache-proxy-and-Synapse-causes-consistent-10-second-delay-in-SSL-handshake-tp16014406p22470055.html Sent from the Synapse - User mailing list archive at Nabble.com.
