When trying to run Microsoft Digital Image Pro, I occasionally get problems when loading it. The splash screen comes up, and then it hangs. This problem only happens occasionally. I have not, to date, managed to reproduce it with relay turned on. This is what I do get on screen:
err:module:import_dll No implementation for USER32.dll.GetScrollBarInfo imported from L"C:\Program Files\Microsoft Picture It! 9\piutil.dll", setting to 0xdeadbeef err:font:ReadFontDir Can't open directory "/win/windows/fonts" err:imagelist:ImageList_LoadImageW Error loading image! err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080deec err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080ea54 err:toolbar:ToolbarWindowProc unknown msg 2210 wp=00ca0001 lp=00010051 err:toolbar:ToolbarWindowProc unknown msg 204e wp=40c757d8 lp=4080eaa4 err:toolbar:ToolbarWindowProc unknown msg 2210 wp=57d80001 lp=00010053 fixme:toolbar:TOOLBAR_SetPadding stub - nothing done with values, cx=7, cy=9 fixme:imm:ImmAssociateContext (0x10056, (nil)): semi-stub fixme:imm:ImmAssociateContext (0x10058, (nil)): semi-stub fixme:imm:ImmAssociateContext (0x1005a, (nil)): semi-stub fixme:hook:NotifyWinEvent (32784,0x10056,-4,0)-stub! fixme:hook:NotifyWinEvent (32784,0x1005a,-4,0)-stub! fixme:hook:NotifyWinEvent (32782,0x10058,-4,0)-stub! err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080e61c fixme:imm:ImmAssociateContext (0x1009d, (nil)): semi-stub err:ntdll:RtlpWaitForCriticalSection section 0x4020fc60 "loader.c: loader_section" wait timed out in thread 0009, blocked by 000c, retrying (60 sec) err:ntdll:RtlpWaitForCriticalSection section 0x7c38b208 "?" wait timed out in thread 000c, blocked by 0009, retrying (60 sec)
On Tue, 2003-12-09 at 13:51, Shachar Shemesh wrote:
When trying to run Microsoft Digital Image Pro, I occasionally get problems when loading it. The splash screen comes up, and then it hangs. This problem only happens occasionally. I have not, to date, managed to reproduce it with relay turned on.
You might want to do a run with +tid,+seh,+debugstr and then when it deadlocks (hopefully it will, sounds like a race) attach with winedbg then get backtraces of the threads that stopped. BTW it looks like something died inside a PROCESS_ATTACH or THREAD_ATTACH as evidenced by the presence of the loader section there. Perhaps it tried to access GetScrollBarInfo? I've noticed that sometimes operations that should cause a crash are silently swallowed and simply cause a deadlock somewhere.
Mike Hearn wrote:
On Tue, 2003-12-09 at 13:51, Shachar Shemesh wrote:
When trying to run Microsoft Digital Image Pro, I occasionally get problems when loading it. The splash screen comes up, and then it hangs. This problem only happens occasionally. I have not, to date, managed to reproduce it with relay turned on.
You might want to do a run with +tid,+seh,+debugstr
I'm not sure I'll manage to do that. The problem happens so rarely, and I'm working on other problems in the program, that I'm not sure the added output is something I can do that over time. Not to mention that when I exit the program with these settings, I get a long loop of: 0009:trace:seh:EXC_CallHandler calling handler at 0x66e5d029 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x66e5c8c2 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x102e826 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x401cfca8 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 2 0009:trace:seh:EXC_CallHandler calling handler at 0x7c34240d code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x66e5d029 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1
it's followed by 0009:trace:seh:EXC_CallHandler calling handler at 0x401cfca8 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 2 0009:trace:seh:EXC_CallHandler calling handler at 0x401d0981 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x401cfca8 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 2 0009:trace:seh:EXC_CallHandler calling handler at 0x6759352c code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x102bfd8 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x102ffb3 code=c0000005 flags=10 0009:trace:seh:EXC_CallHandler handler returned 1 0009:trace:seh:EXC_CallHandler calling handler at 0x102bfd8 code=c0000005 flags=10 0009:warn:seh:setup_exception exception outside of stack limits in thread 0009 eip 401db925 esp 4071123c stack 0x40710000-0x40810000 0009:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0 addr=0x401db925 0009:trace:seh:EXC_RtlRaiseException info[0]=00000000 0009:trace:seh:EXC_RtlRaiseException info[1]=00000000 0009:trace:seh:EXC_CallHandler calling handler at 0x401d0981 code=c0000005 flags=0 0009:trace:seh:EXC_RtlUnwind code=c0000005 flags=2 0009:trace:seh:EXC_CallHandler calling handler at 0x401cfca8 code=c0000005 flags=2 0009:trace:seh:EXC_CallHandler handler returned 1 0009:err:seh:setup_exception stack overflow 2692 bytes in thread 0009 eip 7c34b55e esp 4071057c stack 0x40710000-0x40810000
I'm not sure what seh does, but it's triggering other problems as well.
and then when it deadlocks (hopefully it will, sounds like a race)
I don't know of other causes for problems that only happen OCCASIONALLY. Yes, it's a race.
attach with winedbg then get backtraces of the threads that stopped.
How can I attach to two threads?
BTW it looks like something died inside a PROCESS_ATTACH or THREAD_ATTACH as evidenced by the presence of the loader section there. Perhaps it tried to access GetScrollBarInfo?
Wouldn't that cause it to bomb each and every time? Like I said before - usually it works fine.
I've noticed that sometimes operations that should cause a crash are silently swallowed and simply cause a deadlock somewhere.
This program sets up tons of error handlers. Usually, however, they just bring up a dialog that says "this program has crashed. Do you want us to rerun it for you?". Another fine Microsoft invention.
However, even when that happens, I can usually see the error on the debug output. I have had lots of those when trying out the unicows solution (which Alexandre replaced with something both simpler and more elegant - frustrating).
Shachar
On Tue, 09 Dec 2003 18:47:18 +0200, Shachar Shemesh wrote:
I'm not sure I'll manage to do that. The problem happens so rarely, and I'm working on other problems in the program, that I'm not sure the added output is something I can do that over time. Not to mention that when I exit the program with these settings, I get a long loop of: 0009:trace:seh:EXC_CallHandler calling handler at 0x66e5d029 code=c0000005 flags=10
Well c000005 is "access violation" iirc, so this is definately not normal behaviour :)
I'm not sure what seh does, but it's triggering other problems as well.
It just turns on exception tracing (seh == structured exception handling)
I don't know of other causes for problems that only happen OCCASIONALLY. Yes, it's a race.
Hehe, sorry :) Qualifying everything with a "maybe" is a bad habit of mine.
How can I attach to two threads?
You don't, you attach to a process then pass the thread id to the "bt" command, ie:
attach 0x0e (process id) bt 0x9 bt 0x1 ... etc ....
Wouldn't that cause it to bomb each and every time? Like I said before - usually it works fine.
Yes, true.
This program sets up tons of error handlers. Usually, however, they just bring up a dialog that says "this program has crashed. Do you want us to rerun it for you?". Another fine Microsoft invention.
Hmm, beats simply writing "Segmentation fault" into the ether, which is the default linux behaviour when run from a gui :)
thanks -mike
Mike Hearn wrote:
How can I attach to two threads?
You don't, you attach to a process then pass the thread id to the "bt" command, ie:
attach 0x0e (process id) bt 0x9 bt 0x1 ... etc ....
Ok, it finally happened again. Not at the same place (on program exit rather than entry), and without any debug strings, but beggers can't afford to be choosers.
The console messages:
err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080f14c err:toolbar:ToolbarWindowProc unknown msg 204e wp=40c757d8 lp=4080f22c fixme:mshtml:MSHTML_DllCanUnloadNow fixme:mshtml:MSHTML_DllCanUnloadNow fixme:mshtml:MSHTML_DllCanUnloadNow fixme:mshtml:MSHTML_DllCanUnloadNow err:toolbar:ToolbarWindowProc unknown msg 204e wp=40c757d8 lp=4080f22c err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080f22c err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080f14c err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080f22c err:toolbar:ToolbarWindowProc unknown msg 204e wp=000000ca lp=4080f14c err:ntdll:RtlpWaitForCriticalSection section 0x40b13aa0 "../../windows/user.c: USER_SysLevel" wait timed out in thread 0016, blocked by 0009, retrying (60 sec) err:ntdll:RtlpWaitForCriticalSection section 0x4020fc60 "loader.c: loader_section" wait timed out in thread 0009, blocked by 0016, retrying (60 sec) err:ntdll:RtlpWaitForCriticalSection section 0x40b13aa0 "../../windows/user.c: USER_SysLevel" wait timed out in thread 000b, blocked by 0009, retrying (60 sec) err:font:ReadFontDir Can't open directory "/win/windows/fonts" err:ntdll:RtlpWaitForCriticalSection section 0x4020fc60 "loader.c: loader_section" wait timed out in thread 0009, blocked by 0016, retrying (60 sec) err:ntdll:RtlpWaitForCriticalSection section 0x4020fc60 "loader.c: loader_section" wait timed out in thread 000b, blocked by 0016, retrying (60 sec)
The debug output:
Wine-dbg>walk thread process tid prio 00000018 0000001a 0 00000019 0 00000008 (D) C:\Program Files\Microsoft Picture It! 9\pi.exe 00000016 0 <== 00000010 00000012 0 00000011 0 00000008 (D) C:\Program Files\Microsoft Picture It! 9\pi.exe 0000000b 0 0000000a 0 00000009 0 Wine-dbg>bt 0x16 Backtrace: =>0 0x4010e8ab (NTDLL.DLL._memccpy+0x5202b in libc.so.6) (ebp=40934c60) 1 0x401f4002 (NTDLL_wait_for_multiple_objects+0xbf(count=0x0, handles=0x0, flags=0x8, timeout=0x40934d10) [sync.c:578] in NTDLL.DLL) (ebp=40934cf8) 2 0x401f1edd (usr1_handler+0x4e(__signal=0xa, __context=0x4f) [signal_i386.c:1123] in NTDLL.DLL) (ebp=40934d1c) 3 0x4006e498 (NTDLL.DLL.toupper+0x6208 in libc.so.6) (ebp=4c725f8c) 4 0x401f4002 (NTDLL_wait_for_multiple_objects+0xbf(count=0x1, handles=0x4c726078, flags=0xc, timeout=0x4c72606c) [sync.c:578] in NTDLL.DLL) (ebp=4c726024) 5 0x401f40ae (NTDLL.DLL.NtWaitForMultipleObjects+0x74 in NTDLL.DLL) (ebp=4c72604c) 6 0x404fcb20 (WaitForMultipleObjectsEx+0x1d5(count=0x1, handles=0x4c7261ac, wait_all=0x0, timeout=0x4e20, alertable=0x0) [sync.c:167] in KERNEL32.DLL) (ebp=4c726184) 7 0x404fc8b8 (WaitForSingleObject+0x3c(handle=0x200, timeout=0x4e20) [sync.c:95] in KERNEL32.DLL) (ebp=4c7261a4) 8 0x0101dc93 (pi.exe..text+0x1cc93 in pi.exe) (ebp=4c726240) 9 0x006f0072 (pe_load+0x5d8072 in wine-kthread) (ebp=0050005c) *** Invalid address 0x0050005c (pe_load+0x3e805c in wine-kthread) Wine-dbg>bt 0xb Backtrace: =>0 0x4010e8ab (NTDLL.DLL._memccpy+0x5202b in libc.so.6) (ebp=4092ec60) 1 0x401f4002 (NTDLL_wait_for_multiple_objects+0xbf(count=0x0, handles=0x0, flags=0x8, timeout=0x4092ed10) [sync.c:578] in NTDLL.DLL) (ebp=4092ecf8) 2 0x401f1edd (usr1_handler+0x4e(__signal=0xa, __context=0x4f) [signal_i386.c:1123] in NTDLL.DLL) (ebp=4092ed1c) 3 0x4006e498 (NTDLL.DLL.toupper+0x6208 in libc.so.6) (ebp=42ae2900) 4 0x401f4002 (NTDLL_wait_for_multiple_objects+0xbf(count=0x1, handles=0x42ae29ec, flags=0xc, timeout=0x42ae2a20) [sync.c:578] in NTDLL.DLL) (ebp=42ae2998) 5 0x401f40ae (NTDLL.DLL.NtWaitForMultipleObjects+0x74 in NTDLL.DLL) (ebp=42ae29c0) 6 0x401f40fe (NtWaitForSingleObject+0x42(handle=0x1a4, alertable=0x0, timeout=0x42ae2a20) [sync.c:611] in NTDLL.DLL) (ebp=42ae29e4) 7 0x401cda35 (RtlpWaitForCriticalSection+0x127(crit=0x4020fc60) [critsection.c:193] in NTDLL.DLL) (ebp=42ae2a84) 8 0x401cdc25 (RtlEnterCriticalSection+0x51(crit=0x4020fc60) [critsection.c:255] in NTDLL.DLL) (ebp=42ae2a9c) 9 0x401d92dc (LdrLockLoaderLock+0x92(flags=0x0, result=0x0, magic=0x42ae2d08) [loader.c:926] in NTDLL.DLL) (ebp=42ae2acc) 10 0x404dd58f (GetModuleFileNameW+0x38(hModule=0x0, lpFileName=0x436e0dd8, size=0x104) [module.c:482] in KERNEL32.DLL) (ebp=42ae2d10) 11 0x404dd4d7 (GetModuleFileNameA+0x72(hModule=0x0, lpFileName=0x42ae36e8, size=0x104) [module.c:465] in KERNEL32.DLL) (ebp=42ae2d44) 12 0x0101db7e (pi.exe..text+0x1cb7e in pi.exe) (ebp=42ae2de4) Wine-dbg>bt 0x9 Backtrace: =>0 0x4010e8ab (NTDLL.DLL._memccpy+0x5202b in libc.so.6) (ebp=40032c60) 1 0x401f4002 (NTDLL_wait_for_multiple_objects+0xbf(count=0x0, handles=0x0, flags=0x8, timeout=0x40032d10) [sync.c:578] in NTDLL.DLL) (ebp=40032cf8) 2 0x401f1edd (usr1_handler+0x4e(__signal=0xa, __context=0x4f) [signal_i386.c:1123] in NTDLL.DLL) (ebp=40032d1c) 3 0x4006e498 (NTDLL.DLL.toupper+0x6208 in libc.so.6) (ebp=4076d78c) 4 0x401f4002 (NTDLL_wait_for_multiple_objects+0xbf(count=0x1, handles=0x4076d878, flags=0xc, timeout=0x4076d8ac) [sync.c:578] in NTDLL.DLL) (ebp=4076d824) 5 0x401f40ae (NTDLL.DLL.NtWaitForMultipleObjects+0x74 in NTDLL.DLL) (ebp=4076d84c) 6 0x401f40fe (NtWaitForSingleObject+0x42(handle=0x1a4, alertable=0x0, timeout=0x4076d8ac) [sync.c:611] in NTDLL.DLL) (ebp=4076d870) 7 0x401cda35 (RtlpWaitForCriticalSection+0x127(crit=0x4020fc60) [critsection.c:193] in NTDLL.DLL) (ebp=4076d910) 8 0x401cdc25 (RtlEnterCriticalSection+0x51(crit=0x4020fc60) [critsection.c:255] in NTDLL.DLL) (ebp=4076d928) 9 0x401d92dc (LdrLockLoaderLock+0x92(flags=0x0, result=0x0, magic=0x4076db94) [loader.c:926] in NTDLL.DLL) (ebp=4076d958) 10 0x404dd58f (GetModuleFileNameW+0x38(hModule=0x0, lpFileName=0x436e0bc8, size=0x104) [module.c:482] in KERNEL32.DLL) (ebp=4076db9c) 11 0x404dd4d7 (GetModuleFileNameA+0x72(hModule=0x0, lpFileName=0x4076e574, size=0x104) [module.c:465] in KERNEL32.DLL) (ebp=4076dbd0) 12 0x0101db7e (pi.exe..text+0x1cb7e in pi.exe) (ebp=4076dc70)
This one doesn't look like strictly deadlock in Wine. In thread 0x16 it appears the application called "WaitForSingleObject" directly. I wonder what object that may be, however, and how come we are blocking on it on called to "GetModuleFileNameA".
This is NOT the problem I was reporting before, but I figured I'll report it while wer'e here.
Thread 16 seems to be calling "WaitForSingleObject" on an event it created not long before. It does create another process between creating the event and waiting on it. I'm not sure what process, though.
I hope someone is able to glean useful information of this.
Shachar
-
Mike Hearn -
Shachar Shemesh