| Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server |
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
SSLSCEP@xxxxxxxxxxxxxxxxxx.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
SSLSCEP@xxxxxxxxxxxxxxxxxx.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
SSLSCEP@xxxxxxxxxxxxxxxxx.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
SSLSCEP@xxxxxxxxxxxxxxxxx.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 <janb@xxxxxxxxxxx> 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.tolle@xxxxxxxxx> 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@xxxxxxxxxxx
>> https://dev.eclipse.org/mailman/listinfo/jetty-users
> _______________________________________________
> jetty-users mailing list
> jetty-users@xxxxxxxxxxx
> https://dev.eclipse.org/mailman/listinfo/jetty-users
Attachment:
jetty-client-proxy.pcap
Description: Binary data