Gilman, thanks for the tcpdump, much easier to work with.
Could you please try jetty-8.1.0.RC0? We did a lot of work on the ssl and io layers recently, so that's the best version to try with. Also, FYI, if bug #298502 was marked as fixed for jetty 7.5, then that means that it would have been included in jetty-8.0.5 (as jetty-8 merges changes from 7), so your version doesn't include that change. So, please try with jetty-8.1.0.RC0 with debug enabled, and also throw in -Dorg.eclipse.jetty.util.log.IGNORED=true, and again capture and attach the tcpdump please if its not working for you. thanks, Jan On 19 December 2011 16:53, Gilman Tolle <gilman.to...@gmail.com> wrote: > Thanks for the followup. > > I've attached the tcpdump file. > > I've also included the debug output. > > I tried adding the handler methods you asked for, and none of them > were called during my test. > > Gil > > 2011-12-18 21:48:05.056:DBUG:oejuc.AbstractLifeCycle:starting > org.eclipse.jetty.client.HttpClient@18b753f8#STOPPED > 2011-12-18 21:48:05.063:DBUG:oejuc.AbstractLifeCycle:starting > HttpClient{8<=0<=0/16,-1}#STOPPED > 2011-12-18 21:48:05.073:DBUG:oejuc.AbstractLifeCycle:STARTED > HttpClient{8<=7<=8/16,0}#STARTED > 2011-12-18 21:48:05.073:DBUG:oejuc.AbstractLifeCycle:starting > org.eclipse.jetty.http.ssl.SslContextFactory@2b86c6b2#STOPPED > 2011-12-18 21:48:05.396:INFO:oejhs.SslContextFactory:Enabled Protocols > [SSLv2Hello, TLSv1, SSLv3] of [SSLv2Hello, SSLv3, TLSv1] > 2011-12-18 21:48:05.397:DBUG:oejuc.AbstractLifeCycle:STARTED > org.eclipse.jetty.http.ssl.SslContextFactory@2b86c6b2#STARTED > 2011-12-18 21:48:05.404:DBUG:oejuc.AbstractLifeCycle:starting > org.eclipse.jetty.client.SelectConnector@3f77b3cd#STOPPED > 2011-12-18 21:48:05.408:DBUG:oejuc.AbstractLifeCycle:starting > org.eclipse.jetty.client.SelectConnector$Manager@332611a7#STOPPED > 2011-12-18 21:48:05.415:DBUG:oeji.nio:Starting Thread[HttpClient-8 > Selector0,5,main] on > org.eclipse.jetty.io.nio.SelectorManager$1@165973ea > 2011-12-18 21:48:05.416:DBUG:oejuc.AbstractLifeCycle:STARTED > org.eclipse.jetty.client.SelectConnector$Manager@332611a7#STARTED > 2011-12-18 21:48:05.416:DBUG:oejuc.AbstractLifeCycle:STARTED > org.eclipse.jetty.client.SelectConnector@3f77b3cd#STARTED > 2011-12-18 21:48:05.416:DBUG:oejuc.AbstractLifeCycle:STARTED > org.eclipse.jetty.client.HttpClient@18b753f8#STARTED > 2011-12-18 21:48:05.476:DBUG:oeji.nio:Required scheduleWrite > ssls...@1948703724java.nio.channels.SocketChannel[connected > local=/192.168.202.3:41729 remote=/192.168.201.6:9122][o=true > d=false,io=0,w=true,rb=false,wb=false],NEED_WRAP, in/out=0/0 > bi/o=false/false null > 2011-12-18 21:48:05.485:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] close > 2011-12-18 21:48:05.485:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.487:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.487:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.487:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.488:DBUG:oeji.nio:destroyEndPoint > ssls...@1948703724java.nio.channels.SocketChannel[closed][o=false > d=false,io=1,w=true,rb=false,wb=false],NEED_UNWRAP, in/out=0/0 > bi/o=false/false Status = CLOSED HandshakeStatus = NEED_UNWRAP > bytesConsumed = 0 bytesProduced = 7 > 2011-12-18 21:48:05.490:DBUG:oeji.nio:Required scheduleWrite > ssls...@354199555java.nio.channels.SocketChannel[connected > local=/192.168.202.3:41730 remote=/192.168.201.6:9122][o=true > d=false,io=0,w=true,rb=false,wb=false],NEED_WRAP, in/out=0/0 > bi/o=false/false null > 2011-12-18 21:48:05.501:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] close > 2011-12-18 21:48:05.501:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.501:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.501:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.501:DBUG:oejin.ssl:[Session-1, > SSL_NULL_WITH_NULL_NULL] flush > 2011-12-18 21:48:05.501:DBUG:oeji.nio:destroyEndPoint > ssls...@354199555java.nio.channels.SocketChannel[closed][o=false > d=true,io=1,w=true,rb=false,wb=false],NEED_UNWRAP, in/out=0/0 > bi/o=false/false Status = CLOSED HandshakeStatus = NEED_UNWRAP > bytesConsumed = 0 bytesProduced = 7 > > ... repeats here ... > > On Sun, Dec 18, 2011 at 7:49 PM, Jan Bartel <j...@intalio.com> wrote: >> Hi Gilman, >> >> Could you attach the actual tcp dump file? If you cannot, then please open an >> issue and attach it. The issue tracker is at: >> https://bugs.eclipse.org/bugs/buglist.cgi?cmdtype=runnamed&namedcmd=jetty-bugs >> >> Also, have you turned on debug , and overridden the onException(), >> onConnectionFail(), onExpire() methods of ContentExchange? >> >> thanks >> Jan >> >> On 18 December 2011 11:58, Gilman Tolle <gilman.to...@gmail.com> wrote: >>> Hello all, >>> >>> I'm having problems using jetty-client 8.0.4.v20111024 to open a HTTPS >>> connection through an Apache proxy server, using HTTP CONNECT. >>> >>> The Jetty client appears to open up new connections to the Apache >>> proxy then close them before any data has been returned, repeatedly. >>> I'm seeing many HTTP CONNECT requests being generated a few >>> milliseconds apart. The Apache proxy opens new connections to the real >>> end server and waits for responses, but these responses never make it >>> back to the Jetty client. >>> >>> Simple test code attached. Trimmed tcpdump output captured from the >>> proxy server also attached. >>> >>> I'm using Java SE 1.6.0_29 on RHEL 5.5 Linux. >>> >>> Using the commandline 'curl' client through this proxy server works >>> correctly. >>> >>> This may be related to Bug 298502 - Https exchange through an http >>> proxy. This bug was fixed a few months ago, but I'm still seeing an >>> issue that seems similar. >>> >>> Thanks for any help you can offer. >>> >>> Gil >>> >>> Test code: >>> >>> SslContextFactory factory = new SslContextFactory(); >>> ... >>> HttpClient client = new HttpClient(factory); >>> client.setProxy(new Address( "192.168.201.6", 9122 )); >>> client.start(); >>> >>> ContentExchange exchange = new ContentExchange(); >>> exchange.setMethod("GET"); >>> exchange.setURL("https://192.168.201.4:8443/"); >>> client.send(exchange); >>> exchange.waitForDone(); >>> >>> Tcpdump: >>> >>> 16:40:57.507852 IP 192.168.202.3.49006 > 192.168.201.6.9122: P >>> 1:122(121) ack 1 win 46 <nop,nop,timestamp 3391858150 440115033> >>> E...\.@.?............n#.?M................. >>> .+...;.YCONNECT 192.168.201.4:8443 HTTP/1.1 >>> Host: 192.168.201.4:8443 >>> Proxy-Connection: keep-alive >>> User-Agent: Jetty-Client >>> >>> 16:40:57.507867 IP 192.168.201.6.9122 > 192.168.202.3.49006: . ack 122 >>> win 46 <nop,nop,timestamp 440115069 3391858150> >>> E..42.@.@...........#..n....?M.L.....d..... >>> .;.}.+.. >>> 16:40:57.510653 IP 192.168.201.6.58887 > 192.168.201.4.8443: S >>> 3534877258:3534877258(0) win 5840 <mss 1460,sackOK,timestamp 440115070 >>> 0,nop,wscale 7> >>> E..<m4@.@..+.......... ....J................... >>> .;.~........ >>> 16:40:57.512062 IP 192.168.201.4.8443 > 192.168.201.6.58887: S >>> 873236234:873236234(0) ack 3534877259 win 22104 <mss >>> 1460,nop,nop,timestamp 2272020 440115070> >>> E..8.}..@........... ...4.. >>> ...K..VX C......... >>> ."...;.~ >>> 16:40:57.512074 IP 192.168.201.6.58887 > 192.168.201.4.8443: . ack 1 >>> win 5840 <nop,nop,timestamp 440115074 2272020> >>> E..4m5@.@..2.......... ....K4.......`...... >>> .;...".. >>> >>> 16:40:57.512137 IP 192.168.201.6.9122 > 192.168.202.3.49006: P >>> 1:38(37) ack 122 win 46 <nop,nop,timestamp 440115074 3391858150> >>> E..Y2.@.@...........#..n....?M.L........... >>> .;...+..HTTP/1.0 200 Connection Established >>> >>> 16:40:57.512145 IP 192.168.201.6.9122 > 192.168.202.3.49006: P >>> 38:76(38) ack 122 win 46 <nop,nop,timestamp 440115074 3391858150> >>> E..Z2.@.@...........#..n....?M.L........... >>> .;...+..Proxy-agent: Apache/2.2.3 (CentOS) >>> >>> ... a few additional packet exchanges between the two servers here ... >>> >>> 16:40:57.518032 IP 192.168.202.3.49007 > 192.168.201.6.9122: P >>> 1:122(121) ack 1 win 46 <nop,nop,timestamp 3391858160 440115076> >>> E...%j@.?............o#.?M....u.....a...... >>> .+...;..CONNECT 192.168.201.4:8443 HTTP/1.1 >>> Host: 192.168.201.4:8443 >>> Proxy-Connection: keep-alive >>> User-Agent: Jetty-Client >>> >>> >>> 16:40:57.518042 IP 192.168.201.6.9122 > 192.168.202.3.49007: . ack 122 >>> win 46 <nop,nop,timestamp 440115080 3391858160> >>> E..4..@.@.<g........#..o..u.?M......LX..... >>> .;...+.. >>> 16:40:57.518212 IP 192.168.201.6.58888 > 192.168.201.4.8443: S >>> 3534075867:3534075867(0) win 5840 <mss 1460,sackOK,timestamp 440115080 >>> 0,nop,wscale 7> >>> E..<(S@.@............. ........................ >>> .;.......... >>> 16:40:57.519692 IP 192.168.201.4.8443 > 192.168.201.6.58888: S >>> 2941708955:2941708955(0) ack 3534075868 win 22104 <mss >>> 1460,nop,nop,timestamp 2272020 440115080> >>> E..8....@........... ....V........VXd.......... >>> ."...;.. >>> 16:40:57.519700 IP 192.168.201.6.58888 > 192.168.201.4.8443: . ack 1 >>> win 5840 <nop,nop,timestamp 440115081 2272020> >>> E..4(T@.@............. ......V............. >>> .;...".. >>> 16:40:57.519717 IP 192.168.201.6.9122 > 192.168.202.3.49007: P >>> 1:38(37) ack 122 win 46 <nop,nop,timestamp 440115081 3391858160> >>> E..Y..@.@.<A........#..o..u.?M......l...... >>> .;...+..HTTP/1.0 200 Connection Established >>> >>> 16:40:57.519728 IP 192.168.201.6.9122 > 192.168.202.3.49007: P >>> 38:76(38) ack 122 win 46 <nop,nop,timestamp 440115081 3391858160> >>> E..Z..@.@.<?........#..o..u.?M......w...... >>> .;...+..Proxy-agent: Apache/2.2.3 (CentOS) >>> >>> 'curl' request: >>> >>> 16:56:23.123858 IP 192.168.202.3.37417 > 192.168.201.6.9122: P >>> 1:201(200) ack 1 win 46 <nop,nop,timestamp 3392783764 441040671> >>> }.K....0.............)#.yC.. >>> .9...I..CONNECT 192.168.201.4:8443 HTTP/1.0 >>> Host: 192.168.201.4:8443 >>> User-Agent: curl/7.15.5 (x86_64-redhat-linux-gnu) libcurl/7.15.5 >>> OpenSSL/0.9.8b zlib/1.2.3 libidn/0.6.5 >>> Proxy-Connection: Keep-Alive >>> >>> >>> 16:56:23.123874 IP 192.168.201.6.9122 > 192.168.202.3.37417: . ack 201 >>> win 54 <nop,nop,timestamp 441040671 3392783764> >>> }.KyC.....6,W.......#..) >>> .I...9.. >>> 16:56:23.124141 IP 192.168.201.6.60481 > 192.168.201.4.8443: S >>> 226631487:226631487(0) win 5840 <mss 1460,sackOK,timestamp 441040671 >>> 0,nop,wscale 7> >>> ..?........?.........A . >>> m......... >>> .I.......... >>> 16:56:23.125682 IP 192.168.201.4.8443 > 192.168.201.6.60481: S >>> 1783422927:1783422927(0) ack 226631488 win 27016 <mss >>> 1460,nop,nop,timestamp 2280835 441040671> >>> ..@..i.............. ..AjL.. >>> ."...I.. >>> 16:56:23.125691 IP 192.168.201.6.60481 > 192.168.201.4.8443: . ack 1 >>> win 5840 <nop,nop,timestamp 441040673 2280835> >>> ..@jL......!d........A . >>> .I.!.".. >>> 16:56:23.125748 IP 192.168.201.6.9122 > 192.168.202.3.37417: P >>> 1:38(37) ack 201 win 54 <nop,nop,timestamp 441040673 3392783764> >>> }.KyC.....6L}.......#..) >>> .I.!.9..HTTP/1.0 200 Connection Established >>> >>> 16:56:23.125757 IP 192.168.201.6.9122 > 192.168.202.3.37417: P >>> 38:76(38) ack 201 win 54 <nop,nop,timestamp 441040673 3392783764> >>> }.pyC.....6W........#..) >>> .I.!.9..Proxy-agent: Apache/2.2.3 (CentOS) >>> _______________________________________________ >>> jetty-users mailing list >>> jetty-users@eclipse.org >>> https://dev.eclipse.org/mailman/listinfo/jetty-users >> _______________________________________________ >> jetty-users mailing list >> jetty-users@eclipse.org >> https://dev.eclipse.org/mailman/listinfo/jetty-users > > _______________________________________________ > jetty-users mailing list > jetty-users@eclipse.org > https://dev.eclipse.org/mailman/listinfo/jetty-users > _______________________________________________ jetty-users mailing list jetty-users@eclipse.org https://dev.eclipse.org/mailman/listinfo/jetty-users