Buy commercial curl support from WolfSSL. We help you work
out your issues, debug your libcurl applications, use the API, port to new
platforms, add new features and more. With a team lead by the curl founder
himself.
Re: Sending a largish POST request with --limit-rate delays receiving of small server response
- Contemporary messages sorted: [ by date ] [ by thread ] [ by subject ] [ by author ] [ by messages with attachments ]
From: Fabian Keil via curl-library <curl-library_at_cool.haxx.se>
Date: Fri, 26 Mar 2021 17:58:35 +0100
Fabian Keil via curl-library <curl-library_at_cool.haxx.se> wrote on 2021-03-26:
> Fabian Keil via curl-library <curl-library_at_cool.haxx.se> wrote on
> 2021-03-26:
>
> > Fabian Keil via curl-library <curl-library_at_cool.haxx.se> wrote on
> > 2021-03-26:
> >
> > > Daniel Stenberg <daniel_at_haxx.se> wrote on 2021-03-26:
> > >
> > > > On Fri, 26 Mar 2021, Fabian Keil via curl-library wrote:
> > > >
> > > > > Apparently the rate limit only kicks in after the request has
> > > > > been sent and as a result the (small) response is then received
> > > > > delayed.
> > >
> > > > Proposed fix: https://github.com/curl/curl/pull/6797
> > >
> > > Thanks for the quick fix.
> >
> > Looks like there's a regression.
> >
> > If the --limit-rate value is smaller than the CONNECT request
> > curl now hangs after the first write until Privoxy's connection
> > timeout is triggered:
>
> Thanks for the update pushed to bagder/http-post-speed-limit.
>
> With the commit 9334e4de31a added, one of my tests for Privoxy
> reliably triggers a DEBUGASSERT in curl.
With commit e7dcf9a105 added the test no longer results in
a core dump but it results in a "protocol FAILED!" message.
From Privoxy's point of view it looks like curl fails to send the
remaining request data.
An excerpt from the Privoxy log:
17:44:59.288 802417400 Connect: Client successfully connected over TLSv1.3 (TLS13-AES128-GCM-SHA256).
17:44:59.288 802417400 Header: Reading encrypted headers
17:44:59.288 802417400 Received: TLS from socket 4: POST /6 HTTP/1.1[...]padding
17:44:59.288 802417400 Header: Encrypted headers received completely
[...]
17:44:59.289 802417400 Connect: Connected to 127.0.0.1[127.0.0.1]:24984.
17:44:59.289 802417400 Connect: Created new connection to 127.0.0.1:24984 on socket 5.
17:44:59.289 802417400 Connect: Performing the TLS/SSL handshake with the server
17:44:59.295 802417400 Connect: Server successfully connected over TLSv1.2 (ECDHE-RSA-AES256-GCM-SHA384).
17:45:02.297 802417400 Connect: Not enough encrypted request body has been read: expected 30912 more bytes
17:45:02.301 802417400 Crunch: Connection failure: https://127.0.0.1:24984/6
From the curl trace:
17:44:59.727541 => Send SSL data, 1 bytes (0x1)
0000: .
17:44:59.727571 => Send header, 157 bytes (0x9d)
0000: POST /6 HTTP/1.1
0012: Host: 127.0.0.1:24984
0029: User-Agent: curl/7.76.0-DEV
0046: Accept: */*
0053: Content-Length: 35008
006a: Content-Type: application/x-www-form-urlencoded
009b:
17:44:59.727624 => Send data, 4096 bytes (0x1000)
0000: blafaselpaddingpaddingpaddingpaddingpaddingpaddingpaddingpadding
[...]
0fc0: gpaddingpaddingpaddingpaddingpaddingpaddingpaddingpaddingpadding
17:44:59.728413 == Info: STATE: DO => DID handle 0x8030f8808; line 1922 (connection #0)
17:44:59.728424 == Info: STATE: DID => PERFORMING handle 0x8030f8808; line 2041 (connection #0)
17:44:59.728434 == Info: STATE: PERFORMING => RATELIMITING handle 0x8030f8808; line 2126 (connection #0)
17:45:00.711536 == Info: STATE: RATELIMITING => PERFORMING handle 0x8030f8808; line 2090 (connection #0)
17:45:00.711581 <= Recv SSL data, 5 bytes (0x5)
0000: .....
17:45:00.711635 <= Recv SSL data, 1 bytes (0x1)
0000: .
17:45:00.711666 == Info: TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
17:45:00.711669 <= Recv SSL data, 160 bytes (0xa0)
0000: .......,.........C..........F.)r.tB.......:..uhr.LM.....qE>+I9..
0040: .>/5......X.t.,.\.Yf...r.<.K......B..=B...3.....9UK.......E<..O.
0080: ......p.^?..B.5..................
17:45:02.741409 <= Recv SSL data, 5 bytes (0x5)
0000: .....
17:45:02.741466 <= Recv SSL data, 1 bytes (0x1)
0000: .
17:45:02.741513 == Info: Mark bundle as not supporting multiuse
17:45:02.741520 == Info: HTTP 1.1 or later with persistent connection
17:45:02.741527 <= Recv header, 29 bytes (0x1d)
0000: HTTP/1.1 503 Connect failed
The "Connect failed" response sent by Privoxy isn't entirely accurate,
the real problem seems to be that the socket timeout is triggered.
I should probably add fixing this to the TODO list ...
Fabian
-------------------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.se/mail/etiquette.html
Received on 2021-03-26
Date: Fri, 26 Mar 2021 17:58:35 +0100
Fabian Keil via curl-library <curl-library_at_cool.haxx.se> wrote on 2021-03-26:
> Fabian Keil via curl-library <curl-library_at_cool.haxx.se> wrote on
> 2021-03-26:
>
> > Fabian Keil via curl-library <curl-library_at_cool.haxx.se> wrote on
> > 2021-03-26:
> >
> > > Daniel Stenberg <daniel_at_haxx.se> wrote on 2021-03-26:
> > >
> > > > On Fri, 26 Mar 2021, Fabian Keil via curl-library wrote:
> > > >
> > > > > Apparently the rate limit only kicks in after the request has
> > > > > been sent and as a result the (small) response is then received
> > > > > delayed.
> > >
> > > > Proposed fix: https://github.com/curl/curl/pull/6797
> > >
> > > Thanks for the quick fix.
> >
> > Looks like there's a regression.
> >
> > If the --limit-rate value is smaller than the CONNECT request
> > curl now hangs after the first write until Privoxy's connection
> > timeout is triggered:
>
> Thanks for the update pushed to bagder/http-post-speed-limit.
>
> With the commit 9334e4de31a added, one of my tests for Privoxy
> reliably triggers a DEBUGASSERT in curl.
With commit e7dcf9a105 added the test no longer results in
a core dump but it results in a "protocol FAILED!" message.
From Privoxy's point of view it looks like curl fails to send the
remaining request data.
An excerpt from the Privoxy log:
17:44:59.288 802417400 Connect: Client successfully connected over TLSv1.3 (TLS13-AES128-GCM-SHA256).
17:44:59.288 802417400 Header: Reading encrypted headers
17:44:59.288 802417400 Received: TLS from socket 4: POST /6 HTTP/1.1[...]padding
17:44:59.288 802417400 Header: Encrypted headers received completely
[...]
17:44:59.289 802417400 Connect: Connected to 127.0.0.1[127.0.0.1]:24984.
17:44:59.289 802417400 Connect: Created new connection to 127.0.0.1:24984 on socket 5.
17:44:59.289 802417400 Connect: Performing the TLS/SSL handshake with the server
17:44:59.295 802417400 Connect: Server successfully connected over TLSv1.2 (ECDHE-RSA-AES256-GCM-SHA384).
17:45:02.297 802417400 Connect: Not enough encrypted request body has been read: expected 30912 more bytes
17:45:02.301 802417400 Crunch: Connection failure: https://127.0.0.1:24984/6
From the curl trace:
17:44:59.727541 => Send SSL data, 1 bytes (0x1)
0000: .
17:44:59.727571 => Send header, 157 bytes (0x9d)
0000: POST /6 HTTP/1.1
0012: Host: 127.0.0.1:24984
0029: User-Agent: curl/7.76.0-DEV
0046: Accept: */*
0053: Content-Length: 35008
006a: Content-Type: application/x-www-form-urlencoded
009b:
17:44:59.727624 => Send data, 4096 bytes (0x1000)
0000: blafaselpaddingpaddingpaddingpaddingpaddingpaddingpaddingpadding
[...]
0fc0: gpaddingpaddingpaddingpaddingpaddingpaddingpaddingpaddingpadding
17:44:59.728413 == Info: STATE: DO => DID handle 0x8030f8808; line 1922 (connection #0)
17:44:59.728424 == Info: STATE: DID => PERFORMING handle 0x8030f8808; line 2041 (connection #0)
17:44:59.728434 == Info: STATE: PERFORMING => RATELIMITING handle 0x8030f8808; line 2126 (connection #0)
17:45:00.711536 == Info: STATE: RATELIMITING => PERFORMING handle 0x8030f8808; line 2090 (connection #0)
17:45:00.711581 <= Recv SSL data, 5 bytes (0x5)
0000: .....
17:45:00.711635 <= Recv SSL data, 1 bytes (0x1)
0000: .
17:45:00.711666 == Info: TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
17:45:00.711669 <= Recv SSL data, 160 bytes (0xa0)
0000: .......,.........C..........F.)r.tB.......:..uhr.LM.....qE>+I9..
0040: .>/5......X.t.,.\.Yf...r.<.K......B..=B...3.....9UK.......E<..O.
0080: ......p.^?..B.5..................
17:45:02.741409 <= Recv SSL data, 5 bytes (0x5)
0000: .....
17:45:02.741466 <= Recv SSL data, 1 bytes (0x1)
0000: .
17:45:02.741513 == Info: Mark bundle as not supporting multiuse
17:45:02.741520 == Info: HTTP 1.1 or later with persistent connection
17:45:02.741527 <= Recv header, 29 bytes (0x1d)
0000: HTTP/1.1 503 Connect failed
The "Connect failed" response sent by Privoxy isn't entirely accurate,
the real problem seems to be that the socket timeout is triggered.
I should probably add fixing this to the TODO list ...
Fabian
-------------------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.se/mail/etiquette.html
- application/pgp-signature attachment: OpenPGP digital signature