[Bug 37922] Unity3D 4.6 (.NET app) freezes/hangs sometimes when reopening a newly created project (thread suspension during exit phase with loader lock held)

wine-bugs at winehq.org wine-bugs at winehq.org
Sun Jan 18 12:19:56 CST 2015


https://bugs.winehq.org/show_bug.cgi?id=37922

Anastasius Focht <focht at gmx.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
           Keywords|                            |dotnet, download
                URL|                            |http://unity3d.com/unity/do
                   |                            |wnload/download-windows
          Component|-unknown                    |ntdll
            Summary|Unity3D 4.6 (.NET app)      |Unity3D 4.6 (.NET app)
                   |freezes/hangs sometimes     |freezes/hangs sometimes
                   |when reopening a newly      |when reopening a newly
                   |created project             |created project (thread
                   |                            |suspension during exit
                   |                            |phase with loader lock
                   |                            |held)

--- Comment #1 from Anastasius Focht <focht at gmx.net> ---
Hello folks again,

I used the following 'winetricks' extension verb for installation:

https://github.com/Unity3D-Wine-Support/Unity3D-on-Wine/blob/master/unity3d.verb

--- snip ---
$ winetricks --no-isolate -q unity3d
--- snip ---

Unfortunately using full relay trace doesn't work here.
Relay thunks cause crashes much earlier in other places which might be target
for future investigation when no other interesting bugs are available hehe.

The manifestation of the frozen GUI is visible in console:

--- snip ---
0042:err:ntdll:RtlpWaitForCriticalSection section 0x7bcdbf44
"/home/focht/projects/wine/wine.repo/src/dlls/ntdll/loader.c: loader_section"
wait timed out in thread 0042, blocked by 002e, retrying (60 sec) 
--- snip ---

After many trial runs I managed to get one log with the loader deadlock and
attached the debugger for better overview:

--- snip ---
Wine-dbg>info process
 pid      threads  executable (all id:s are in hex)
 00000022 1        'explorer.exe'
 0000000e 5        'services.exe'
 0000001b 3        \_ 'plugplay.exe'
 00000014 4        \_ 'winedevice.exe'
 00000008 5        'Unity.exe'
 00000041 11       \_ 'Unity.exe'

Wine-dbg>info thread
process  tid      prio (all id:s are in hex)
00000008 Unity.exe
    0000003e    0
    0000003d    0
    00000029    0
    00000028    0
    00000009    0
...
00000041 Unity.exe
    00000037    0
    00000040    0
    0000002f    0
    0000002e    0
    00000032    0
    00000034    0
    00000012    0
    00000047    0
    00000044    0
    00000043    0
    00000042    0
...
--- snip ---

The first Unity3D process is not that important (for now).
When you reload the project it starts a new instance (child process).

The deadlocked threads in question:

tid 0x42 = main thread

--- snip ---
Wine-dbg>bt 0x42
Backtrace:
=>0 0xf7708430 __kernel_vsyscall+0x10() in [vdso].so (0x00000000)
  1 0xf741f707 syscall+0x26() in libc.so.6 (0x00000000)
  2 0x7bc39a85 futex_wait+0x4c(addr=0x7bcdbf54, val=0, timeout=0x23e9d84)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:69] in ntdll
(0x023e9d68)
  3 0x7bc39bc7 fast_wait+0x4c(crit=0x7bcdbf44, timeout=0x3c)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:108] in ntdll
(0x023e9d98)
  4 0x7bc39d44 wait_semaphore+0x24(crit=0x7bcdbf44, timeout=0x3c)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:229] in ntdll
(0x023e9ed8)
  5 0x7bc3a243 RtlpWaitForCriticalSection+0x146(crit=<couldn't compute
location>)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:452] in ntdll
(0x023e9fa8)
  6 0x7bc3a54c RtlEnterCriticalSection+0xdc(crit=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:566] in ntdll
(0x023e9ff8)
  7 0x7bc55bcd LdrLockLoaderLock+0x115(flags=<couldn't compute location>,
result=<couldn't compute location>, magic=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/loader.c:1378] in ntdll
(0x023ea058)
  8 0x7b85a93b GetModuleFileNameW+0xca(hModule=<couldn't compute location>,
lpFileName=<couldn't compute location>, size=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/kernel32/module.c:695] in
kernel32 (0x023ea0d8)
  9 0x7eb4a6b7 GetIconInfoExW+0x282(icon=<couldn't compute location>,
info=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/user32/cursoricon.c:2084] in
user32 (0x023ea158) 

  24 0x7eba6594 MessageBoxA+0x45(hWnd=<couldn't compute location>,
text=<couldn't compute location>, title=<couldn't compute location>,
type=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/user32/msgbox.c:381] in user32
(0x023eaf98)
  25 0x0a34aa59 in mono (+0x10aa58) (0x023eafb8)
  26 0x0a34b38e in mono (+0x10b38d) (0x023eb2b0)
  27 0x0a34c6f9 in mono (+0x10c6f8) (0x023eb2cc)
...
--- snip --

The main thread needs the loader lock due to retrieval of executable name from
modules list. Unfortunately the loader lock is already taken...

Some Mono internal thread (finalizer or garbage collector):

--- snip ---
Wine-dbg>bt 0x2e
Backtrace:
=>0 0xf7708430 __kernel_vsyscall+0x10() in [vdso].so (0x0c69e5c8)
  1 0xf74f73cf pthread_sigmask+0x3e() in libpthread.so.0 (0x0c69e5c8)
  2 0x7bc7f41b wine_server_call+0x7a(req_ptr=0xc69e5e0)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/server.c:298] in ntdll
(0x0c69e5c8)
  3 0x7bc62f05 close_handle+0x7f(handle=0x4b8)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/om.c:355] in ntdll
(0x0c69e668)
  4 0x7bc62f39 NtClose+0x13(Handle=0x4b8)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/om.c:376] in ntdll
(0x0c69e688)
  5 0x7b86a3bf CloseHandle+0x110(handle=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/kernel32/process.c:3038] in
kernel32 (0x0c69e708)
  6 0x0a34b081 in mono (+0x10b080) (0x0c69e728)
  7 0x0a34b555 in mono (+0x10b554) (0x0c69e738)
  8 0x0a2f08f2 in mono (+0xb08f1) (0x0c69e74c)
  9 0x0a35743b in mono (+0x11743a) (0x0c69e78c)
  10 0x0a3574e3 in mono (+0x1174e2) (0x0c69e798)
  11 0x7bc52b26 call_dll_entry_point+0x15() in ntdll (0x0c69e7b8)
--- snip ---

At the same time a couple of other threads are "fighting" for the loader lock
too:

--- snip ---
Wine-dbg>bt 0x2f
Backtrace:
=>0 0xf7708430 __kernel_vsyscall+0x10() in [vdso].so (0x00000000)
  1 0xf741f707 syscall+0x26() in libc.so.6 (0x00000000)
  2 0x7bc39a85 futex_wait+0x4c(addr=0x7bcdbf54, val=0, timeout=0xc93e694)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:69] in ntdll
(0x0c93e678)
  3 0x7bc39bc7 fast_wait+0x4c(crit=0x7bcdbf44, timeout=0x5)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:108] in ntdll
(0x0c93e6a8)
  4 0x7bc39d44 wait_semaphore+0x24(crit=0x7bcdbf44, timeout=0x5)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:229] in ntdll
(0x0c93e7e8)
  5 0x7bc3a169 RtlpWaitForCriticalSection+0x6c(crit=<couldn't compute
location>)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:442] in ntdll
(0x0c93e8b8)
  6 0x7bc3a54c RtlEnterCriticalSection+0xdc(crit=<couldn't compute location>)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/critsection.c:566] in ntdll
(0x0c93e908)
  7 0x7bc59113 LdrShutdownThread+0x82()
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/loader.c:2588] in ntdll
(0x0c93e998)
  8 0x7bc8d87c exit_thread+0xb1(status=0)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/thread.c:378] in ntdll
(0x0c93ea58)
  9 0x7bc86685 call_thread_func_wrapper+0x14() in ntdll (0x0c93ea68)
  10 0x7bc866c5 call_thread_func+0x3e(entry=0xa34b4ab, arg=0xa69afc0,
frame=0xc93eb68)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/signal_i386.c:2723] in
ntdll (0x0c93eb48)
  11 0x7bc8665a call_thread_entry_point+0x11() in ntdll (0x0c93eb68)
  12 0x7bc8da62 start_thread+0x11a(info=0x81fe4fb8)
[/home/focht/projects/wine/wine.repo/src/dlls/ntdll/thread.c:429] in ntdll
(0x0c93f3a8)
  13 0xf74f29dc start_thread+0xcb() in libpthread.so.0 (0x0c93f468)
--- snip ---

A sempaphore triggers the shutdown of multiple finalizer/gc threads.
All start their thread exit in parallel (by closing their duplicated thread
handle and returning from entry).

--- snip ---
$ pwd
/home/focht/wine-apps/unity3d/drive_c/Program Files/Unity/Editor

$ WINEDEBUG=+tid,+seh,+loaddll,+process,+ntdll,+snoop,+server,+debugstr,+module
wine ./Unity.exe >>log.txt 2>&1
...
0042:warn:debugstr:OutputDebugStringA "Cleanup mono\n" 
...
0042:RET  mono.mono_domain_unload() retval=00000001 ret=00841c14
0042:CALL mono.mono_gc_max_generation() ret=00841c1d
0042:RET  mono.mono_gc_max_generation() retval=00000000 ret=00841c1d
0042:CALL mono.mono_gc_collect(00000000) ret=00841c24 
...
0042:RET  mono.mono_gc_collect() retval=00000001 ret=00841c24
...
0042:CALL mono.mono_threads_set_shutting_down(<unknown, check return>)
ret=00846a52 
...
0042:RET  mono.mono_threads_set_shutting_down() retval=00000000 ret=00846a52
...
0042:CALL mono.mono_thread_pool_cleanup(<unknown, check return>) ret=00846a58 
...
0043: select() = PENDING { timeout=infinite, call={APC_NONE}, apc_handle=0000 }
0042: release_semaphore( handle=0170, count=00000004 )
0031: *wakeup* signaled=0
0030: *wakeup* signaled=0
0032: *wakeup* signaled=0
0034: *wakeup* signaled=0 
...
0031:trace:module:LdrShutdownThread () 
...
0030:trace:module:LdrShutdownThread () 
...
002e: close_handle( handle=04a8 )
...
002e: close_handle() = 0
...
002e:trace:module:LdrShutdownThread () 
...
002e:trace:module:MODULE_InitDLL (0xf6ec0000
L"winealsa.drv",THREAD_DETACH,(nil)) - CALL
0042: get_thread_info() = 0 { pid=0041, tid=002e, teb=81fa8000,
affinity=0000000f, creation_time=1d03333112ab2d4 (-5.6711900), exit_time=0,
exit_code=259, priority=0, last=0 }
002e:trace:module:MODULE_InitDLL (0xf6ec0000,THREAD_DETACH,(nil)) - RETURN 1
002e:trace:module:MODULE_InitDLL (0xa240000 L"mono.dll",THREAD_DETACH,(nil)) -
CALL
...
0042: suspend_thread( handle=04b8 )
002e: *sent signal* signal=10
0042: suspend_thread() = 0 { count=0 }
002e: close_handle( handle=04b8 )
002e: close_handle() = 0
...
0042: get_thread_info( handle=04cc, tid_in=0000 )
0042: get_thread_info() = 0 { pid=0041, tid=002f, teb=81fe4000,
affinity=0000000f, creation_time=1d033331146e09e (-5.4867260), exit_time=0,
exit_code=259, priority=0, last=0 }
002e: set_suspend_context(
context={cpu=x86,eip=f7708430,esp=0c69e484,ebp=0c69e5c8,eflags=00000296,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=00000000,ebx=00000002,ecx=0c69e538,edx=00000000,esi=00000008,edi=7bcd3000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,fp.ctrl=ffff027f,fp.status=ffff0000,fp.tag=ffffffff,fp.err_off=0a2484a4,fp.err_sel=00000023,fp.data_off=0c69e938,fp.data_sel=ffff002b,fp.cr0npx=00000000,fp.reg0=0.5,fp.reg1=1,fp.reg2=1,fp.reg3=52,fp.reg4=6196,fp.reg5=344,fp.reg6=22,fp.reg7=2.25,extended={...}}
)
002e: set_suspend_context() = 0
...
0042: suspend_thread( handle=04cc )
...
0042: suspend_thread() = 0 { count=0 }
002e: select( flags=2, cookie=81fab33c, timeout=0, prev_apc=0000, result={},
data={} )
002e: select() = PENDING { timeout=1d03333148c1a1c (+0.0000000),
call={APC_NONE}, apc_handle=0000 } 
...
0042: create_window( parent=00010020, owner=00000000, atom=8002,
instance=00000000, class=L"" )
0042: create_window() = 0 { handle=00010154, parent=00010020, owner=00000000,
extra=30, class_ptr=00131a18 } 
...
0042:err:ntdll:RtlpWaitForCriticalSection section 0x7bcdbf44
"/home/focht/projects/wine/wine.repo/src/dlls/ntdll/loader.c: loader_section"
wait timed out in thread 0042, blocked by 002e, retrying (60 sec) 
--- snip ---

NOTE: I left out various traces/calls from multiple interleaving threads. The
shutdown sequence is highly multi-threaded.

The OS loader lock must be acquired by the exiting thread to deliver the thread
detach notification.
In that short time window, Mono manages to suspend the thread which causes a
deadlock on all other threads requiring the loader lock for their own detach
notifications and the main thread.

Although this looks like a bug in Mono to me (surprise... not!), one solution
could be to forbid handling of APCs that ought to suspend the thread in the
final phase of thread exit.

There are various reports from Windows users that Unity3D crashes or freezes
for them this problem might be present on Windows too, making this bug report
invalid.

$ sha1sum UnitySetup-4.6.0.exe 
5cc7a85e186c965d230bcc7a2a463d92fbc2f7fc  UnitySetup-4.6.0.exe

$ du -sh UnitySetup-4.6.0.exe 
1.3G    UnitySetup-4.6.0.exe

$ wine --version
wine-1.7.34-74-gcf92569

Regards

-- 
Do not reply to this email, post in Bugzilla using the
above URL to reply.
You are receiving this mail because:
You are watching all bug changes.



More information about the wine-bugs mailing list