On Thu, 25 Jul 2013, Daniel Stenberg wrote:
However, at line 75 we can see the second HTTP response being received 36817
microseconds after the data was sent! Going down the log we can see that all
subsequent responses show this exessive time.
...
I can also confirm these numbers when stracing the problematic version. Now
I'm diving into why this is happening and what I can do about it...
Using strace -T, I can also see that the poll() call actually takes that long:
23:58:38.816031 poll([{fd=3, events=POLLIN}], 1, 1002) = 1 ([{fd=3,
revents=POLLIN}]) <0.037972>
...
23:58:38.855623 poll([{fd=3, events=POLLIN}], 1, 1002) = 1 ([{fd=3,
revents=POLLIN}]) <0.038399>
...
23:58:38.896152 poll([{fd=3, events=POLLIN}], 1, 1002) = 1 ([{fd=3,
revents=POLLIN}]) <0.037898>
etc - the time there in <brackets> is in seconds.
(this particular log says 1002 instead of 1000 simply because I changed a few
occurances of 1000 to better detect exactly which 1000 use that takes this
long)
In the current code, this slow poll is the one called from within
curl_multi_wait() which in turn is used from within curl_easy_perform().
Next on my agenda is to wireshark and see if I can detect on the network why
the poll takes such a long time in this situation.
--
/ daniel.haxx.se
-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
