Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]

Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server

From: Gilman Tolle <gilman.tolle@xxxxxxxxx>
Date: Tue, 20 Dec 2011 20:47:40 -0800
Delivered-to: jetty-users@xxxxxxxxxxx
List-archive: <https://dev.eclipse.org/mailman/private/jetty-users>
List-help: <mailto:jetty-users-request@eclipse.org?subject=help>
List-subscribe: <https://dev.eclipse.org/mailman/listinfo/jetty-users>, <mailto:jetty-users-request@eclipse.org?subject=subscribe>
List-unsubscribe: <https://dev.eclipse.org/mailman/options/jetty-users>, <mailto:jetty-users-request@eclipse.org?subject=unsubscribe>

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 <janb@xxxxxxxxxxx> 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 <gilman.tolle@xxxxxxxxx> 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 <janb@xxxxxxxxxxx> 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 <gilman.tolle@xxxxxxxxx> 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
>>>> 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
>>>>
>>>> _______________________________________________
>>>> 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
>>
>> _______________________________________________
>> 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

2011-12-20 20:39:17.496:DBUG:oejuc.AbstractLifeCycle:starting org.eclipse.jetty.client.HttpClient@38c5c3ac#STOPPED
2011-12-20 20:39:17.503:DBUG:oejuc.AbstractLifeCycle:starting HttpClient{8<=0<=0/16,-1}#STOPPED
2011-12-20 20:39:17.506:DBUG:oejuc.AbstractLifeCycle:STARTED HttpClient{8<=7<=8/16,0}#STARTED
2011-12-20 20:39:17.506:DBUG:oejuc.AbstractLifeCycle:starting org.eclipse.jetty.http.ssl.SslContextFactory@5cdf8f5e#STOPPED
***
[Confidential SSL identifying information snipped]
trigger seeding of SecureRandom
done seeding SecureRandom
Using SSLEngineImpl.
2011-12-20 20:39:17.856:INFO:oejus.SslContextFactory:Enabled Protocols [SSLv2Hello, TLSv1, SSLv3] of [SSLv2Hello, SSLv3, TLSv1]
2011-12-20 20:39:17.857:DBUG:oejus.SslContextFactory:Enabled Ciphers   [TLS_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_DES_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA] of [SSL_RSA_WITH_RC4_128_MD5, SSL_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, SSL_RSA_WITH_NULL_MD5, SSL_RSA_WITH_NULL_SHA, SSL_DH_anon_WITH_RC4_128_MD5, TLS_DH_anon_WITH_AES_128_CBC_SHA, SSL_DH_anon_WITH_3DES_EDE_CBC_SHA, SSL_DH_anon_WITH_DES_CBC_SHA, SSL_DH_anon_EXPORT_WITH_RC4_40_MD5, SSL_DH_anon_EXPORT_WITH_DES40_CBC_SHA, TLS_KRB5_WITH_RC4_128_SHA, TLS_KRB5_WITH_RC4_128_MD5, TLS_KRB5_WITH_3DES_EDE_CBC_SHA, TLS_KRB5_WITH_3DES_EDE_CBC_MD5, TLS_KRB5_WITH_DES_CBC_SHA, TLS_KRB5_WITH_DES_CBC_MD5, TLS_KRB5_EXPORT_WITH_RC4_40_SHA, TLS_KRB5_EXPORT_WITH_RC4_40_MD5, TLS_KRB5_EXPORT_WITH_DES_CBC_40_SHA, TLS_KRB5_EXPORT_WITH_DES_CBC_40_MD5]
2011-12-20 20:39:17.857:DBUG:oejuc.AbstractLifeCycle:STARTED org.eclipse.jetty.http.ssl.SslContextFactory@5cdf8f5e#STARTED
2011-12-20 20:39:17.862:DBUG:oejuc.AbstractLifeCycle:starting org.eclipse.jetty.client.SelectConnector@ac980c9#STOPPED
2011-12-20 20:39:17.862:DBUG:oejuc.AbstractLifeCycle:starting org.eclipse.jetty.client.SelectConnector$Manager@332611a7#STOPPED
2011-12-20 20:39:17.869:DBUG:oejuc.AbstractLifeCycle:STARTED org.eclipse.jetty.client.SelectConnector$Manager@332611a7#STARTED
2011-12-20 20:39:17.869:DBUG:oejuc.AbstractLifeCycle:STARTED org.eclipse.jetty.client.SelectConnector@ac980c9#STARTED
2011-12-20 20:39:17.870:DBUG:oejuc.AbstractLifeCycle:STARTED org.eclipse.jetty.client.HttpClient@38c5c3ac#STARTED
2011-12-20 20:39:17.884:DBUG:oejc.HttpExchange:URI = https://192.168.201.4:8443/
2011-12-20 20:39:17.889:DBUG:oejc.HttpExchange:setStatus 1 MyContentExchange@7e78fc6=GET//192.168.201.4:8443/#START(5ms)->CONNECTING(0ms)
2011-12-20 20:39:17.904:DBUG:oeji.nio:Starting Thread[HttpClient-8 Selector0,5,main] on org.eclipse.jetty.io.nio.SelectorManager$1@144aa0ce
2011-12-20 20:39:17.904:DBUG:oejc.SelectConnector:Channels with connection pending: 0
2011-12-20 20:39:17.909:DBUG:oejc.SelectConnector:secure to java.nio.channels.SocketChannel[connected local=/192.168.202.3:35217 remote=/192.168.201.6:9122], proxied=true
Using SSLEngineImpl.
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
%% No cached client session
*** ClientHello, TLSv1
RandomCookie:  GMT: 1307664885 bytes = { 12, 16, 233, 240, 215, 155, 246, 20, 66, 52, 59, 4, 158, 243, 100, 230, 121, 121, 141, 202, 102, 104, 182, 143, 242, 179, 25, 125 }
Session ID:  {}
Cipher Suites: [TLS_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_DES_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA]
Compression Methods:  { 0 }
***
HttpClient-8 Selector0, WRITE: TLSv1 Handshake, length = 75
HttpClient-8 Selector0, WRITE: SSLv2 client hello message, length = 101
2011-12-20 20:39:17.938:DBUG:oejc.AbstractHttpConnection:Send ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#START(5ms) on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}
2011-12-20 20:39:17.940:DBUG:oejc.HttpExchange:setStatus 2 ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#START(7ms)->CONNECTED(0ms)
2011-12-20 20:39:17.941:DBUG:oeji.nio:created SCEP@151ca803{l(/192.168.201.6:9122)<->r(/192.168.202.3:35217),d=true,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=0}-{AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}}
2011-12-20 20:39:17.942:DBUG:oejc.AsyncHttpConnection:while open=true more=false progress=true
2011-12-20 20:39:17.943:DBUG:oejc.AsyncHttpConnection:exchange ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#START(7ms)->CONNECTED(3ms) on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}
2011-12-20 20:39:17.944:DBUG:oejc.AsyncHttpConnection:commit ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#START(7ms)->CONNECTED(4ms)
2011-12-20 20:39:17.944:DBUG:oejc.HttpExchange:setStatus 3 ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONNECTED(4ms)->SENDING(0ms)sent=0ms
2011-12-20 20:39:17.949:DBUG:oejc.HttpExchange:setStatus 4 ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#SENDING(5ms)->WAITING(0ms)sent=5ms
2011-12-20 20:39:17.950:DBUG:oejc.AsyncHttpConnection:flushed
2011-12-20 20:39:17.950:DBUG:oejc.AsyncHttpConnection:complete ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#SENDING(5ms)->WAITING(1ms)sent=6ms
2011-12-20 20:39:17.950:DBUG:oejc.AsyncHttpConnection:requestComplete ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#SENDING(5ms)->WAITING(1ms)sent=6ms
2011-12-20 20:39:17.951:DBUG:oejh.HttpParser:filled 0/0
2011-12-20 20:39:17.951:DBUG:oejc.AsyncHttpConnection:finally ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#SENDING(5ms)->WAITING(2ms)sent=7ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0} progress=true Upgradable:SCEP@151ca803{l(/192.168.201.6:9122)<->r(/192.168.202.3:35217),d=true,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=0}-{AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}}
2011-12-20 20:39:17.952:DBUG:oejc.AsyncHttpConnection:while open=true more=false progress=true
2011-12-20 20:39:17.952:DBUG:oejc.AsyncHttpConnection:exchange ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#SENDING(5ms)->WAITING(3ms)sent=8ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}
2011-12-20 20:39:17.953:DBUG:oejh.HttpParser:filled 75/75
2011-12-20 20:39:17.954:DBUG:oejc.HttpExchange:setStatus 5 ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#WAITING(4ms)->HEADERS(1ms)sent=10ms
2011-12-20 20:39:17.954:DBUG:oejc.HttpExchange:setStatus 6 ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#HEADERS(1ms)->CONTENT(0ms)sent=10ms
2011-12-20 20:39:17.954:DBUG:oejc.AsyncHttpConnection:parsed ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#HEADERS(1ms)->CONTENT(0ms)sent=10ms
2011-12-20 20:39:17.955:DBUG:oejc.AsyncHttpConnection:finally ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#HEADERS(1ms)->CONTENT(1ms)sent=11ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=1,l=21,c=-1} progress=true Upgradable:SCEP@151ca803{l(/192.168.201.6:9122)<->r(/192.168.202.3:35217),d=true,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=0r}-{AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=1,l=21,c=-1}}
2011-12-20 20:39:17.960:DBUG:oejc.AsyncHttpConnection:while open=true more=false progress=true
2011-12-20 20:39:17.960:DBUG:oejc.AsyncHttpConnection:exchange ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#HEADERS(1ms)->CONTENT(6ms)sent=16ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=1,l=21,c=-1}
2011-12-20 20:39:17.961:DBUG:oejh.HttpParser:filled 0/0
2011-12-20 20:39:17.964:DBUG:oejc.SelectConnector:upgrade Upgradable:SSL NEED_WRAP i/o/u=-1/-1/-1 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}} to SslConnection@7b5a6029 SSL NEED_WRAP i/o/u=-1/-1/-1 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}} for AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}
2011-12-20 20:39:17.966:DBUG:oejc.HttpExchange:setStatus 7 ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONTENT(7ms)->COMPLETED(5ms)sent=22ms
2011-12-20 20:39:17.967:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_WRAP i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}} NEED_WRAP filled=0/0 flushed=0/0
2011-12-20 20:39:17.972:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] wrap OK NEED_UNWRAP consumed=0 produced=103
2011-12-20 20:39:17.972:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}} NEED_UNWRAP filled=0/0 flushed=103/0
2011-12-20 20:39:17.973:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}} NEED_UNWRAP filled=0/0 flushed=0/0
2011-12-20 20:39:17.974:DBUG:oejc.AsyncHttpConnection:hasProgressed ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONTENT(7ms)->COMPLETED(13ms)sent=30ms
2011-12-20 20:39:17.974:DBUG:oejc.AsyncHttpConnection:finally ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONTENT(7ms)->COMPLETED(13ms)sent=30ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1} progress=true Upgradable:SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}}
2011-12-20 20:39:17.976:DBUG:oejc.AsyncHttpConnection:while open=true more=false progress=true
2011-12-20 20:39:17.976:DBUG:oejc.AsyncHttpConnection:exchange ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONTENT(7ms)->COMPLETED(15ms)sent=32ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}
2011-12-20 20:39:17.977:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}} NEED_UNWRAP filled=0/0 flushed=0/0
2011-12-20 20:39:17.977:DBUG:oejh.HttpParser:filled 0/0
2011-12-20 20:39:17.978:DBUG:oejc.AsyncHttpConnection:Failure on ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONTENT(7ms)->COMPLETED(17ms)sent=34ms
java.lang.IllegalStateException: COMPLETED => COMPLETED
	at org.eclipse.jetty.client.HttpExchange.setStatus(HttpExchange.java:365)
	at org.eclipse.jetty.client.AbstractHttpConnection$Handler.messageComplete(AbstractHttpConnection.java:335)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:814)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:233)
	at org.eclipse.jetty.client.AsyncHttpConnection.handle(AsyncHttpConnection.java:126)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:623)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:45)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:598)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:533)
	at java.lang.Thread.run(Thread.java:662)
2011-12-20 20:39:17.979:DBUG:oejc.AsyncHttpConnection:finally ConnectExchange@1c5dd582=CONNECT//192.168.201.6:9122192.168.201.4:8443#CONTENT(7ms)->COMPLETED(18ms)sent=35ms on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1} progress=false Upgradable:SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=21,c=-1}}
2011-12-20 20:39:17.980:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] ssl endp.oshut SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=false {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}
HttpClient-10, called closeOutbound()
HttpClient-10, closeOutboundInternal()
HttpClient-10, SEND TLSv1 ALERT:  warning, description = close_notify
HttpClient-10, WRITE: TLSv1 Alert, length = 2
2011-12-20 20:39:17.982:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_WRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}} NEED_WRAP filled=0/0 flushed=0/0
2011-12-20 20:39:17.983:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] wrap CLOSED NEED_UNWRAP consumed=0 produced=7
2011-12-20 20:39:17.983:DBUG:oejin.ssl:wrap CLOSE SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/7/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}} Status = CLOSED HandshakeStatus = NEED_UNWRAP
bytesConsumed = 0 bytesProduced = 7
2011-12-20 20:39:17.984:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}} NEED_UNWRAP filled=0/0 flushed=7/0
2011-12-20 20:39:17.985:DBUG:oejin.ChannelEndPoint:oshut SCEP@151ca803{l(/192.168.201.6:9122)<->r(/192.168.202.3:35217),d=true,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=0r}-{SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}}
2011-12-20 20:39:17.986:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}} NEED_UNWRAP filled=0/0 flushed=0/0
2011-12-20 20:39:17.988:DBUG:oejin.ChannelEndPoint:oshut SCEP@151ca803{l(/192.168.201.6:9122)<->r(/192.168.202.3:35217),d=true,open=true,ishut=false,oshut=true,rb=false,wb=false,w=true,i=0r}-{SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=4,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}}
2011-12-20 20:39:17.989:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] ssl endp.close
2011-12-20 20:39:17.989:DBUG:oejin.ChannelEndPoint:close SCEP@151ca803{l(/192.168.201.6:9122)<->r(/192.168.202.3:35217),d=true,open=true,ishut=false,oshut=true,rb=false,wb=false,w=true,i=0r}-{SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=0,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}}
2011-12-20 20:39:17.992:DBUG:oejc.AsyncHttpConnection:unhandle null on Upgradable:SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}
2011-12-20 20:39:17.993:DBUG:oeji.nio:AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3} replaced SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}
2011-12-20 20:39:17.994:DBUG:oejc.AsyncHttpConnection:while open=false more=false progress=true
2011-12-20 20:39:17.994:DBUG:oejc.AsyncHttpConnection:exchange null on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}
2011-12-20 20:39:17.995:DBUG:oejin.ChannelEndPoint:java.nio.channels.ClosedChannelException
2011-12-20 20:39:17.994:DBUG:oeji.nio:destroyEndPoint SCEP@151ca803{l(null)<->r(/192.168.202.3:35217),d=true,open=false,ishut=true,oshut=true,rb=false,wb=false,w=true,i=0!}-{AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}}
2011-12-20 20:39:17.995:DBUG:oejc.SelectConnector:Channels with connection pending: 0
2011-12-20 20:39:17.995:DBUG:oejc.SelectConnector:secure to java.nio.channels.SocketChannel[connected local=/192.168.202.3:35218 remote=/192.168.201.6:9122], proxied=true
Using SSLEngineImpl.
Allow unsafe renegotiation: false
Allow legacy hello messages: true
Is initial handshake: true
Is secure renegotiation: false
%% No cached client session
*** ClientHello, TLSv1
RandomCookie:  GMT: 1307664885 bytes = { 219, 185, 15, 49, 33, 171, 122, 1302011-12-20 20:39:17.995:IGNORED:oejin.ChannelEndPoint:
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureReadOpen(SocketChannelImpl.java:120)
	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:163)
	at org.eclipse.jetty.io.nio.ChannelEndPoint.fill(ChannelEndPoint.java:230)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.fill(SelectChannelEndPoint.java:314)
	at org.eclipse.jetty.io.nio.SslConnection.process(SslConnection.java:313)
	at org.eclipse.jetty.io.nio.SslConnection.process(SslConnection.java:284)
	at org.eclipse.jetty.io.nio.SslConnection.access$700(SslConnection.java:43)
	at org.eclipse.jetty.io.nio.SslConnection$SslEndPoint.fill(SslConnection.java:645)
	at org.eclipse.jetty.client.SelectConnector$UpgradableEndPoint.fill(SelectConnector.java:337)
	at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1055)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:233)
	at org.eclipse.jetty.client.AsyncHttpConnection.handle(AsyncHttpConnection.java:126)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:623)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:45)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:598)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:533)
	at java.lang.Thread.run(Thread.java:662)
, 201, 209, 176, 23, 254, 93, 252, 1052011-12-20 20:39:17.997:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=7,l=0,c=-3}} NEED_UNWRAP filled=-1/0 flushed=0/0
2011-12-20 20:39:17.998:DBUG:oejh.HttpParser:filled -1/0
, 2011-12-20 20:39:17.998:DBUG:oejin.ChannelEndPoint:java.nio.channels.ClosedChannelException
98, 12, 75, 114, 602011-12-20 20:39:17.998:IGNORED:oejin.ChannelEndPoint:
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureReadOpen(SocketChannelImpl.java:120)
	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:163)
	at org.eclipse.jetty.io.nio.ChannelEndPoint.fill(ChannelEndPoint.java:230)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.fill(SelectChannelEndPoint.java:314)
	at org.eclipse.jetty.io.nio.SslConnection.process(SslConnection.java:313)
	at org.eclipse.jetty.io.nio.SslConnection.access$700(SslConnection.java:43)
	at org.eclipse.jetty.io.nio.SslConnection$SslEndPoint.flush(SslConnection.java:705)
	at org.eclipse.jetty.client.SelectConnector$UpgradableEndPoint.flush(SelectConnector.java:427)
	at org.eclipse.jetty.client.AsyncHttpConnection.handle(AsyncHttpConnection.java:133)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:623)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:45)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:598)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:533)
	at java.lang.Thread.run(Thread.java:662)
, 168, 185, 194, 113, 18, 26, 117 }
Session ID:  2011-12-20 20:39:17.999:DBUG:oejin.ssl:[Session-1, SSL_NULL_WITH_NULL_NULL] SslConnection@7b5a6029 SSL NEED_UNWRAP i/o/u=0/0/0 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=0,l=0,c=-3}} NEED_UNWRAP filled=-1/0 flushed=0/0
2011-12-20 20:39:17.999:DBUG:oejc.AsyncHttpConnection:hasProgressed null
{}
Cipher Suites: [TLS_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_RSA_WITH_AES_128_CBC_SHA, SSL_DHE_RSA_WITH_DES_CBC_SHA, SSL_DHE_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_RC4_40_MD5, SSL_DHE_RSA_WITH_3DES_EDE_CBC_SHA, SSL_RSA_WITH_RC4_128_SHA, SSL_RSA_WITH_DES_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV, SSL_DHE_DSS_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_EXPORT_WITH_DES40_CBC_SHA, SSL_RSA_WITH_RC4_128_MD5, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, SSL_DHE_DSS_WITH_3DES_EDE_CBC_SHA, SSL_DHE_DSS_WITH_DES_CBC_SHA, SSL_RSA_WITH_3DES_EDE_CBC_SHA]
Compression Methods:  { 0 }
***
HttpClient-8 Selector0, WRITE: TLSv1 Handshake, length = 75
HttpClient-8 Selector0, WRITE: SSLv2 client hello message, length = 101
2011-12-20 20:39:18.000:DBUG:oejc.AbstractHttpConnection:Send ConnectExchange@979dce4=CONNECT//192.168.201.6:9122192.168.201.4:8443#START(0ms) on AsyncHttpConnection@6f9bb25a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}
2011-12-20 20:39:18.002:DBUG:oejc.HttpExchange:setStatus 2 ConnectExchange@979dce4=CONNECT//192.168.201.6:9122192.168.201.4:8443#START(2ms)->CONNECTED(0ms)
2011-12-20 20:39:18.002:DBUG:oeji.nio:created SCEP@56da6bf4{l(/192.168.201.6:9122)<->r(/192.168.202.3:35218),d=true,open=true,ishut=false,oshut=false,rb=false,wb=false,w=true,i=0}-{AsyncHttpConnection@6f9bb25a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=-14,l=0,c=0}}
2011-12-20 20:39:17.999:DBUG:oejc.AsyncHttpConnection:finally null on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=0,l=0,c=-3} progress=true Upgradable:SSL NEED_UNWRAP i/o/u=-1/-1/-1 ishut=false oshut=true {AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=0,l=0,c=-3}}
2011-12-20 20:39:18.014:DBUG:oejc.AsyncHttpConnection:while open=false more=false progress=true
2011-12-20 20:39:18.014:DBUG:oejc.AsyncHttpConnection:exchange null on AsyncHttpConnection@546c585a 192.168.201.4:8443 g=HttpGenerator{s=0,h=-1,b=-1,c=-1} p=HttpParser{s=0,l=0,c=-3}
2011-12-20 20:39:18.016:DBUG:oejin.ChannelEndPoint:java.nio.channels.ClosedChannelException
2011-12-20 20:39:18.016:IGNORED:oejin.ChannelEndPoint:
java.nio.channels.ClosedChannelException
	at sun.nio.ch.SocketChannelImpl.ensureReadOpen(SocketChannelImpl.java:120)
	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:163)
	at org.eclipse.jetty.io.nio.ChannelEndPoint.fill(ChannelEndPoint.java:230)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.fill(SelectChannelEndPoint.java:314)

Attachment: jetty-client-proxy-8.1.0-20111221.035843-3.pcap
Description: Binary data

Follow-Ups:
- Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Gilman Tolle

References:
- [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Gilman Tolle
- Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Jan Bartel
- Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Gilman Tolle
- Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Jan Bartel
- Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Gilman Tolle
- Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
  - From: Jan Bartel

Prev by Date: Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
Next by Date: [jetty-users] various problems with embedded jetty (in web app)
Previous by thread: Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
Next by thread: Re: [jetty-users] Jetty client v8.0.4 - problem opening HTTPS connection through HTTP proxy server
Index(es):
- Date
- Thread

Breadcrumbs