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)?
>
>
>>
>> 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-06