cURL / Mailing Lists / curl-library / Single Mail

curl-library

Re: Abnormal delay while receiving answer from a POST

From: Farabet Olivier via curl-library <curl-library_at_cool.haxx.se>
Date: Thu, 11 Aug 2016 08:42:22 +0000 (UTC)

Hi all,
Some good news this morning : we have identified the origin of the delay. Our browser is configured witha local apache proxy but if we configure the browser to reach the application server directly the delay disappears.
We are currently searching the origin of this behavior of the apache proxy. Any suggestion welcome.
regardsOliver

      De : Farabet Olivier via curl-library <curl-library_at_cool.haxx.se>
 À : libcurl development <curl-library_at_cool.haxx.se>
Cc : Farabet Olivier <ofarabet_at_yahoo.fr>
 Envoyé le : Mercredi 10 août 2016 10h13
 Objet : Re: Abnormal delay while receiving answer from a POST
   
Morning all,
I agree, the process polls 15 seconds to receive the data.
In the tcpdump trace though, the same data arrive quickly, so something between low level networkand libcurl recv() on the socket generates this wait.
Do you know of a parameter / reason that could explain this ?
The way we use libcurl:
curl_easy_init() once for the application
loopcurl_easy_setopt() to set exchange parameterscurl_easy_perform() to do the exchange cur_easy_reset() to reset parametersand so on

regardsOliver

      De : Daniel Stenberg <daniel_at_haxx.se>
 À : libcurl hacking <curl-library_at_cool.haxx.se>
 Envoyé le : Mardi 9 août 2016 16h55
 Objet : Re: Abnormal delay while receiving answer from a POST
  
On Tue, 9 Aug 2016, Farabet Olivier wrote:

> - strace : I've called it with -T, there are time info in system calls and
> the system calls during the gap are the following ones

I assume your mailer strips the times then or something because they certainly
don't show up here... But still, look at these strace details:

> [pid  990] write(23, "09/08/2016 10:16:02 curlWriteCal"..., 60) = 60

Is this the last received header?

> [pid  990] poll([{fd=22, events=POLLIN}], 1, 36) = 0 (Timeout)

Timeout the waiting for more data.

> [pid  990] poll([{fd=22, events=POLLIN}], 1, 1000) = 0 (Timeout)
> [pid  990] poll([{fd=22, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1,
> 0) = 0 (Timeout)

... and we see about 14 more timeouts like the one above. Each waiting 1000
milliseconds. That's saying the kernel hasn't delivered any data to the socket
for libcurl to read.

> [pid  990] poll([{fd=22, events=POLLIN}], 1, 1000) = 1 ([{fd=22,
> revents=POLLIN}])

*There*, data has finally arrived after a long time waiting. I can't see that
libcurl does anything wrong there! Can you?

> [pid  990] recvfrom(22, "oll'\" />\r\n      <var name=\"TELID"..., 1731,
> 0, NULL, NULL) = 1731

... and it reads 1731 bytes. I assume the rest then follows as it loops to
read more.

-- 
  / daniel.haxx.se
-------------------------------------------------------------------
List admin: https://cool.haxx.se/list/listinfo/curl-library
Etiquette:  https://curl.haxx.se/mail/etiquette.html
   
-------------------------------------------------------------------
List admin: https://cool.haxx.se/list/listinfo/curl-library
Etiquette:  https://curl.haxx.se/mail/etiquette.html
  

-------------------------------------------------------------------
List admin: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.haxx.se/mail/etiquette.html
Received on 2016-08-11