On Mon, Oct 6, 2014 at 5:58 PM, Scott Mitchell <scott.k.mitch1_at_gmail.com>
wrote:

>
>
> On Mon, Oct 6, 2014 at 5:48 PM, Scott Mitchell <scott.k.mitch1_at_gmail.com>
> wrote:
>
>>
>>
>> On Mon, Oct 6, 2014 at 5:24 PM, Daniel Stenberg <daniel_at_haxx.se> wrote:
>>
>>> On Mon, 6 Oct 2014, Scott Mitchell wrote:
>>>
>>> curl will attempt to use the same connection for both (all) requests but
>>>>> probably something makes the server or curl to close that connection
>>>>> and
>>>>> make a new one for the second one.
>>>>>
>>>>
>>> curl is saying that it can re-use connection 0 and then issues the
>>>> second stream 3 request. Other than curl attempting to re-try the request
>>>> I don't see how this relates to the second connection being made.
>>>>
>>>
>>> I don't see curl mentioning any second connection?
>>>
>>> I apologize. I provided abbreviated output and the second connection
>> starts at the end. To avoid confusion here is the full output.
>>
>>
>> $ curl --http2 -k 'https://10.0.2.2:13443/proxy/address' -H "accept:
>> application/vnd.akamai.query" -d '<post body 1>' -i -v -o dump1_1 --next
>> --http2 -k 'https://10.0.2.2:13443/sql' -H "accept:
>> application/vnd.akamai.query" -d '<post body 2>' -i -v -o dump2_1
>> * Hostname was NOT found in DNS cache
>> * Trying 10.0.2.2...
>> % Total % Received % Xferd Average Speed Time Time Time
>> Current
>> Dload Upload Total Spent Left
>> Speed
>> 0 0 0 0 0 0 0 0 --:--:-- --:--:--
>> --:--:-- 0* Connected to 10.0.2.2 (10.0.2.2) port 13443 (#0)
>> * successfully set certificate verify locations:
>> * CAfile: /etc/ssl/certs/ca-certificates.crt
>> CApath: none
>> * SSLv3, TLS Unknown, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Client hello (1):
>> } [data not shown]
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, Server hello (2):
>> { [data not shown]
>> * NPN, negotiated HTTP2 (h2-14)
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, CERT (11):
>> { [data not shown]
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, Server key exchange (12):
>> { [data not shown]
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, Server finished (14):
>> { [data not shown]
>> * SSLv2, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Client key exchange (16):
>> } [data not shown]
>> * SSLv2, Unknown (20):
>> } [data not shown]
>> * SSLv3, TLS change cipher, Client hello (1):
>> } [data not shown]
>> * SSLv2, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Unknown (67):
>> } [data not shown]
>> * SSLv2, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Finished (20):
>> } [data not shown]
>> * SSLv2, Unknown (20):
>> { [data not shown]
>> * SSLv3, TLS change cipher, Client hello (1):
>> { [data not shown]
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, Finished (20):
>> { [data not shown]
>> * SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
>> * Server certificate:
>> * subject: C=US; ST=MA; L=<town>; O=<company>; OU=<company>;
>> CN=<user name>; emailAddress=<user name>@akamai.com
>> * start date: 2014-09-24 21:38:31 GMT
>> * expire date: 2015-09-24 21:38:31 GMT
>> * issuer: C=US; ST=MA; L=<town>; O=<company>; OU=<company>; CN=<user
>> name>; emailAddress=<user name>@akamai.com
>> * SSL certificate verify result: self signed certificate (18),
>> continuing anyway.
>>
>> * Using HTTP2
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * http2_send len=191
>> * request content-length=115
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> > POST /proxy/address HTTP/1.1
>> > User-Agent: curl/7.38.1-DEV
>> > Host: 10.0.2.2:13443
>> > accept: application/vnd.akamai.query
>> > Content-Length: 115
>> > Content-Type: application/x-www-form-urlencoded
>> >
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=15
>> * on_frame_recv() was called with header 4
>> * nghttp2_session_mem_recv() returns 15
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> * http2_send len=115
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> } [data not shown]
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=9
>> * on_frame_recv() was called with header 4
>> * nghttp2_session_mem_recv() returns 9
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=67
>> * on_begin_headers() was called
>> * nghttp2_session_mem_recv() returns 67
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> * on_stream_close() was called, error_code = 1
>> 100 115 0 0 100 115 0 436 --:--:-- --:--:--
>> --:--:-- 438
>> * Connection #0 to host 10.0.2.2 left intact
>> * Found bundle for host 10.0.2.2: 0x853200
>> * Re-using existing connection! (#0) with host 10.0.2.2
>> * Connected to 10.0.2.2 (10.0.2.2) port 13443 (#0)
>> * Using HTTP2
>> * http2_send len=180
>> * request content-length=31
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> > POST /sql HTTP/1.1
>> > User-Agent: curl/7.38.1-DEV
>> > Host: 10.0.2.2:13443
>> > accept: application/vnd.akamai.query
>> > Content-Length: 31
>> > Content-Type: application/x-www-form-urlencoded
>> >
>> * http2_send len=31
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> } [data not shown]
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=37
>> * on_begin_headers() was called
>> * nghttp2_session_mem_recv() returns 37
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> * on_stream_close() was called, error_code = 1
>> * Connection died, retrying a fresh connect
>> 100 31 0 0 100 31 0 595 --:--:-- --:--:--
>> --:--:-- 595
>> * HTTP/2 DISCONNECT starts now
>> * HTTP/2 DISCONNECT done
>> * Closing connection 0
>> * SSLv2, Unknown (21):
>> } [data not shown]
>> * SSLv3, TLS alert, Client hello (1):
>> } [data not shown]
>> * Issue another request to this URL: 'https://10.0.2.2:13443/sql'
>> * Hostname was found in DNS cache
>> * Trying 10.0.2.2...
>> * Connected to 10.0.2.2 (10.0.2.2) port 13443 (#1)
>> * successfully set certificate verify locations:
>> * CAfile: /etc/ssl/certs/ca-certificates.crt
>> CApath: none
>> * SSL re-using session ID
>> * SSLv2, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Client hello (1):
>> } [data not shown]
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, Server hello (2):
>> { [data not shown]
>> * NPN, negotiated HTTP2 (h2-14)
>> * SSLv2, Unknown (20):
>> { [data not shown]
>> * SSLv3, TLS change cipher, Client hello (1):
>> { [data not shown]
>> * SSLv2, Unknown (22):
>> { [data not shown]
>> * SSLv3, TLS handshake, Finished (20):
>> { [data not shown]
>> * SSLv2, Unknown (20):
>> } [data not shown]
>> * SSLv3, TLS change cipher, Client hello (1):
>> } [data not shown]
>> * SSLv2, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Unknown (67):
>> } [data not shown]
>> * SSLv2, Unknown (22):
>> } [data not shown]
>> * SSLv3, TLS handshake, Finished (20):
>> } [data not shown]
>> * SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
>> * Server certificate:
>> * subject: C=US; ST=MA; L=<town>; O=<company>; OU=<company>;
>> CN=<user name>; emailAddress=<user name>@akamai.com
>> * start date: 2014-09-24 21:38:31 GMT
>> * expire date: 2015-09-24 21:38:31 GMT
>> * issuer: C=US; ST=MA; L=<town>; O=<company>; OU=<company>; CN=<user
>> name>; emailAddress=<user name>@akamai.com
>> * SSL certificate verify result: self signed certificate (18),
>> continuing anyway.
>> * Using HTTP2
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * http2_send len=180
>> * request content-length=31
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> > POST /sql HTTP/1.1
>> > User-Agent: curl/7.38.1-DEV
>> > Host: 10.0.2.2:13443
>> > accept: application/vnd.akamai.query
>> > Content-Length: 31
>> > Content-Type: application/x-www-form-urlencoded
>> >
>> * http2_send len=31
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> } [data not shown]
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=15
>> * on_frame_recv() was called with header 4
>> * nghttp2_session_mem_recv() returns 15
>> * before_frame_send() was called
>> * SSLv2, Unknown (23):
>> } [data not shown]
>> * on_frame_send() was called
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=9
>> * on_frame_recv() was called with header 4
>> * nghttp2_session_mem_recv() returns 9
>> * http2_recv: 16384 bytes buffer
>> * SSLv2, Unknown (23):
>> { [data not shown]
>> * nread=24
>> * on_begin_headers() was called
>> * got http2 header: server: http2query2
>> * on_frame_recv() was called with header 1
>> * on_stream_close() was called, error_code = 0
>> * nghttp2_session_mem_recv() returns 24
>> < HTTP/2.0 403
>> * Server http2query2 is not blacklisted
>> < server:http2query2
>> * HTTP error before end of send, stop sending
>> <
>> { [data not shown]
>> 100 31 0 0 100 31 0 258 --:--:-- --:--:--
>> --:--:-- 258
>> * HTTP/2 DISCONNECT starts now
>> * HTTP/2 DISCONNECT done
>> * Closing connection 1
>> * SSLv2, Unknown (21):
>> } [data not shown]
>> * SSLv3, TLS alert, Client hello (1):
>> } [data not shown]
>> $
>>
>>
>> I have included the application data portion of the -v output below but
>>>> are there any other debug flags that may be useful?
>>>>
>>>
>>> There's no additional level but you can get also the protocol "body"
>>> parts with --trace and --trace-ascii.
>>>
>>
> --trace-ascii is not very useful in this case as the first request does
> not generate any files. Here is the modified command syntax:
>
> $ curl --http2 -k 'https://10.0.2.2:13443/proxy/address' -H "accept:
> application/vnd.akamai.query" -d '<post body 1>' -i -o dump1_1
> --trace-ascii dump1_2 --next --http2 -k 'https://10.0.2.2:13443/sql' -H
> "accept: application/vnd.akamai.query" -d '<post body 2>' -i -o dump2_1
> --trace-ascii dump2_2
>
> After this command the only files that are generated are dump2_1 and
> dump2_2. The content of these files are from the second connection (see
> the previous thread's Observed Behaviour explanation).
>
>
>>
>>> It would be helpful to know where a protocol error is being triggered
>>>> from or in general why it is being triggered.
>>>>
>>>
>>> I agree that it would be useful at least at times, but we may need to
>>> add more logging for that.
>>>
>>> The server I am attempting to communicate with is nghttp2 based and I
>>>> am able to communicate with it from a Netty based client.
>>>>
>>>
>>> Well, we are also able to communicate with nghttp2 based servers...
>>>
>>
>> Do you have test scenarios/servers that are not HTTP/2 proxies (i.e. pure
>> HTTP/2 servers)?
>>
>>
>
Why this may be relevant is because the HTTP/2 protocol has a different
mechanism to signify the end of a request/response. An HTTP/2 proxy will
likely still preserve the HTTP/1.x header semantics in terms of ending
responses and stream transitions. So a client that works for HTTP/1.x may
not necessarily function correctly in all HTTP/2 scenarios. There are also
different semantics for content length, transfer-encoding, etc...

There are a few problems I don't have an answer to:
1) Regardless of how my server is behaving I'm not able to justify curl
creating a second connection (after it has already issued both requests on
the first connection) here. Even if curl is attempting to re-request
because it detected a previous failure (which I don't think makes sense),
why are both requests not re-issued as curl generated a RST_STREAM for both
streams on the first connection? Any thoughts?

2) Also, why is the output (-o and --trace-ascii) from the first request
being erased (or not generated at all)? I'm guessing it is because this is
related to the second connection but I'm not sure.

>>> Do you have a curl example command that mimics the described request
>>>> scheme (2 post requests, first response is headers only, second response is
>>>> headers + data) against a test server?
>>>>
>>>
>>> I'm sorry but can you show us a curl command line that doesn't work ?
>>>
>>
>> Sure. See above.
>>
>>
>>>
>>> * SSLv2, Unknown (23):
>>>>
>>>
>>> That looks bad!
>>>
>>
>> Agreed that is not the best looking output ;). However various errors
>> are displayed throughout the handshake also. The server is using openssl
>> and should be excluding sslv2 via (SSL_OP_NO_SSLv2 | SSL_OP_NO_SSLv3 |
>> SSL_OP_NO_TLSv1 | SSL_OP_NO_TLSv1_1) SSL_CTX_set_options. I have tried
>> connecting with various clients that do not support TLS v1.2 and they are
>> not able to connect. I'm not sure why the SSLv2 is being displayed at all...
>>
>>
>>>
>>> * Connection #0 to host 10.0.2.2 left intact
>>>> * Found bundle for host 10.0.2.2: 0x2073200
>>>> * Re-using existing connection! (#0) with host 10.0.2.2
>>>> * Connected to 10.0.2.2 (10.0.2.2) port 13443 (#0)
>>>>
>>>
>>> ... this shows curl re-using an existing connection for the next
>>> transfer. No new connection there. Are you saying this message output is
>>> incorrect?
>>>
>>>
>> I don't have a problem with the output itself as it seems to be
>> describing the behaviour. The problem is the behaviour is not expected.
>>
>> Expected behaviour:
>> - Curl opens 1 connection
>> - This connection has 2 streams and issues 2 post requests with <post
>> body 1> and <post body 2>.
>> - No errors and results are printed out.
>>
>> Observed behaviour:
>> - Curl opens 1 connection
>> - This connection has 2 streams and issues 2 post requests with <post
>> body 1> and <post body 2> BUT issues a RST_STREAM for each stream after
>> receiving the response. The output can not be verified at the end because
>> it is overwritten by the second connection (see next step).
>> - Curl opens a second connection
>> - This connection has 1 stream which is a post request with <post body 2>.
>>
>>
>>>
>>> --
>>>
>>> / daniel.haxx.se
>>> -------------------------------------------------------------------
>>> List admin: http://cool.haxx.se/list/listinfo/curl-users
>>> FAQ: http://curl.haxx.se/docs/faq.html
>>> Etiquette: http://curl.haxx.se/mail/etiquette.html
>>>
>>
>>
>

-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-users
FAQ: http://curl.haxx.se/docs/faq.html
Etiquette: http://curl.haxx.se/mail/etiquette.html
Received on 2014-10-07