[Bug 48847] New: dotnet471: often gets a critical section timeout
https://bugs.winehq.org/show_bug.cgi?id=48847 Bug ID: 48847 Summary: dotnet471: often gets a critical section timeout Product: Wine Version: 5.5 Hardware: x86 OS: Linux Status: NEW Severity: normal Priority: P2 Component: -unknown Assignee: wine-bugs(a)winehq.org Reporter: austinenglish(a)gmail.com Distribution: --- Created attachment 66764 --> https://bugs.winehq.org/attachment.cgi?id=66764 bt all I've been seeing this when running winetricks-test, for dotnet46* and dotnet471. This info is for dotnet471. austin(a)laptop ~ $ grep 'wait timed out' /tmp/out.txt | sort -u 0048:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 0048, blocked by 006e, retrying (60 sec) 006e:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 006e, blocked by 0174, retrying (60 sec) 00ad:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 00ad, blocked by 006e, retrying (60 sec) 00bb:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 00bb, blocked by 0174, retrying (60 sec) 00e2:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 00e2, blocked by 006e, retrying (60 sec) 0114:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 0114, blocked by 0174, retrying (60 sec) 0166:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 0166, blocked by 006e, retrying (60 sec) 0169:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 0169, blocked by 006e, retrying (60 sec) 016c:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 016c, blocked by 0174, retrying (60 sec) 0193:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 0193, blocked by 006e, retrying (60 sec) winedbg bt all is attached. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |focht(a)gmx.net Keywords| |dotnet, Installer --- Comment #1 from Anastasius Focht <focht(a)gmx.net> --- Hello Austin, the 'bt all' doesn't seem to match your console output. There are way too many differences in the thread ids. Even if thread 006e has died while owning lock(s), many other threads blocked by it don't appear in winedbg list. Please provide console and winedbg logs from the same run. Include 'info process' and 'info thread' output as well. Your 'bt all' shows it's already happening at .NET Framework 4.5 verb. Does testing 'winetricks -q dotnet45' exhibit the same problems? --- snip --- Backtracing for thread 0009 in process 0008 (Y:\dotnet45\dotnetfx45_full_x86_x64.exe): --- snip --- Also try to make a "lightweight" trace log if possible: --- snip --- $ WINEDEBUG=+timestamp,+pid,+seh,+process,+loaddll ... >>log.txt 2>&1 --- snip --- Relay logs would be rather huge and make the issue potentially disappear. FYI I can't reproduce it here with Wine 5.5. It successfully installed ten consecutive times, each with clean 64-bit WINEPREFIX. 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 Austin English <austinenglish(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- Attachment #66764|0 |1 is obsolete| | --- Comment #2 from Austin English <austinenglish(a)gmail.com> --- Created attachment 66784 --> https://bugs.winehq.org/attachment.cgi?id=66784 terminal output (try 2) -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #3 from Austin English <austinenglish(a)gmail.com> --- Created attachment 66785 --> https://bugs.winehq.org/attachment.cgi?id=66785 bt all -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #4 from Austin English <austinenglish(a)gmail.com> --- Created attachment 66786 --> https://bugs.winehq.org/attachment.cgi?id=66786 info process/thread -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #5 from Austin English <austinenglish(a)gmail.com> --- I wasn't able to reproduce in 25 tries with WINEDEBUG set, but was able to get the output/winedbg info from another deadlock. Note that I've seen similar in dotnet461 (usually when running winetricks' tests), but I'm hoping they're the same root issue. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #6 from Anastasius Focht <focht(a)gmx.net> --- Hello Austin, --- snip --- Wine-dbg>info process pid threads executable (all id:s are in hex) 0000019d 1 'winedbg.exe' 0000001b 4 'explorer.exe' 0000000e 10 'services.exe' 000000d8 4 \_ 'mscorsvw.exe' 000000c7 5 \_ 'rpcss.exe' 000000c0 7 \_ 'svchost.exe' 00000020 5 \_ 'winedevice.exe' 00000019 3 \_ 'plugplay.exe' 00000011 4 \_ 'winedevice.exe' 00000008 1 'NDP461-KB3102436-x86-x64-AllOS-ENU.exe' 0000002e 5 \_ 'Setup.exe' 0000003c 2 \_ 'msiexec.exe' 00000059 14 \_ 'ngen.exe' 0000017d 5 \_ 'mscorsvw.exe' 00000179 6 \_ 'mscorsvw.exe' 000000a6 12 \_ 'mscorsvw.exe' Wine-dbg>info thread process tid prio (all id:s are in hex) 00000008 NDP461-KB3102436-x86-x64-AllOS-ENU.exe 00000009 0 ... 00000059 ngen.exe 0000018e 0 0000014b 0 00000137 0 0000011b 0 00000117 0 00000102 0 00000100 0 000000a7 0 00000132 0 00000116 0 0000010e 0 0000010b 0 00000108 0 0000005a 0 --- snip --- --- snip --- ... 0105:err:ole:ifproxy_release_public_refs IRemUnknown_RemRelease failed with error 0x800706be 0105:err:ole:ifproxy_release_public_refs IRemUnknown_RemRelease failed with error 0x800706be 0105:err:ole:ifproxy_release_public_refs IRemUnknown_RemRelease failed with error 0x800706be 0105:err:ole:ifproxy_release_public_refs IRemUnknown_RemRelease failed with error 0x800706be 0105:err:ole:ifproxy_release_public_refs IRemUnknown_RemRelease failed with error 0x800706be ... 0105:fixme:ole:NdrClearOutParameters (01BEF664,008FAC56,01BEFD9C): stub 0105:err:seh:setup_exception_record stack overflow 756 bytes in thread 0105 eip 1008f936 esp 01af103c stack 0x1af0000-0x1af1000-0x1bf0000 00a7:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 00a7, blocked by 0105, retrying (60 sec) 0100:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 0100, blocked by 0105, retrying (60 sec) 0132:err:ntdll:RtlpWaitForCriticalSection section 0x110060 "heap.c: main process heap section" wait timed out in thread 0132, blocked by 0105, retrying (60 sec) 0108:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 0108, blocked by 0132, retrying (60 sec) 014b:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 014b, blocked by 0132, retrying (60 sec) 011b:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 011b, blocked by 0132, retrying (60 sec) 0137:err:ntdll:RtlpWaitForCriticalSection section 0x7bd2c220 "loader.c: loader_section" wait timed out in thread 0137, blocked by 0132, retrying (60 sec) ... --- snip --- Thread 0105 seems to be the culprit here. It was likely belonging to ngen client (010x tid range). Happened maybe during update of GAC ('ngen update' / 'ngen executeQueuedItems'). If that's the case you could try to force run GAC update continuously (loop) after installation and see if it breaks at some point (tee + grep for exception/timeout patterns in output). --- snip --- # 32-bit assemblies $ wine "c:\\windows\\Microsoft.NET\\Framework\\v4.0.30319\\ngen.exe" update # 64-bit assemblies $ wine "c:\\windows\\Microsoft.NET\\Framework64\\v4.0.30319\\ngen.exe" update --- snip --- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 Igor Zinovyev <zinigor+winehq(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |zinigor+winehq(a)gmail.com --- Comment #7 from Igor Zinovyev <zinigor+winehq(a)gmail.com> --- The GOG Galaxy application seems to be affected by this bug as well. Since this entry seems to be quite specific to the dotnet installation, should I add the trace here, or create a separate report? -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #8 from Austin English <austinenglish(a)gmail.com> --- (In reply to Anastasius Focht from comment #1)
FYI I can't reproduce it here with Wine 5.5. It successfully installed ten consecutive times, each with clean 64-bit WINEPREFIX.
FWIW, with winetricks-test, it's relatively reliable. Running dotnet471 in a loop of 1000 last night, didn't fail until iteration #107. winedbg hung when I tried to dump info. Not sure if it was machine state or a wine regression, I'm retrying with WINEDEBUG set (and will try other wine versions if needed). -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 Alexandr Oleynikov <sashok.olen(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |sashok.olen(a)gmail.com --- Comment #9 from Alexandr Oleynikov <sashok.olen(a)gmail.com> --- I've noticed that this issue happens more commonly on slow machines. Perhaps it would be easier to reproduce this by introducing some kind of a hard load on the system? -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 Forest <forestix(a)sonic.net> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |forestix(a)sonic.net -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #10 from Austin English <austinenglish(a)gmail.com> --- Still in wine-6.6. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 ax 34noff <otaku(a)rambler.ru> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |otaku(a)rambler.ru -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #11 from ax 34noff <otaku(a)rambler.ru> --- It looks like a regression, i didn't have such problem with Wine 5.7 from Lutris. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #12 from Austin English <austinenglish(a)gmail.com> --- (In reply to ax 34noff from comment #11)
It looks like a regression, i didn't have such problem with Wine 5.7 from Lutris.
It definitely is a regression. It's not very clear what caused it though, as there have been several dotnet regressions (some fixed, some not) over the last year. At this point, it would likely require bisecting + cherry picking multiple fixes, and is not for the faint of heart.. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 m0rvj <johnpgoodman(a)gmail.com> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |johnpgoodman(a)gmail.com --- Comment #13 from m0rvj <johnpgoodman(a)gmail.com> --- If someone can explain to me how to automate the testing, I'd be minded to give it a go... I've done plenty of regression testing so I know how to do the bisect etc. The bit I'd need advice on is how to test whether the dotnet installation succeeded? -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #14 from Austin English <austinenglish(a)gmail.com> --- (In reply to m0rvj from comment #13)
If someone can explain to me how to automate the testing, I'd be minded to give it a go... I've done plenty of regression testing so I know how to do the bisect etc. The bit I'd need advice on is how to test whether the dotnet installation succeeded?
`winetricks --verify dotnet471` will reproduce it, rarely, when run in a loop (be sure to cleanup between runs). I more often see it when running winetricks's unit tests, see https://github.com/Winetricks/winetricks#tests But again, it's not consistent, and what causes it to fail is unclear. In addition, native .net in general has had several intermixed regressions that will make this a challenge to accurately bisect. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #15 from m0rvj <johnpgoodman(a)gmail.com> --- Would a debug log help? If so which options are needed? WINEDEBUG=+seh -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #16 from Austin English <austinenglish(a)gmail.com> --- I retested with 7.6, now that 52722 is fixed. Reproduced it on the 9th try. Unfortunately didn't get a good backtrace (bug 52790/pebkac). I'll upload the lightweight (WINEDEBUG=+timestamp,+pid,+seh,+process,+loaddll) log. Will try again.. -- 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.
https://bugs.winehq.org/show_bug.cgi?id=48847 --- Comment #17 from Austin English <austinenglish(a)gmail.com> --- Created attachment 72176 --> https://bugs.winehq.org/attachment.cgi?id=72176 WINEDEBUG=+timestamp,+pid,+seh,+process,+loaddll, wine-7.6 -- 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.
participants (1)
-
WineHQ Bugzilla