DEBUGASSERT(NULL) fails in Curl_multi_pollset_ev #16174

fujii · 2025-02-04T21:42:57Z

I did this

I'm using libcurl for Windows WebKit. Windows WebKit has been using release builds of libcurl for debug build WebKit.
Now, I'm planning to use debug builds of libcurl for debug build WebKit.
However, I'm facing an assertion failure in libcurl while browsing some web sites.

DEBUGASSERT(NULL) fails in Curl_multi_pollset_ev.

curl/lib/multi.c

Line 3104 in 1b4e635

DEBUGASSERT(NULL);

This is reproducible with libcurl 8.12.0.

I added debug logging to Curl_multi_pollset_ev.
fujii@35d508f

I got a log and uploaded there.
https://gist.github.com/fujii/7696b2fe5a9a392766e4283d14ff1ccf

Here is the excerpt of the log of loading https://www.reddit.com/.

Curl_multi_pollset_ev: transfers=000001E9F69AC1C0 data=000001E9F265E7E0 last_action=0 s=1760
Curl_hash_add: transfers=000001E9F69AC1C0 data=000001E9F265E7E0                                   ← key 000001E9F265E7E0 was added to transfers hash 000001E9F69AC1C0
(...)
Curl_hash_init: transfers=000001E9F6B55E60                                                        ← transfers hash 000001E9F6B55E60 was created
(...)
Curl_hash_delete: transfers=000001E9F6B55E60 data=000001E9F265E7E0                                ← trying to delete 000001E9F265E7E0 key, but
Assertion failed!

libcurl was trying to delete a hash key not added to a transfers hash.

I expected the following

No response

curl/libcurl version

8.12.0

operating system

Windows 11

The text was updated successfully, but these errors were encountered:

fujii · 2025-02-05T03:49:39Z

callstack:

ucrtbased.dll!00007fffc037edc5()	Unknown
ucrtbased.dll!00007fffc037ebe3()	Unknown
ucrtbased.dll!00007fffc03818af()	Unknown
libcurl.dll!Curl_multi_pollset_ev(Curl_multi * multi, Curl_easy * data, easy_pollset * ps, easy_pollset * last_ps) Line 3138	C
libcurl.dll!singlesocket(Curl_multi * multi, Curl_easy * data) Line 2977	C
libcurl.dll!curl_multi_remove_handle(void * m, void * d) Line 902	C
WebCore.dll!WebCore::CurlMultiHandle::removeHandle(void * handle) Line 271	C++
WebCore.dll!WebCore::CurlRequestScheduler::finalizeTransfer::<lambda_4>::operator()() Line 255	C++
WebCore.dll!WTF::Detail::CallableWrapper<`lambda at C:\webkit\wb\Source\WebCore\platform\network\curl\CurlRequestScheduler.cpp:248:17',void>::call() Line 53	C++
WebCore.dll!WTF::Function<void ()>::operator()() Line 82	C++
WebCore.dll!WebCore::CurlRequestScheduler::executeTasks() Line 150	C++
WebCore.dll!WebCore::CurlRequestScheduler::workerThread() Line 173	C++
WebCore.dll!WebCore::CurlRequestScheduler::startOrWakeUpThread::<lambda_0>::operator()() Line 102	C++
WebCore.dll!WTF::Detail::CallableWrapper<`lambda at C:\webkit\wb\Source\WebCore\platform\network\curl\CurlRequestScheduler.cpp:100:47',void>::call() Line 53	C++
JavaScriptCore.dll!WTF::Function<void ()>::operator()() Line 82	C++
JavaScriptCore.dll!WTF::Thread::entryPoint(WTF::Thread::NewThreadContext * newThreadContext) Line 267	C++
JavaScriptCore.dll!WTF::wtfThreadEntryPoint(void * data) Line 147	C++
ucrtbase.dll!00007ff8aab49333()	Unknown
kernel32.dll!00007ff8ab00259d()	Unknown
ntdll.dll!RtlUserThreadStart()	Unknown

fujii · 2025-02-06T00:12:25Z

I created another debug logging patch, and got this log.

Here is an excerpt of the log.

sh_addentry Curl_hash_init: transfers=0000023644AFD3C0
Curl_multi_pollset_ev xxx: transfers=0000023644AFD3C0 data=0000023644BD4570 last_action=0 s=1732
Curl_multi_pollset_ev users++: entry=0000023644AFD3C0 users=0 data=0000023644BD4570
Curl_multi_pollset_ev Curl_hash_add: transfers=0000023644AFD3C0 data=0000023644BD4570            ← data 0000023644BD4570 was added to a transfers hash 0000023644AFD3C0
(...)
Curl_multi_pollset_ev users--: entry=0000023644AFD3C0 users=1 data=0000023644BD5A80
sh_delentry Curl_hash_destroy: transfers=0000023644AFD3C0                                        ← The transfers hash 0000023644AFD3C0 was destroyed unexpectedly because entry->users is 0
(...)
sh_addentry Curl_hash_init: transfers=0000023644AFD720                                           ← another transfers hash 0000023644AFD720 was created
(...)
curl_multi_remove_handle curl_multi_remove_handle: multi=000002364458E870 data=0000023644BD4570
Curl_multi_pollset_ev users--: entry=0000023644AFD720 users=4 data=0000023644BD4570
Curl_multi_pollset_ev Curl_hash_delete: transfers=0000023644AFD720 data=0000023644BD4570 s=1732  ← Tring to delete data 0000023644BD4570 from transfers hash 0000023644AFD720, but failed
Assertion failed!

The transfers hash 0000023644AFD3C0 was destroyed unexpectedly.

fujii · 2025-02-06T00:26:18Z

I'd like to suggest this patch. if entry->transfers doesn't contains data, it should be ad 8000 ded even though last_action isn't empty.

diff --git a/lib/multi.c b/lib/multi.c
index d4dd4a004..324d999fe 100644
--- a/lib/multi.c
+++ b/lib/multi.c
@@ -3010,8 +3010,7 @@ CURLMcode Curl_multi_pollset_ev(struct Curl_multi *multi,
       if(cur_action & CURL_POLL_OUT)
         entry->writers++;
     }
-    else if(!last_action &&
-            !Curl_hash_pick(&entry->transfers, (char *)&data, /* hash key */
+    else if(!Curl_hash_pick(&entry->transfers, (char *)&data, /* hash key */
                             sizeof(struct Curl_easy *))) {
       DEBUGASSERT(entry->users < 100000); /* detect weird values */
       /* a new transfer using this socket */

Unfortunately, the same DEBUGASSERT(NULL) still fails with this patch.
But, it seems like a different issue.

icing · 2025-02-12T10:45:49Z

@fujii thanks for the detailed report. The event based scheduling in curl is a bit tricky. We have adde test coverage for it, but the problem space for possible configurations and run patters is very large. Since your application stumbles on edge cases, may this is an opportunity to tweak things a bit with your cooperation.

I did #16297 in the meantime that adds more tracing to the multi operations. If you build that with debug, you can set the environment var

CURL_DEBUG=multi

to make that tracing active (you seem do have a CURLOPT_DEBUGFUNCTION already).

I'll do a PR on top of #16297 and try some tweaking. If you are willing to test that, we should be able to iron this out, I guess. Do you have cycles to spare?

icing · 2025-02-12T15:23:50Z

Created #16308 with rework on internal event callback handling.

fujii · 2025-02-12T21:27:59Z

Thank you very much. I took some logs by loading https://www.reddit.com/ with #16308 and OutputDebugStringA.
https://drive.google.com/file/d/1D_GWQhkMhBj816VNfJuvL5kCPnKX63hV/view?usp=sharing

icing · 2025-02-13T11:45:15Z

@fujii thanks a lot for the traces! I see that the assertion in the reworked code still triggers and that we have not understood the situation here. I updated #16308 that reveals the transfer and connection ids involved and that hopefully allow us to understand what is going on.

Could you repeat you test with a fresh #16308 and set the environment variable:

CURL_DEBUG=multi,ids

If that takes effect, you should see in every log line things like [5-2] which means transfer #5 is using connection #2 regarding the trace line.

Thanks for your help!

fujii · 2025-02-13T20:40:25Z

Thank you. I got logs.
https://drive.google.com/file/d/1Zz_B4Joyx0JcJgAsQf5BqTBTFbwi2h02/view?usp=sharing

icing · 2025-02-14T14:25:33Z

Thanks for the logs! With them I believe I was able to understand why the assertion was triggered. I have updated PR #16308 and it would be nice to know how that one now fares in your tests.

fujii · 2025-02-15T00:20:15Z

Great! It works perfectly. Thank you very much.

icing self-assigned this Feb 12, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

DEBUGASSERT(NULL) fails in Curl_multi_pollset_ev #16174

DEBUGASSERT(NULL) fails in Curl_multi_pollset_ev #16174

DEBUGASSERT(NULL) fails in Curl_multi_pollset_ev #16174

DEBUGASSERT(NULL) fails in Curl_multi_pollset_ev #16174

Comments

I did this

I expected the following

curl/libcurl version

operating system