cURL / Mailing Lists / curl-library / Single Mail

curl-library

Re: curl_multi_wait changes timeout to 0 and returns immediately

From: Alex Lyakas <alex_at_zadarastorage.com>
Date: Thu, 25 Dec 2014 12:58:25 +0200

Hi Daniel,
Thank you for your response.
I have done some additional debugging.

> On Tue, 16 Dec 2014, Alex Lyakas wrote:
>
>> I always specify one "extra_fd", which most of the time is not readable,
>> and a timeout of 30,000 msec.
>>
>> What I see is that curl_multi_wait appears to always change this value to 0
>> ms, and as a result it's poll() call returns immediately. This results in a
>> busy loop in the calling thread. Is this something expected?
>
> No. That sounds like a possible bug.
>
>> As an experiment, I tried to specify timeout=-1 to the curl_multi_wait
>> API. In this case, the timeout value is not overridden, and everything
>> works as expected. However, I am bit worried to use timeout=-1,
>
> You should be. It is not documented to work. Maybe it should be, but you're
> relying on undocumented behaviors right now.
>
>> because as I learned from email thread "curl_multi_wait returns immediately
>> when using bandwidth limit" in
>> http://curl.haxx.se/mail/lib-2014-05/0224.html, in some cases, the code may
>> decide that the state of the SessionHandle is not appropriate for returning
>> any socket. In that case, it may happen that the only socket that libcurl
>> will wait on, will be my extra socket.
>
> Not only during that situation, so yes it can certainly happen.
>
>> Am I missing something? What the caller is expected to do if curl_multi_wait
>> returns immediately?
>
> I've been thinking about either adding a curl_multi_wait() replacement, or an
> additional helper function to provide more information to the application in
> the case when 'numfds' is zero on return. Did it then return due to timeout or
> due to there being no file desciptors to wait for? Currently you basically
> need to time the function to figure that out and I find that a bit disturbing.
What happens is this: curl_multi_wait() calls multi_timeout(), which
sets its output parameter to 0. As a result, curl_multi_wait does:

  /* If the internally desired timeout is actually shorter than requested from
     the outside, then use the shorter time! But only if the internal timer
     is actually larger than -1! */
  (void)multi_timeout(multi, &timeout_internal);
  if((timeout_internal >= 0) && (timeout_internal < (long)timeout_ms))
    timeout_ms = (int)timeout_internal;

So timeout_ms ends up being 0. Next, we call Curl_poll() with
timeout_ms=0. This ends up in Linux system call poll(), which returns
immediately due to zero timeout.
This happens again and again, and leads to busy loop.

As for the descriptors: even if curl_multi_wait() would not have found
any curl descriptors to wait for, I always pass an additional
descriptor, so we always have to wait for at least one descriptor. But
in my tests, curl_multi_wait() always finds some curl descriptor(s) to
wait for as well.

Debugging further, I found that curl_multi_wait() calls
Curl_splaycomparekeys() and it always returns -1. As a result,
multi_timeout does:
*timeout_ms = 0;

I added prints to see why Curl_splaycomparekeys() returns -1:
#define Curl_splaycomparekeys(i,j) ( ((i.tv_sec) < (j.tv_sec)) ? -1 : \
                                   ( ((i.tv_sec) > (j.tv_sec)) ? 1 : \
                                   ( ((i.tv_usec) < (j.tv_usec)) ? -1 : \
                                   ( ((i.tv_usec) > (j.tv_usec)) ? 1 : 0 ))))

What happens is that i.tv_sec==j.tv_sec, but i.tv_usec<j.tv_usec.
Please see[1] for values that I got in my test. This was a very simple
test, performing 3 small PUTs onto AWS S3 in parallel.

>
> If there are no file descriptors to wait for, the application better either
> add file descriptors or wait a little while before it loops back and waits
> again as otherwise it'll just busy-loop until a descriptor shows up.
>
>> I see that in curl_easy_perform, there is some code which sleeps if that
>> happens (depending on the number of times that it happened). Is this the
>> recommended approach?
>
> The curl_multi_fdset() has some language for this and it says: "How long to
> wait? We suggest 100 milliseconds at least, but you may want to test it out in
> your own particular conditions to find a suitable value. "
The behavior that would be ideal for me (after fixing the timeout=0 issue):
# if curl_multi_wait() finds at least one curl descriptor to wait for,
wait for all the descriptors (including the extra_fds) for the proper
timeout.
# otherwise: wait for extra_fd descriptors for a very short timeout,
like 100ms and reutrn. This way, user has a chance to poll every 100ms
in case no curl descriptors to wait are available.
But I realize this behavior is very custom to my use-case.

Thanks,
Alex.

[1]
The values in brackes are: tv.sec:tv.usec
: multi_timeout: return 0, multi->timetree->key=[485:670697] now=[485:690777]
: multi_timeout: return 0, multi->timetree->key=[485:890191] now=[485:907776]
: multi_timeout: return 0, multi->timetree->key=[486:429936] now=[486:430346]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676601]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676704]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676721]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676752]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676766]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676782]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676796]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676823]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676837]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676865]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676878]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676892]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676906]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676933]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676947]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676961]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:676975]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677002]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677016]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677043]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677057]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677073]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677087]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677114]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677128]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677142]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677156]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677696]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:677711]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679534]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679548]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679563]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679577]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679673]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679687]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679702]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679716]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:679745]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680697]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680727]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680741]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680823]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680837]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680865]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680879]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680907]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680934]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680948]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680976]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:680989]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:681003]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:681016]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:681044]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:681058]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:681085]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682134]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682149]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682177]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682191]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682209]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682223]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682251]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682265]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682292]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682320]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682334]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682361]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682375]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682388]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682402]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682430]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682443]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682471]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682499]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682512]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682540]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682553]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682567]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682581]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682609]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682622]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682650]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682677]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682691]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682719]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682732]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682746]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682760]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682788]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682801]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:682829]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684299]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684314]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684343]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684356]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684373]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684387]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684416]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684429]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684457]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684485]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684499]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684526]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684540]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684554]
 : multi_timeout: return 0, multi->timetree->key=[685:656845] now=[685:684568]
...
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317176]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317197]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317227]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317248]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317249]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317279]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317295]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:317305]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349265]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349312]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349312]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349375]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349375]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349375]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349398]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349419]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349422]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349482]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349482]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349508]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349530]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349563]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349563]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349581]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349620]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:349627]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370686]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370715]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370745]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370774]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370806]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370806]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370836]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370836]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370866]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370894]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370924]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370953]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370953]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370982]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:370982]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:371013]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:371013]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:371045]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:394992]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:394992]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395045]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395057]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395095]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395104]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395116]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395116]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395162]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395173]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395210]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395231]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395231]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395276]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395288]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395288]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395288]
 : multi_timeout: return 0, multi->timetree->key=[936:243969] now=[936:395345]

>
>> Or should I drop the curl_multi_wait approach and try to use the
>> curl_multi_socket_action API?
>
> I can't really tell since it depends on many factors. Sure you can but you
> don't _have to_.
>
> --
>
> / daniel.haxx.se
>
>
> ------------------------------
>
> Subject: Digest Footer
>
> _______________________________________________
> curl-library mailing list
> curl-library_at_cool.haxx.se
> http://cool.haxx.se/cgi-bin/mailman/listinfo/curl-library
>
>
> ------------------------------
>
> End of curl-library Digest, Vol 112, Issue 35
> *********************************************
-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
Received on 2014-12-25