[Mono-dev] mono_thread_attach/mono_thread_detach not threadsafe?

[Allan Hsu]

Lately, we've been seeing a lot of messages in the imeem OS X client  
that look like this:

** (process:23127): WARNING **: _wapi_handle_unref: Attempting to  
unref unused handle 0x7cf

These messages eventually lead to messages of this form:

** (process:23127): WARNING **: _wapi_thread_apc_pending: error  
looking up thread handle 0x2c8

I've tracked down these messages to our use of mono_thread_attach and  
mono_thread_detach; I've isolated the messages down to a small bit of  
C that mimics the Dumbarton NSThread poser (minus the Objective-C code):

http://www.blargle.com/~allan/racy.tar.bz2

Is this proper usage of mono_thread_attach/mono_thread_detach? The  
results that follow seem to suggest that I'm either using these two  
functions incorrectly, or these functions are not threadsafe and the  
code in the tarball is exposing some sort of race condition.

The code:

The code simply initializes the JIT and then creates 64 threads that  
call mono_thread_attach, then mono_thread_detach, then joins each  
thread and repeats the process indefinitely.

Under Mono 1.1.13.2 on OS X 10.4.4, the sample code eventually  
generates a lot of _wapi_handle_unref g_log calls that originate from  
CloseHandle called from the finalizer thread:

#0  0x006e8688 in g_log ()
#1  0x00317130 in _wapi_handle_unref (handle=0x2863) at handles.c:827
#2  0x00317c18 in CloseHandle (handle=0x2863) at handles.c:1040
#3  0x00309d74 in  
ves_icall_System_Threading_Thread_Thread_free_internal (this=0x0,  
thread=0x10) at threads.c:555
#4  0x00064c58 in ?? ()
#5  0x00064968 in ?? ()
#6  0x0006458c in ?? ()
#7  0x0022f334 in mono_jit_runtime_invoke (method=0x111c6c0,  
obj=0xe4870, params=0x0, exc=0xf0103c90) at mini.c:9863
#8  0x002e5b9c in mono_runtime_invoke (method=0x0, obj=0x10,  
params=0x382300, exc=0x3822ec) at object.c:1346
#9  0x002b446c in run_finalize (obj=0xe4870, data=0x0) at gc.c:102
#10 0x00343920 in GC_invoke_finalizers ()
#11 0x002b5300 in finalizer_thread (unused=0x0) at gc.c:778
#12 0x003097c8 in start_wrapper (data=0x0) at threads.c:305
#13 0x0032a360 in timed_thread_start_routine (args=0x1120a40) at  
timed-thread.c:134
#14 0x9002b200 in _pthread_body ()

Sometimes (though rarely), this code will cause Mono on OS X to  
segfault. This will happen more often if you increase  
CHUNK_THREADCOUNT to 200 or more.

Under Mono 1.1.13.2  on (32-bit) Linux 2.6.9, the sample code almost  
immediately dies with a segfault; Mono catches the segfault roughly  
half the time. Here is a backtrace:

0x00d1c890 in pthread_kill () from /lib/tls/libpthread.so.0
(gdb) bt
#0  0x00d1c890 in pthread_kill () from /lib/tls/libpthread.so.0
#1  0x0025bb05 in GC_suspend_all () from /usr/lib/libmono.so.0
#2  0x0025bb49 in GC_suspend_all () from /usr/lib/libmono.so.0
#3  0x0025bcf7 in GC_stop_world () from /usr/lib/libmono.so.0
#4  0x0024b731 in GC_stopped_mark () from /usr/lib/libmono.so.0
#5  0x0024b3b4 in GC_try_to_collect_inner () from /usr/lib/libmono.so.0
#6  0x0024c4f3 in GC_collect_or_expand () from /usr/lib/libmono.so.0
#7  0x0024c736 in GC_allocobj () from /usr/lib/libmono.so.0
#8  0x00250ed1 in GC_generic_malloc_inner () from /usr/lib/libmono.so.0
#9  0x00250ff1 in GC_generic_malloc () from /usr/lib/libmono.so.0
#10 0x002512dd in GC_malloc () from /usr/lib/libmono.so.0
#11 0x001da3df in mono_gc_alloc_fixed () from /usr/lib/libmono.so.0
#12 0x001f3385 in mono_thread_get_pending_exception ()
    from /usr/lib/libmono.so.0
#13 0x001f3531 in mono_thread_get_pending_exception ()
    from /usr/lib/libmono.so.0
#14 0x001f0718 in mono_thread_attach () from /usr/lib/libmono.so.0
#15 0x080487f1 in thread_function ()
#16 0x00d19341 in start_thread () from /lib/tls/libpthread.so.0
#17 0x00c846fe in clone () from /lib/tls/libc.so.6

	-Allan
--
Allan Hsu <allan at counterpop dot net>
1E64 E20F 34D9 CBA7 1300  1457 AC37 CBBB 0E92 C779