curl / Mailing Lists / curl-library / Single Mail

curl-library

Re: curl_multi_perform sometimes does not return while its threadus es1 00% cpu resources

From: <h9791521_at_docomo.ne.jp>
Date: Tue, 25 Dec 2018 18:24:14 +0900

Hello all,

I finally got the detailed log when the event occurred.
As you see, since time_t is defined to unsigned type in 32 bit Windows, the evaluation failed in the specific case.
https://github.com/curl/curl/issues/2004
I think this guy already pointed out this issue in 7.55, but missed the following point.
As I'm not familir with libcurl, I will use compare macro that is used in Curl_splaygetbest() for the same purpose.
Do you think this compare to macro should work?

add_next_timeout(2599)#### ttime(12207 998000) tnow(12208 003000) ####
add_next_timeout(2603) sizeofdiff : 8
add_next_timeout(2609) diff : fffffffb ffffffff ffffffff ffffffff ffffffe7 03 00 00

nodetime(999 12207) now(998000 12208)
diff = Curl_timediff(node->time, now);

timediff_t Curl_timediff(struct curltime newer, struct curltime older)
{
 timediff_t diff = newer.tv_sec-older.tv_sec;
 if(diff >= (TIME_MAX/1000))
   return TIME_MAX;
 else if(diff <= (TIME_MIN/1000))
   return TIME_MIN;
 return diff * 1000 + (newer.tv_usec-older.tv_usec)/1000;
}

struct curltime {
 time_t tv_sec; /* seconds */
 int tv_usec; /* microseconds */
};


return -1 * 1000 + (998000 - 003000)/1000;
Expected result: -5

In reality, time_t is defined to unsigned type in 32 bit Windows
return 0xFFFFFFFF * 1000 + (998000 - 003000)/1000;
Actual result: 4294967295000 + 995 =0x3e7fffffffb


timediff_t Curl_timediff(struct curltime newer, struct curltime older)
{
 timediff_t diff = newer.tv_sec-older.tv_sec;




2018/12/19 18:55、"h9791521_at_docomo.ne.jp" <h9791521_at_docomo.ne.jp>のメール:

> Hello all
>
> I inserted the log in multi.c to find why the endless loop happened, and after many executions, I finally got the following log.
> Could somebody tell me what's going on?
> Or tell me what kind of logs I should add more
> Apparenetly, timetree got corrupt,which caused calling add_next_timeout() endlessly.
>
> You can see in the end "t = 00924960" kept happening endlessly, which caused thread 25C8039A to consume the cpu usage 100%.
>
> 12:30:59.300 TID:36DB014E <libcurl>[Debug]Curl_expire_clear(3050) data->state.timenode = 00E94960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00E94960, data->state.timenode.samep = 00E94960, data->state.timenode.key.tv_sec = 403
> 12:30:59.300 TID:36DB014E <libcurl>[Debug]Curl_expire_clear(3051) call Curl_splayremovebyaddr
> 12:31:51.934 TID:3C010402 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00EA4960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:31:51.934 TID:3C010402 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:31:51.934 TID:3C010402 <libcurl>[Debug]curl_multi_perform(2196) t = 00EA4960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00EA4960, t->samep = 00EA4960, t->key.tv_sec = 381
> 12:31:51.934 TID:3C010402 <libcurl>[Debug]curl_multi_perform(2196) t = 00EA4960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00EA4960, t->samep = 00EA4960, t->key.tv_sec = 381
> 12:31:52.106 TID:3C010402 <libcurl>[Debug]curl_multi_perform(2196) t = 00EA4960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00EA4960, t->samep = 00EA4960, t->key.tv_sec = 471
> 12:31:53.400 TID:285A0256 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00924960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:31:53.400 TID:285A0256 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:31:53.400 TID:285A0256 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 382
> 12:31:53.463 TID:285A0256 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 383
> 12:31:53.572 TID:285A0256 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 383
> 12:31:55.007 TID:3D9105DE <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00974960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:31:55.007 TID:3DA701F6 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00994960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:31:55.007 TID:3D9105DE <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:31:55.023 TID:3DAB0236 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 009B4960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:31:55.023 TID:3DA701F6 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:31:55.023 TID:3DAB0236 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:31:55.023 TID:3D9105DE <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 383
> 12:31:55.023 TID:3DA701F6 <libcurl>[Debug]curl_multi_perform(2196) t = 00994960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00994960, t->samep = 00994960, t->key.tv_sec = 383
> 12:31:55.038 TID:3DAB0236 <libcurl>[Debug]curl_multi_perform(2196) t = 009B4960, t->smaller = 00000000, t->larger = 00000000, t->samen = 009B4960, t->samep = 009B4960, t->key.tv_sec = 383
> 12:31:55.038 TID:3D9105DE <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 383
> 12:31:55.038 TID:3DA701F6 <libcurl>[Debug]curl_multi_perform(2196) t = 00994960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00994960, t->samep = 00994960, t->key.tv_sec = 383
> 12:31:55.038 TID:3DAB0236 <libcurl>[Debug]curl_multi_perform(2196) t = 009B4960, t->smaller = 00000000, t->larger = 00000000, t->samen = 009B4960, t->samep = 009B4960, t->key.tv_sec = 383
> 12:31:55.194 TID:3D9105DE <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 383
> 12:31:55.210 TID:3DAB0236 <libcurl>[Debug]curl_multi_perform(2196) t = 009B4960, t->smaller = 00000000, t->larger = 00000000, t->samen = 009B4960, t->samep = 009B4960, t->key.tv_sec = 383
> 12:31:55.210 TID:3DA701F6 <libcurl>[Debug]curl_multi_perform(2196) t = 00994960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00994960, t->samep = 00994960, t->key.tv_sec = 383
> 12:31:56.037 TID:255A02FE <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00A44960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:31:56.037 TID:255A02FE <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:31:56.037 TID:255A02FE <libcurl>[Debug]curl_multi_perform(2196) t = 00A44960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00A44960, t->samep = 00A44960, t->key.tv_sec = 384
> 12:31:56.037 TID:255A02FE <libcurl>[Debug]curl_multi_perform(2196) t = 00A44960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00A44960, t->samep = 00A44960, t->key.tv_sec = 385
> 12:31:56.068 TID:255A02FE <libcurl>[Debug]curl_multi_perform(2196) t = 00A44960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00A44960, t->samep = 00A44960, t->key.tv_sec = 385
> 12:31:56.567 TID:3C010402 <libcurl>[Debug]Curl_expire_clear(3050) data->state.timenode = 00EA4960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00EA4960, data->state.timenode.samep = 00EA4960, data->state.timenode.key.tv_sec = 471
> 12:31:56.583 TID:3C010402 <libcurl>[Debug]Curl_expire_clear(3051) call Curl_splayremovebyaddr
> 12:32:03.260 TID:35570316<libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00944960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:03.260 TID:35570316<libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:03.260 TID:35570316<libcurl>[Debug]curl_multi_perform(2196) t = 00944960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00944960, t->samep = 00944960, t->key.tv_sec = 392
> 12:32:03.306 TID:35570316<libcurl>[Debug]curl_multi_perform(2196) t = 00944960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00944960, t->samep = 00944960, t->key.tv_sec = 392
> 12:32:03.431 TID:3445014A <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00994960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:03.431 TID:3445014A <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:03.431 TID:3445014A <libcurl>[Debug]curl_multi_perform(2196) t = 00994960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00994960, t->samep = 00994960, t->key.tv_sec = 392
> 12:32:03.431 TID:3445014A <libcurl>[Debug]curl_multi_perform(2196) t = 00994960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00994960, t->samep = 00994960, t->key.tv_sec = 392
> 12:32:03.650 TID:0E9402BA <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00934960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:03.665 TID:0E9402BA <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:03.665 TID:0E9402BA <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 392
> 12:32:03.665 TID:0E9402BA <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 392
> 12:32:03.759 TID:35570316<libcurl>[Debug]curl_multi_perform(2196) t = 00944960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00944960, t->samep = 00944960, t->key.tv_sec = 392
> 12:32:03.821 TID:3445014A <libcurl>[Debug]curl_multi_perform(2196) t = 00994960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00994960, t->samep = 00994960, t->key.tv_sec = 392
> 12:32:03.852 TID:0E9402BA <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 392
> 12:32:09.546 TID:3D91064A <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00924960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:09.562 TID:3D91064A <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:09.562 TID:3D91064A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 399
> 12:32:09.562 TID:3D91064A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 399
> 12:32:09.671 TID:3D91064A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 399
> 12:32:14.882 TID:3D6C04B2 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00924960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:14.882 TID:3D6C04B2 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:14.882 TID:3D6C04B2 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 404
> 12:32:14.882 TID:3D6C04B2 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 404
> 12:32:15.038 TID:3D6C04B2 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 404
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00974960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]Curl_expire(2987) data->state->timenode = 00974960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00974960, data->state.timenode.samep = 00974960, data->state.timenode.key.tv_sec = 408
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]Curl_expire(2988) call Curl_splayremovebyaddr
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00974960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00974960, data->state.timenode.samep = 00974960, data->state.timenode.key.tv_sec = 408
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:18.454 TID:3D9301EA <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 408
> 12:32:18.626 TID:3D9301EA <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 408
> 12:32:20.919 TID:3CE905E6 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00924960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:20.934 TID:3CE905E6 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:20.934 TID:3CE905E6 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 410
> 12:32:20.934 TID:3CE905E6 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 410
> 12:32:21.044 TID:3CE905E6 <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 410
> 12:32:22.604 TID:3D770116 <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00974960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:22.604 TID:3D770116 <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:22.619 TID:3D770116 <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 412
> 12:32:22.619 TID:3D770116 <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 412
> 12:32:22.760 TID:3D770116 <libcurl>[Debug]curl_multi_perform(2196) t = 00974960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00974960, t->samep = 00974960, t->key.tv_sec = 412
> 12:32:26.722 TID:3CF600CA <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00924960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:26.722 TID:3CF600CA <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:26.722 TID:3CF600CA <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 416
> 12:32:26.722 TID:3CF600CA <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 416
> 12:32:26.894 TID:3CF600CA <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 416
> 12:32:27.128 TID:3CC206EE <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00934960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:27.128 TID:3CC206EE <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:27.128 TID:3CC206EE <libcurl>[Debug]Curl_expire(2987) data->state->timenode = 00934960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00934960, data->state.timenode.samep = 00934960, data->state.timenode.key.tv_sec = 416
> 12:32:27.128 TID:3CC206EE <libcurl>[Debug]Curl_expire(2988) call Curl_splayremovebyaddr
> 12:32:27.128 TID:3CC206EE <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00934960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00934960, data->state.timenode.samep = 00934960, data->state.timenode.key.tv_sec = 416
> 12:32:27.143 TID:3CC206EE <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:27.143 TID:3CC206EE <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 416
> 12:32:27.206 TID:3CC206EE <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 416
> 12:32:31.449 TID:3CD4015E <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00934960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:31.449 TID:3CD4015E <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:31.449 TID:3CD4015E <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 420
> 12:32:31.464 TID:3CD4015E <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 420
> 12:32:31.808 TID:3CD4015E <libcurl>[Debug]curl_multi_perform(2196) t = 00934960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00934960, t->samep = 00934960, t->key.tv_sec = 420
> 12:32:33.929 TID:25C8039A <libcurl>[Debug]Curl_expire(3007) data->state.timenode = 00924960, data->state.timenode.smaller = 00000000, data->state.timenode.larger = 00000000, data->state.timenode.samen = 00000000, data->state.timenode.samep = 00000000, data->state.timenode.key.tv_sec = 0
> 12:32:33.929 TID:25C8039A <libcurl>[Debug]Curl_expire(3008) call Curl_splayinsert
> 12:32:33.929 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:33.945 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.023 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.023 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.085 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.085 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.085 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.085 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.085 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.085 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.101 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> 12:32:34.101 TID:25C8039A <libcurl>[Debug]curl_multi_perform(2196) t = 00924960, t->smaller = 00000000, t->larger = 00000000, t->samen = 00924960, t->samep = 00924960, t->key.tv_sec = 421
> "t = 00924960" kept happening endlessly, which caused thread 25C8039A to consume the cpu usage 100%.
>
> The following are where I added the log.
>
> CURLMcode curl_multi_perform(struct Curl_multi *multi, int *running_handles)
>
> do {
> multi->timetree = Curl_splaygetbest(now, multi->timetree, &t);
> if(t){
> /* the removed may have another timeout in queue */
> (void)add_next_timeout(now, multi, t->payload);
> DEBUGLOG("t = %p, t->smaller = %p, t->larger = %p, t->samen = %p, t->samep = %p, t->key.tv_sec = %ld \n",
> t, t->smaller, t->larger, t->samen, t->samep, t->key.tv_sec );
> }
>
> } while(t);
>
> void Curl_expire(struct Curl_easy *data, time_t milli, expire_id id)
>
> /* Indicate that we are in the splay tree and insert the new timer expiry
> value since it is our local minimum. */
> *nowp = set;
> data->state.timenode.payload = data;
>
> DEBUGLOG("data->state.timenode = %p, data->state.timenode.smaller = %p, data->state.timenode.larger = %p, data->state.timenode.samen = %p, data->state.timenode.samep = %p, data->state.timenode.key.tv_sec = %ld \n ",
> &data->state.timenode, data->state.timenode.smaller, data->state.timenode.larger, data->state.timenode.samen, data->state.timenode.samep, data->state.timenode.key.tv_sec );
> DEBUGLOG(" call Curl_splayinsert\n ");
>
> multi->timetree = Curl_splayinsert(*nowp, multi->timetree,
> &data->state.timenode);
> }
>
>
>
> 2018/12/14 16:23、Daniel Stenberg <daniel_at_haxx.se>のメール:
>
>>> On Thu, 13 Dec 2018, "h9791521_at_docomo.ne.jp" wrote:
>>>
>>> I confirmed that time_t is defined as unsigned long in windows, which I
>>> think is equivalent to HAVE TIME T UNSIGNED.
>>
>> Please show me details and describe exactly where you found this.
>>
>>> Regarding an example source code, it's hard for me to pick up and post them
>>> and it(= "compare(i, t->key) never gets negative") occurs once in thousand
>>> times after simply calling curl_easy_perform()
>>
>> I understand that I'm asking for something that might not be easy to create,
>> but it is even harder for us outside of your project to understand or
>> reproduce this issue.
>>
>> Until we can reproduce or understand it, it *could* also just be your program
>> running amok somehow. libcurl is after all used by a large amount of users all
>> over that don't get this problem.
>>
>>> I don't use libcurl multi-threaded, I mean, there are many other threads in
>>> this process, but the only one thread calls curl_easy_perform().
>>
>> Also the only thread doing libcurl calls?
>>
>> --
>>
>> / daniel.haxx.se

-------------------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.haxx.se/mail/etiquette.html
Received on 2018-12-25