On Thu, 25 Dec 2014, Alex Lyakas wrote:

Thanks a lot for all these additional debugging and research details Alex!

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.

But the reason for it being set to 0 is that the closest timeout libcurl has for this multi handle has already passed or expires this millisecond!

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.

The big question is how it can end up doing this in a loop. Which libcurl version are you using?

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.

Right, but that won't matter much if it thinks there are timeouts that expire.

Debugging further, I found that curl_multi_wait() calls
Curl_splaycomparekeys() and it always returns -1.

*always* ? I don't think that is true, as then everyone would always see this problem happen and I know for a fact not everybody does...

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.

Yes, it is a comparison of two time stamps. It returns -1 or 1 if they differ or 0 if they are identical. Right?

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.

That's basically what it does already - with the litte twist: If it has an timeout that expires in 75 and it was given a timeout of 100, it is REALLY helpful that it returns after 75 without activity so that applications can maintain accurate timeout timers etc.

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

I'm thinking about a new option for curl_multi_setopt() to tell curl_multi_wait() how long to wait if it finds no file descriptors at all to wait for... Or something like that.

Would that be something you'd like and would consider using?

: multi_timeout: return 0, multi->timetree->key=[485:670697] now=[485:690777]

See, the timeout has already expired. The timestamp is in the past so it decides it should run now!

: multi_timeout: return 0, multi->timetree->key=[485:890191] now=[485:907776]

... and here.

: multi_timeout: return 0, multi->timetree->key=[486:429936] now=[486:430346]

... and here. And so on. The question is how you end up having those timeout expire times in them multi handle, as it indidates something is odd.

It also resembles symptoms of previous bugs we've already fixed...

--

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

Reply via email to