Hello Jan, Hope you had a good holiday.
Just wanted to check in about this problem with HTTP CONNECT. After some recent experiments, I wonder if it has something to do with the fact that Apache is returning "HTTP/1.0" in response to the CONNECT, while the Jetty server CONNECT proxy returns "HTTP/1.1". Is it possible that the Jetty client requires a proxy server which supports HTTP/1.1, so that the client can send the proxied HTTP request as though it were the second request in a HTTP persistent connection? And, when the client receives a HTTP/1.0 response, the parser indicates that persistent connections aren't supported and requires the connection to be closed? Gil On Tue, Dec 20, 2011 at 8:47 PM, Gilman Tolle <[email protected]> wrote: > Hi Jan, > > Just downloaded jetty-distribution-8.1.0-20111221.035843-3.tar.gz from > that directory. It seemed like the newest snapshot there. > > Still seeing the problem. > > Logfile (plus SSL debug) and tcpdump attached. > > Thanks for looking into this. I'm curious - what kind of issues are you > seeing? > > Gil > > On Tue, Dec 20, 2011 at 7:15 PM, Jan Bartel <[email protected]> wrote: >> Hi Gil, >> >> Thanks for that info, we're getting closer to zeroing in on it. >> >> There have been a number of changes lately in trunk which may affect >> this. I've pushed a new snapshot distribution that you can download >> from here: >> https://oss.sonatype.org/content/groups/jetty/org/eclipse/jetty/jetty-distribution/8.1.0-SNAPSHOT/ >> >> It would be great if you could try with that snapshot, again with the >> debug and ignore on (and also throw in some ssl debug too, see >> http://docs.oracle.com/javase/1.5.0/docs/guide/security/jsse/JSSERefGuide.html#Debug), >> and post the output here. >> >> thanks again, >> Jan >> >> On 20 December 2011 16:14, Gilman Tolle <[email protected]> wrote: >>> Hi Jan, >>> >>> I just downloaded 8.1.0.RC0 from http://download.eclipse.org/jetty/. I >>> didn't see a jetty-8.0.5 on that page. >>> >>> The new 8.1.0.RC0 version prints a lot more debug information to >>> stdout, but it looks like a similar problem is still happening. >>> Jetty-client keeps opening up connections to the proxy without waiting >>> for the response. >>> >>> I'm still running the same test code. Added >>> -Dorg.eclipse.jetty.util.log.IGNORED=true to the java commandline. >>> >>> Log excerpt and tcpdump file attached. >>> >>> Thanks, >>> Gil >>> >>> On Mon, Dec 19, 2011 at 8:51 PM, Jan Bartel <[email protected]> wrote: >>>> 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 <[email protected]> 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 >>>>> [email protected][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 >>>>> [email protected][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 >>>>> [email protected][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 >>>>> [email protected][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 <[email protected]> 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 <[email protected]> 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@[email protected].......... ....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> >>>>>>> [email protected].............. ..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 >>>>>>> [email protected] >>>>>>> https://dev.eclipse.org/mailman/listinfo/jetty-users >>>>>> _______________________________________________ >>>>>> jetty-users mailing list >>>>>> [email protected] >>>>>> https://dev.eclipse.org/mailman/listinfo/jetty-users >>>>> >>>>> _______________________________________________ >>>>> jetty-users mailing list >>>>> [email protected] >>>>> https://dev.eclipse.org/mailman/listinfo/jetty-users >>>>> >>>> _______________________________________________ >>>> jetty-users mailing list >>>> [email protected] >>>> https://dev.eclipse.org/mailman/listinfo/jetty-users >>> >>> _______________________________________________ >>> jetty-users mailing list >>> [email protected] >>> https://dev.eclipse.org/mailman/listinfo/jetty-users >>> >> _______________________________________________ >> jetty-users mailing list >> [email protected] >> https://dev.eclipse.org/mailman/listinfo/jetty-users _______________________________________________ jetty-users mailing list [email protected] https://dev.eclipse.org/mailman/listinfo/jetty-users
