Fix channel destruction race conditions with c-ares queue synchronization and safety delay #249

bdraco · 2025-07-23T10:39:04Z

PR Summary

This PR fixes critical race conditions in channel destruction by combining c-ares's ares_queue_wait_empty() with a minimal safety delay. This approach eliminates crashes while maintaining high throughput for channel destruction.

Problem

The current implementation has fundamental safety issues:

Race conditions cause crashes - Even with long delays, channels can be destroyed while the c-ares event thread is processing
Specific crash points identified:
- https://github.com/c-ares/c-ares/blob/4f42928848e8b73d322b15ecbe3e8d753bf8734e/src/lib/ares_process.c#L1421 (callback invocation in end_query)
- https://github.com/c-ares/c-ares/blob/4f42928848e8b73d322b15ecbe3e8d753bf8734e/src/lib/ares_process.c#L1422 (query freeing in end_query)
c-ares limitation - Even ares_queue_wait_empty() alone isn't sufficient because the event thread may be in a critical section after removing queries from the queue
Sequential processing limitation - The SimpleQueue approach limited throughput to 60 channels/minute

Root Cause

When using event_thread=True, there's a race condition where:

The event thread removes a query from the queue (making ares_queue_wait_empty() return success)
But the thread is still in end_query() processing callbacks or freeing memory
If ares_destroy() is called at this moment, it causes use-after-free crashes

Solution

Implement a two-phase approach:

Use ares_queue_wait_empty() to detect when queries are complete
Add a minimal delay (0.1s) after queue is empty to let the event thread exit critical sections
Then safely call ares_destroy()

This combines deterministic waiting with a safety margin for the critical section.

Key Changes

Added ares_queue_wait_empty() binding - Exposes c-ares function to check when queries are done
Two-phase destruction - Wait for empty queue, then add small delay for critical section
Non-blocking implementation - Uses 0ms timeout polling to avoid blocking the event loop
Asyncio event loop - Enables concurrent destruction without throughput limitations
Thread-safe design - Fixed race in thread creation with threading.Lock
Comprehensive documentation - Added comments explaining the race conditions and solution

Benefits

Eliminates crashes - Proper synchronization prevents use-after-free errors
Minimal delays - Only waits as long as necessary (until queue empty + 0.1s)
High throughput - Multiple channels can be destroyed concurrently
Deterministic - Based on actual queue state rather than blind delays

Why This Approach

ares_queue_wait_empty() alone is insufficient - The event thread can still be in critical sections
Pure delay-based approach is unreliable - No guarantee the delay is long enough
This hybrid approach - Waits for a known safe state, then adds minimal delay for the critical section

Testing

This change has been designed to handle the specific race conditions in c-ares's event thread implementation. The combination of queue state checking and minimal delay provides the safety needed while maintaining good performance.

…loop

bdraco · 2025-07-23T11:18:48Z

~~I can still get it to crash after 42mil attempts with this approach~~
nevermind , I had the ulimit set really low

bdraco · 2025-07-23T11:32:29Z

I can still get a crash with this

bdraco · 2025-07-23T17:53:05Z

test script

import sys
import asyncio
import ipaddress

import aiodns

# TOR exit relay without a PTR record. This POC uses a single IP in a loop but the crash
# can be caused by issuing multiple PTR requests which do not have an record.
ip = '38.135.24.32'

# IPs with valid PTR records do not reproduce the error in my testing
# ip = '8.8.8.8'

# The nameserver of choice does not seem to impact the output
# nameservers = ['8.8.8.8']
nameservers = []

async def lookup(valu):
    res = aiodns.DNSResolver(nameservers=nameservers)
    answ = None
    try:
        answ = await res.query(valu, 'PTR')
    except aiodns.error.DNSError as e:
        if e.args[0] != 4:  # Domain name not found
            raise
    return answ

async def main():
    valu = ipaddress.ip_address(ip).reverse_pointer
    while True:
        task = asyncio.create_task(lookup(valu))
        await task

if __name__ == '__main__':
    sys.exit(asyncio.run(main()))

bdraco · 2025-07-23T18:22:08Z

here is the trace on macos

Thread 18 Crashed:
0   libsystem_kernel.dylib        	       0x18a6cd388 __pthread_kill + 8
1   libsystem_pthread.dylib       	       0x18a70688c pthread_kill + 296
2   libsystem_c.dylib             	       0x18a60fc60 abort + 124
3   libsystem_malloc.dylib        	       0x18a514174 malloc_vreport + 892
4   libsystem_malloc.dylib        	       0x18a517c90 malloc_report + 64
5   libsystem_malloc.dylib        	       0x18a51c21c ___BUG_IN_CLIENT_OF_LIBMALLOC_POINTER_BEING_FREED_WAS_NOT_ALLOCATED + 32
6   _cares.abi3.so                	       0x105bddd10 ares_dnsrec_convert_cb + 112 (ares_search.c:425)
7   _cares.abi3.so                	       0x105bdd514 ares_query_dnsrec_cb + 88
8   _cares.abi3.so                	       0x105bdbab0 end_query + 44 (ares_process.c:1421) [inlined]
9   _cares.abi3.so                	       0x105bdbab0 process_answer + 1024 (ares_process.c:890) [inlined]
10  _cares.abi3.so                	       0x105bdbab0 read_answers + 1256 (ares_process.c:582) [inlined]
11  _cares.abi3.so                	       0x105bdbab0 process_read + 1256 (ares_process.c:644) [inlined]
12  _cares.abi3.so                	       0x105bdbab0 ares_process_fds_nolock + 1920 (ares_process.c:226)
13  _cares.abi3.so                	       0x105bdb308 ares_process_fds + 60 (ares_process.c:258)
14  _cares.abi3.so                	       0x105be79d4 ares_event_thread_process_fd + 40 (ares_event_thread.c:204)
15  _cares.abi3.so                	       0x105be6938 ares_evsys_kqueue_wait + 260 (ares_event_kqueue.c:235)
16  _cares.abi3.so                	       0x105be7858 ares_event_thread + 148 (ares_event_thread.c:347)
17  libsystem_pthread.dylib       	       0x18a706c0c _pthread_start + 136
18  libsystem_pthread.dylib       	       0x18a701b80 thread_start + 8

bdraco · 2025-07-23T18:22:54Z

https://github.com/c-ares/c-ares/blob/4f42928848e8b73d322b15ecbe3e8d753bf8734e/src/lib/ares_process.c#L1422 is still the problem

bdraco · 2025-07-23T18:24:10Z

Actually its a different issue. The callback was freed but it was already freed by python destruction

bdraco · 2025-07-23T18:24:34Z

So its one line off https://github.com/c-ares/c-ares/blob/4f42928848e8b73d322b15ecbe3e8d753bf8734e/src/lib/ares_process.c#L1421

bdraco · 2025-07-23T18:59:40Z

even with the check and a 5s delay I still get a crash

0   libsystem_kernel.dylib        	       0x19ae05388 __pthread_kill + 8
1   libsystem_pthread.dylib       	       0x19ae3e88c pthread_kill + 296
2   libsystem_c.dylib             	       0x19ad47c60 abort + 124
3   libsystem_malloc.dylib        	       0x19ac4c174 malloc_vreport + 892
4   libsystem_malloc.dylib        	       0x19ac4fc90 malloc_report + 64
5   libsystem_malloc.dylib        	       0x19ac5421c ___BUG_IN_CLIENT_OF_LIBMALLOC_POINTER_BEING_FREED_WAS_NOT_ALLOCATED + 32
6   _cares.abi3.so                	       0x1011a5d10 ares_dnsrec_convert_cb + 112 (ares_search.c:425)
7   _cares.abi3.so                	       0x1011a5514 ares_query_dnsrec_cb + 88
8   _cares.abi3.so                	       0x1011a3ab0 end_query + 44 (ares_process.c:1421) [inlined]
9   _cares.abi3.so                	       0x1011a3ab0 process_answer + 1024 (ares_process.c:890) [inlined]
10  _cares.abi3.so                	       0x1011a3ab0 read_answers + 1256 (ares_process.c:582) [inlined]
11  _cares.abi3.so                	       0x1011a3ab0 process_read + 1256 (ares_process.c:644) [inlined]
12  _cares.abi3.so                	       0x1011a3ab0 ares_process_fds_nolock + 1920 (ares_process.c:226)
13  _cares.abi3.so                	       0x1011a3308 ares_process_fds + 60 (ares_process.c:258)
14  _cares.abi3.so                	       0x1011af9d4 ares_event_thread_process_fd + 40 (ares_event_thread.c:204)
15  _cares.abi3.so                	       0x1011ae938 ares_evsys_kqueue_wait + 260 (ares_event_kqueue.c:235)
16  _cares.abi3.so                	       0x1011af858 ares_event_thread + 148 (ares_event_thread.c:347)
17  libsystem_pthread.dylib       	       0x19ae3ec0c _pthread_start + 136
18  libsystem_pthread.dylib       	       0x19ae39b80 thread_start + 8

bdraco · 2025-07-23T19:11:26Z

The original PR fixed the crash on 1422 but this crash happens on 1421

bdraco · 2025-07-23T19:11:46Z

Thread 22 Crashed:
0   libsystem_kernel.dylib        	       0x19ae05388 __pthread_kill + 8
1   libsystem_pthread.dylib       	       0x19ae3e88c pthread_kill + 296
2   libsystem_c.dylib             	       0x19ad47c60 abort + 124
3   libsystem_malloc.dylib        	       0x19ac4c174 malloc_vreport + 892
4   libsystem_malloc.dylib        	       0x19ac4fc90 malloc_report + 64
5   libsystem_malloc.dylib        	       0x19ac5421c ___BUG_IN_CLIENT_OF_LIBMALLOC_POINTER_BEING_FREED_WAS_NOT_ALLOCATED + 32
6   _cares.abi3.so                	       0x1015f9ce8 ares_dnsrec_convert_cb + 112 (ares_search.c:425)
7   _cares.abi3.so                	       0x1015f94ec ares_query_dnsrec_cb + 88
8   _cares.abi3.so                	       0x1015f7a88 end_query + 44 (ares_process.c:1421) [inlined]
9   _cares.abi3.so                	       0x1015f7a88 process_answer + 1024 (ares_process.c:890) [inlined]
10  _cares.abi3.so                	       0x1015f7a88 read_answers + 1256 (ares_process.c:582) [inlined]
11  _cares.abi3.so                	       0x1015f7a88 process_read + 1256 (ares_process.c:644) [inlined]
12  _cares.abi3.so                	       0x1015f7a88 ares_process_fds_nolock + 1920 (ares_process.c:226)
13  _cares.abi3.so                	       0x1015f72e0 ares_process_fds + 60 (ares_process.c:258)
14  _cares.abi3.so                	       0x1016039ac ares_event_thread_process_fd + 40 (ares_event_thread.c:204)
15  _cares.abi3.so                	       0x101602910 ares_evsys_kqueue_wait + 260 (ares_event_kqueue.c:235)
16  _cares.abi3.so                	       0x101603830 ares_event_thread + 148 (ares_event_thread.c:347)
17  libsystem_pthread.dylib       	       0x19ae3ec0c _pthread_start + 136
18  libsystem_pthread.dylib       	       0x19ae39b80 thread_start + 8

bdraco · 2025-07-23T19:31:15Z

#0  __pthread_kill_implementation (threadid=281471118012800, signo=signo@entry=6, no_tid=no_tid@entry=0) at ./nptl/pthread_kill.c:44
#1  0x0000ffffb4cd0ab4 in __pthread_kill_internal (signo=6, threadid=<optimized out>) at ./nptl/pthread_kill.c:78
#2  0x0000ffffb4c8a72c in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#3  0x0000ffffb4c7747c in __GI_abort () at ./stdlib/abort.c:79
#4  0x0000ffffb4cc4aac in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0xffffb4da6d28 "%s\n") at ../sysdeps/posix/libc_fatal.c:156
#5  0x0000ffffb4cdaebc in malloc_printerr (str=str@entry=0xffffb4da1fb8 "free(): double free detected in tcache 2") at ./malloc/malloc.c:5660
#6  0x0000ffffb4cdd0a8 in _int_free (av=0xffffb4df0af0 <main_arena>, p=p@entry=0xaaaae55f8300, have_lock=have_lock@entry=0) at ./malloc/malloc.c:4469
#7  0x0000ffffb4cdf77c in __GI___libc_free (mem=<optimized out>) at ./malloc/malloc.c:3385
#8  0x0000ffffb3c21ea4 in ares_dnsrec_convert_cb (arg=0xaaaae55f8310, status=ARES_ENOTFOUND, timeouts=0, dnsrec=<optimized out>) at deps/c-ares/src/lib/ares_search.c:425
#9  0x0000ffffb3c21ba0 in ares_query_dnsrec_cb (arg=0xaaaae55fa310, status=<optimized out>, timeouts=0, dnsrec=0xfffdcc020c60) at deps/c-ares/src/lib/ares_query.c:56
#10 0x0000ffffb3c20ec0 in end_query (dnsrec=0xfffdcc020c60, status=ARES_SUCCESS, query=0xaaaae55fa380, server=0xaaaae55f9e50, channel=0xaaaae55f9010)
    at deps/c-ares/src/lib/ares_process.c:1421
#11 process_answer (requeue=<optimized out>, now=<optimized out>, conn=<optimized out>, alen=<optimized out>, abuf=<optimized out>, channel=<optimized out>)
    at deps/c-ares/src/lib/ares_process.c:890
#12 read_answers (now=0xffff1a00e7a0, conn=<optimized out>) at deps/c-ares/src/lib/ares_process.c:582
#13 process_read (now=0xffff1a00e7a0, read_fd=<optimized out>, channel=0xaaaae55f9010) at deps/c-ares/src/lib/ares_process.c:644
#14 ares_process_fds_nolock (channel=channel@entry=0xaaaae55f9010, events=events@entry=0xffff1a00e818, nevents=nevents@entry=1, flags=flags@entry=1) at deps/c-ares/src/lib/ares_process.c:226
#15 0x0000ffffb3c21040 in ares_process_fds_nolock (flags=1, nevents=1, events=0xffff1a00e818, channel=0xaaaae55f9010) at deps/c-ares/src/lib/ares_process.c:200
#16 ares_process_fds (channel=0xaaaae55f9010, events=events@entry=0xffff1a00e818, nevents=nevents@entry=1, flags=flags@entry=1) at deps/c-ares/src/lib/ares_process.c:258
#17 0x0000ffffb3c2b510 in ares_event_thread_process_fd (e=<optimized out>, fd=<optimized out>, data=<optimized out>, flags=<optimized out>)
    at deps/c-ares/src/lib/event/ares_event_thread.c:204
#18 0x0000ffffb3c2ad5c in ares_evsys_epoll_wait (e=0xaaaae55fa0a0, timeout_ms=<optimized out>) at deps/c-ares/src/lib/event/ares_event_epoll.c:179
#19 0x0000ffffb3c2b828 in ares_event_thread (arg=0xaaaae55fa0a0) at deps/c-ares/src/lib/event/ares_event_thread.c:347
#20 0x0000ffffb4cceea0 in start_thread (arg=0xffffeaf87397) at ./nptl/pthread_create.c:442
#21 0x0000ffffb4d37b1c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:79

bdraco · 2025-07-23T19:38:18Z

no matter what I do I can't solve this. I think we need to dump the event_thread as its fundamentally unsafe.

I'm going to give up on this as I think changes have to be made upstream, and trying to solve it here is just an exercise in frustration.

bdraco · 2025-07-23T19:44:24Z

So the original PR did fix the crash online 1422, but we still have a race crash from the double free on 1421

At this point, I'm convinced that the event thread implementation cannot be made safe unless c-ares makes changes

bdraco · 2025-08-04T07:57:36Z

I still plan on giving this another shot before giving up on the event thread but I haven't had free cycles to work on it between my other commitments

saghul · 2025-08-04T08:47:28Z

Oh, looks like a made a PR following roughly the same approach but I hadn't seen this one from you, sorry!

bdraco · 2025-08-04T09:19:36Z

Oh, looks like a made a PR following roughly the same approach but I hadn't seen this one from you, sorry!

no worries. happy to have it solved by any means possible 👍

bdraco · 2025-08-05T18:38:19Z

replaced by #253

Remove channel destruction throughput limitation using asyncio event …

e18ff13

…loop

bdraco mentioned this pull request Jul 23, 2025

inotify leaks aio-libs/aiodns#175

Closed

bdraco added 9 commits July 23, 2025 00:54

race

653df3d

race

07a0ebd

race

69e536a

race

bad5398

race

85f510e

race

106715b

race

d14016d

race

74bd4e6

race

7e47c6e

bdraco closed this Jul 23, 2025

bdraco deleted the shutdown_max_throughput branch July 23, 2025 11:32

bdraco restored the shutdown_max_throughput branch July 23, 2025 17:52

bdraco reopened this Jul 23, 2025

crash fixed

58223a7

bdraco changed the title ~~Remove channel destruction throughput limitation using asyncio event loop~~ Safe channel destruction with asyncio event loop and c-ares queue synchronization Jul 23, 2025

bdraco changed the title ~~Safe channel destruction with asyncio event loop and c-ares queue synchronization~~ Fix channel destruction race conditions using c-ares queue synchronization Jul 23, 2025

messy

4fbf556

bdraco changed the title ~~Fix channel destruction race conditions using c-ares queue synchronization~~ Fix channel destruction race conditions with c-ares queue synchronization and safety delay Jul 23, 2025

bdraco added 3 commits July 23, 2025 08:50

messy

158b145

messy

01ddc64

messy

d59db6c

bdraco added 2 commits July 23, 2025 09:04

try

461a10b

try

cd3874c

bdraco added 4 commits July 23, 2025 09:13

try

1e8e564

try

6a57b05

try

19b2726

try

6ef2103

bdraco closed this Aug 5, 2025

Fix channel destruction race conditions with c-ares queue synchronization and safety delay #249

Fix channel destruction race conditions with c-ares queue synchronization and safety delay #249

Uh oh!

Conversation

bdraco commented Jul 23, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

PR Summary

Problem

Root Cause

Solution

Key Changes

Benefits

Why This Approach

Testing

Uh oh!

bdraco commented Jul 23, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025

Uh oh!

bdraco commented Jul 23, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

bdraco commented Jul 23, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

bdraco commented Aug 4, 2025

Uh oh!

saghul commented Aug 4, 2025

Uh oh!

bdraco commented Aug 4, 2025

Uh oh!

bdraco commented Aug 5, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

bdraco commented Jul 23, 2025 •

edited

Loading

bdraco commented Jul 23, 2025 •

edited

Loading

bdraco commented Jul 23, 2025 •

edited

Loading

bdraco commented Jul 23, 2025 •

edited

Loading