Bug 16808 - ThreadAbortException. Finally block does not execute
Summary: ThreadAbortException. Finally block does not execute
Status: RESOLVED FIXED
Alias: None
Product: Runtime
Classification: Mono
Component: General (show other bugs)
Version: 5.8 (2017-10)
Hardware: PC All
: Normal normal
Target Milestone: Future Cycle (TBD)
Assignee: Vlad Brezae
URL:
Depends on:
Blocks:
 
Reported: 2013-12-15 15:46 UTC by Sergey Zhukov
Modified: 2017-12-01 19:16 UTC (History)
8 users (show)

See Also:
Tags: bugpool
Is this bug a regression?: ---
Last known good build:


Attachments
OrphanedLocksTest (2.25 KB, text/x-csharp)
2013-12-15 15:46 UTC, Sergey Zhukov
Details

Description Sergey Zhukov 2013-12-15 15:46:09 UTC
Created attachment 5665 [details]
OrphanedLocksTest

According to MSDN:
http://msdn.microsoft.com/en-us/library/system.threading.threadabortexception.aspx
=====================
When a call is made to the Abort method to destroy a thread, the common language runtime throws a ThreadAbortException. ThreadAbortException is a special exception that can be caught, but it will automatically be raised again at the end of the catch block. When this exception is raised, the runtime executes all the finally blocks before ending the thread. Because the thread can do an unbounded computation in the finally blocks or call Thread.ResetAbort to cancel the abort, there is no guarantee that the thread will ever end. If you want to wait until the aborted thread has ended, you can call the Thread.Join method. Join is a blocking call that does not return until the thread actually stops executing.
=============================================
The key phrase: "When this exception is raised, the runtime executes all the finally blocks before ending the thread."

I wrote simple test to check if it works correctly in mono and could be used for properly locking. When I run it after few minutes application gets in deadlock, the output is varies from time to time. In one time, I can get following output:

Aborted read b1=True, b2=True, b3=True, b4=False, s2=True
Aborted write b1=True, b2=False, b3=False, b4=False, s2=True

What means, that first finally block was not executed, while second was.

Or I can get:
Aborted read b1=True, b2=True, b3=True, b4=False, s2=False

What means, that first finally block was executed, while second was not.

But b1,b2 and s2 must always be 'True' if all finally blocks are executed properly.

Such random looks very strange. 

Mono Runtime Engine version 3.2.7 (master/01b7a50 Sat Dec 14 01:48:49 NOVT 2013)
Copyright (C) 2002-2013 Novell, Inc, Xamarin Inc and Contributors. www.mono-project.com
	TLS:           __thread
	SIGSEGV:       altstack
	Notifications: epoll
	Architecture:  x86
	Disabled:      none
	Misc:          softdebug 
	LLVM:          yes(3.4svn-mono-mono/e656cac)
	GC:            sgen
Comment 1 Sergey Zhukov 2013-12-15 15:58:49 UTC
You can decrease Thread.Sleep() time from 500 to 100 ms, to get the deadlock faster.

And one more thing:

In most cases you won't get a phrase "Gotcha!" on your screen, seems that timeout for TryEnterReadLock does not work correctly.
Comment 2 Zoltan Varga 2013-12-21 23:43:28 UTC
The testcase is racy, for example, the thread abort request could arrive when the thread is in the second finalizer, but before it executes the b4=true; line.
Comment 3 Sergey Zhukov 2013-12-22 04:29:26 UTC
I'm not sure the last comment is a confirmation of the bug or rejection, so want to mention, if ThreadAbortException is raised in second finally block before b4=true, runtime must execute all statements in the finally block and only after that pass execution flow to catch(ThreadAbortException) block. See remarks for ThreadAbortException class in msdn
http://msdn.microsoft.com/ru-ru/library/system.threading.threadabortexception%28v=vs.110%29.aspx
Comment 4 Sergey Zhukov 2013-12-22 21:50:45 UTC
And msdn documentation of Thread.Abort method:

http://msdn.microsoft.com/ru-ru/library/5b50fdsz%28v=vs.110%29.aspx

----------------------------------------------------------------------------
The thread is not guaranteed to abort immediately, or at all. This situation can occur if a thread does an unbounded amount of computation in the finally blocks that are called as part of the abort procedure, thereby indefinitely delaying the abort. To wait until a thread has aborted, you can call the Join method on the thread after calling the Abort method, but there is no guarantee that the wait will end.

Note

The thread that calls Abort might block if the thread that is being aborted is in a protected region of code, such as a catch block, finally block, or constrained execution region.  
----------------------------------------------------------------
Comment 5 Sergey Zhukov 2013-12-22 23:30:48 UTC
And the code above does not deadlock on MS .NET
Comment 6 Zoltan Varga 2014-01-05 18:51:40 UTC
This is yet another async bug. When the testcase is aot-ed, it randomly crashes because 
the implementation of OP_ATOMIC_ADD_NEW_I4 uses callee-saved regs as temporary regs by push-ing and pop-ing them. If the thread is interrupted in the middle of this code sequence, the unwinder will use
the ebx value set by the code sequence instead of the original pushed value.
Comment 7 pr0vieh 2016-09-18 16:58:31 UTC
not sure if related to this Bug report

at shutdown i get randomly this Stacktrace @mono Master

 Failed to close connection: System.Threading.ThreadAbortException
  at System.Net.HttpWebRequest.Abort () <0x7f61f82507e0 + 0x00309> in <76b6376638884822b2efb587630d5b7e#2bbc429d4f85cbdaecb5d0cb86d630de>:0
  at mytool.WebCrawlerWorker.CloseConnection () <0x7f61f29f2280 + 0x00022> in <630e3cc849c549498c690f2b568f83e5#2bbc429d4f85cbdaecb5d0cb86d630de>:0
 Status: FinishedSystem.Threading.ThreadAbortException
  at mytool.WebCrawler.Crawl () [0x007cb] in <630e3cc849c549498c690f2b568f83e5>:0

* Assertion at aot-runtime.c:2897, condition `!async' not met

Stacktrace:

* Assertion at mini-exceptions.c:955, condition `unwind_options == MONO_UNWIND_NONE' not met

any news about this ?
Comment 8 Ludovic Henry 2017-11-10 23:27:51 UTC
I can reproduce with Mono 5.8.0.40 (2017-10/ce494e3d152)

I get a hang with the following native stacktrace:

> (lldb) bt all
> * thread #1, name = 'tid_307', queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
>   * frame #0: 0x00007fff927b6bf2 libsystem_kernel.dylib`__psynch_cvwait + 10
>     frame #1: 0x00007fff928a27fa libsystem_pthread.dylib`_pthread_cond_wait + 712
>     frame #2: 0x000000010d317b70 mono`mono_os_event_wait_multiple [inlined] mono_os_cond_wait(mutex=<unavailable>) at mono-os-mutex.h:173 [opt]
>     frame #3: 0x000000010d317b5b mono`mono_os_event_wait_multiple(events=0x00007fff52b760c8, nevents=1, waitall=1, timeout=4294967295, alertable=1) at os-event-unix.c:190 [opt]
>     frame #4: 0x000000010d317936 mono`mono_os_event_wait_one(event=0x00007fac7540df20, timeout=<unavailable>, alertable=<unavailable>) at os-event-unix.c:94 [opt]
>     frame #5: 0x000000010d32bb7d mono`mono_thread_info_wait_one_handle(thread_handle=<unavailable>, timeout=<unavailable>, alertable=<unavailable>) at mono-threads.c:1632 [opt]
>     frame #6: 0x000000010d278c0f mono`ves_icall_System_Threading_Thread_Join_internal at threads.c:1789 [opt]
>     frame #7: 0x000000010d278be1 mono`ves_icall_System_Threading_Thread_Join_internal(this_obj=<unavailable>, ms=<unavailable>) at threads.c:1845 [opt]
>     frame #8: 0x000000010d5e8b62
>     frame #9: 0x000000010d5e8a93
>     frame #10: 0x000000010d5e3b93
>     frame #11: 0x000000010d5e3e3d
>     frame #12: 0x000000010d09bd97 mono`mono_jit_runtime_invoke(method=<unavailable>, obj=<unavailable>, params=0x00007fff52b764f8, exc=0xffffffffffffffff, error=<unavailable>) at mini-runtime.c:2800 [opt]
>     frame #13: 0x000000010d25c224 mono`do_runtime_invoke(method=0x00007fac75506b88, obj=0x0000000000000000, params=0x00007fff52b764f8, exc=0x0000000000000000, error=0x00007fff52b76538) at object.c:2849 [opt]
>     frame #14: 0x000000010d25f849 mono`do_exec_main_checked [inlined] mono_runtime_invoke_checked(method=<unavailable>, obj=<unavailable>, error=<unavailable>) at object.c:3002 [opt]
>     frame #15: 0x000000010d25f808 mono`do_exec_main_checked(method=0x00007fac75506b88, args=<unavailable>, error=0x00007fff52b76538) at object.c:4726 [opt]
>     frame #16: 0x000000010d108dff mono`mono_jit_exec(domain=<unavailable>, assembly=<unavailable>, argc=1, argv=0x00007fff52b76870) at driver.g.c:1040 [opt]
>     frame #17: 0x000000010d10b5f4 mono`mono_main [inlined] main_thread_handler at driver.g.c:1109 [opt]
>     frame #18: 0x000000010d10b5c1 mono`mono_main(argc=4, argv=<unavailable>) at driver.g.c:2222 [opt]
>     frame #19: 0x000000010d08b77d mono`main [inlined] mono_main_with_options(argc=<unavailable>, argv=<unavailable>) at main.c:46 [opt]
>     frame #20: 0x000000010d08b769 mono`main(argc=4, argv=<unavailable>) at main.c:339 [opt]
>     frame #21: 0x000000010d08b674 mono`start + 52
>   thread #2, name = 'SGen worker'
>     frame #0: 0x00007fff927b6bf2 libsystem_kernel.dylib`__psynch_cvwait + 10
>     frame #1: 0x00007fff928a27fa libsystem_pthread.dylib`_pthread_cond_wait + 712
>     frame #2: 0x000000010d314fae mono`thread_func [inlined] mono_os_cond_wait(mutex=<unavailable>) at mono-os-mutex.h:173 [opt]
>     frame #3: 0x000000010d314f9b mono`thread_func at sgen-thread-pool.c:165 [opt]
>     frame #4: 0x000000010d314f8d mono`thread_func(data=0x0000000000000000) at sgen-thread-pool.c:196 [opt]
>     frame #5: 0x00007fff928a193b libsystem_pthread.dylib`_pthread_body + 180
>     frame #6: 0x00007fff928a1887 libsystem_pthread.dylib`_pthread_start + 286
>     frame #7: 0x00007fff928a108d libsystem_pthread.dylib`thread_start + 13
>   thread #3, name = 'Finalizer'
>     frame #0: 0x00007fff927af386 libsystem_kernel.dylib`semaphore_wait_trap + 10
>     frame #1: 0x000000010d2c172c mono`finalizer_thread [inlined] mono_os_sem_wait(flags=MONO_SEM_FLAGS_ALERTABLE) at mono-os-semaphore.h:90 [opt]
>     frame #2: 0x000000010d2c1721 mono`finalizer_thread at mono-coop-semaphore.h:43 [opt]
>     frame #3: 0x000000010d2c1715 mono`finalizer_thread(unused=<unavailable>) at gc.c:866 [opt]
>     frame #4: 0x000000010d27d9f0 mono`start_wrapper [inlined] start_wrapper_internal at threads.c:993 [opt]
>     frame #5: 0x000000010d27d953 mono`start_wrapper(data=<unavailable>) at threads.c:1053 [opt]
>     frame #6: 0x00007fff928a193b libsystem_pthread.dylib`_pthread_body + 180
>     frame #7: 0x00007fff928a1887 libsystem_pthread.dylib`_pthread_start + 286
>     frame #8: 0x00007fff928a108d libsystem_pthread.dylib`thread_start + 13
>   thread #4
>     frame #0: 0x00007fff927b744e libsystem_kernel.dylib`__workq_kernreturn + 10
>     frame #1: 0x00007fff928a148e libsystem_pthread.dylib`_pthread_wqthread + 1023
>     frame #2: 0x00007fff928a107d libsystem_pthread.dylib`start_wqthread + 13
>   thread #5, name = 'tid_2103'
>     frame #0: 0x00007fff927b6bf2 libsystem_kernel.dylib`__psynch_cvwait + 10
>     frame #1: 0x00007fff928a27fa libsystem_pthread.dylib`_pthread_cond_wait + 712
>     frame #2: 0x000000010d320900 mono`mono_os_cond_timedwait [inlined] mono_os_cond_wait(cond=0x00007fac7581b160, mutex=0x00007fac7581b120) at mono-os-mutex.h:173 [opt]
>     frame #3: 0x000000010d3208f5 mono`mono_os_cond_timedwait(cond=0x00007fac7581b160, mutex=0x00007fac7581b120, timeout_ms=4294967295) at mono-os-mutex.c:32 [opt]
>     frame #4: 0x000000010d29eba4 mono`mono_w32handle_timedwait_signal_handle [inlined] mono_w32handle_timedwait_signal_naked(cond=<unavailable>, mutex=<unavailable>, timeout=4294967295, poll=0, alerted=<unavailable>) at w32handle.c:871 [opt]
>     frame #5: 0x000000010d29eb9c mono`mono_w32handle_timedwait_signal_handle(handle=<unavailable>, timeout=<unavailable>, poll=0, alerted=<unavailable>) at w32handle.c:988 [opt]
>     frame #6: 0x000000010d29e9c0 mono`mono_w32handle_wait_one(handle=0x0000000000000002, timeout=4294967295, alertable=<unavailable>) at w32handle.c:1109 [opt]
>     frame #7: 0x000000010d29ecd6 mono`mono_w32handle_wait_multiple(handles=<unavailable>, nhandles=<unavailable>, waitall=<unavailable>, timeout=<unavailable>, alertable=<unavailable>) at w32handle.c:1145 [opt]
>     frame #8: 0x000000010d278f84 mono`ves_icall_System_Threading_WaitHandle_Wait_internal(handles=<unavailable>, numhandles=<unavailable>, waitall=<unavailable>, timeout=-1, error=0x0000700005076550) at threads.c:1920 [opt]
>     frame #9: 0x000000010d5f0c60
>     frame #10: 0x000000010d5f090b
>     frame #11: 0x000000010d5f0633
>     frame #12: 0x000000010d5f04b3
>     frame #13: 0x000000010d5f02b3
>     frame #14: 0x000000010d5f0209
>     frame #15: 0x000000010d5ef07a
>     frame #16: 0x000000010d5e952b
>     frame #17: 0x000000010d5e8753
>     frame #18: 0x000000010d5e86ab
>     frame #19: 0x000000010d5e85d3
>     frame #20: 0x000000010d5e8143
>     frame #21: 0x000000010d5e79b3
>     frame #22: 0x000000010d5e74ce
>     frame #23: 0x000000010d5e7243
>     frame #24: 0x000000010d5e6fe3
>     frame #25: 0x000000010d5e6ddb
>     frame #26: 0x000000010d5e6ced
>     frame #27: 0x000000010d09bd97 mono`mono_jit_runtime_invoke(method=<unavailable>, obj=<unavailable>, params=0x0000700005076ea8, exc=0x00000000ffffffff, error=<unavailable>) at mini-runtime.c:2800 [opt]
>     frame #28: 0x000000010d25c224 mono`do_runtime_invoke(method=0x00007fac7582c028, obj=0x000000010d800888, params=0x0000700005076ea8, exc=0x0000000000000000, error=0x0000700005076e40) at object.c:2849 [opt]
>     frame #29: 0x000000010d27da1b mono`start_wrapper at threads.c:1001 [opt]
>     frame #30: 0x000000010d27d953 mono`start_wrapper(data=<unavailable>) at threads.c:1053 [opt]
>     frame #31: 0x00007fff928a193b libsystem_pthread.dylib`_pthread_body + 180
>     frame #32: 0x00007fff928a1887 libsystem_pthread.dylib`_pthread_start + 286
>     frame #33: 0x00007fff928a108d libsystem_pthread.dylib`thread_start + 13

A log of the trace can be found at https://gist.github.com/luhenry/45214217db913d788a7e131fab4022af
Comment 9 Ludovic Henry 2017-11-20 22:52:58 UTC
https://github.com/mono/mono/pull/6023

Note You need to log in before you can comment on or make changes to this bug.