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.
>
> 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