Hi,
I feel rather stupid, but need help understanding this. I managed to screw up winetest so that it runs into trouble. The relay trace goes like (indented by examine-relay)
-------------------------------------------------------------------- 000a:Call comctl32.InitCommonControls() ret=40593c29 000a:Ret comctl32.InitCommonControls() retval=40def6d4 ret=40593c29 000a:Call kernel32.GetModuleHandleA(00000000) ret=40593c3c 000a:Ret kernel32.GetModuleHandleA() retval=40540000 ret=40593c3c 000a:Call user32.CreateDialogParamA(40540000,00000064,00000000,40593b4c,00000000) ret=40593c42 000a:Call kernel32.FindResourceA(40540000,00000064,00000005) ret=407aa47f 000a:Ret kernel32.FindResourceA() retval=405954f8 ret=407aa47f 000a:Call kernel32.LoadResource(40540000,405954f8) ret=407aa48a 000a:Ret kernel32.LoadResource() retval=40590d20 ret=407aa48a 000a:Call kernel32._EnterSysLevel(40810b00) ret=407c21b8 000a:Ret kernel32._EnterSysLevel() retval=00000008 ret=407c21b8 000a:Call kernel32._LeaveSysLevel(40810b00) ret=407c21dc 000a:Ret kernel32._LeaveSysLevel() retval=00000000 ret=407c21dc 000a:Call kernel32._EnterSysLevel(40810b00) ret=407c21b8 000a:Ret kernel32._EnterSysLevel() retval=00000008 ret=407c21b8 000a:Call kernel32._EnterSysLevel(40810b00) ret=407c21b8 000a:Ret kernel32._EnterSysLevel() retval=00000008 ret=407c21b8 000a:Call kernel32._LeaveSysLevel(40810b00) ret=407c21dc 000a:Ret kernel32._LeaveSysLevel() retval=00000000 ret=407c21dc 000a:Call ntdll.RtlAllocateHeap(40300000,00000000,0000001c) ret=407a6047 000a:Ret ntdll.RtlAllocateHeap() retval=40347998 ret=407a6047 000a:Call gdi32.CreateDCA(407f0e04 "DISPLAY",00000000,00000000,00000000) ret=407a6066 000a:Call ntdll.RtlCreateUnicodeStringFromAsciiz(40def3e8,407f0e04 "DISPLAY") ret=408994dd 000a:Ret ntdll.RtlCreateUnicodeStringFromAsciiz() retval=00000001 ret=408994dd 000a:Call kernel32._CheckNotSysLevel(408cf320) ret=408a56e8 000a:Ret kernel32._CheckNotSysLevel() retval=0000000a ret=408a56e8 000a:Call ntdll.RtlEnterCriticalSection(408cf400) ret=408ae109 000a:Ret ntdll.RtlEnterCriticalSection() retval=00000000 ret=408ae109 000a:Call ntdll.RtlLeaveCriticalSection(408cf400) ret=408ae1d9 000a:Ret ntdll.RtlLeaveCriticalSection() retval=00000000 ret=408ae1d9 000a:Call kernel32._EnterSysLevel(408cf320) ret=408a50cf 000a:Ret kernel32._EnterSysLevel() retval=0000000c ret=408a50cf 000a:Call ntdll.RtlAllocateHeap(40300000,00000000,00000138) ret=408a5215 000a:Ret ntdll.RtlAllocateHeap() retval=403479c0 ret=408a5215 000a:Call x11drv.CreateDC(403479c0,403479d8,40def15c L"DISPLAY",00000000,00000000,00000000) ret=40899405 000a:Call ntdll.RtlAllocateHeap(40300000,00000008,0000008c) ret=409ee0de 000a:Ret ntdll.RtlAllocateHeap() retval=40347b00 ret=409ee0de 000a:Call gdi32.GetObjectType(0000007c) ret=409ee125 000a:Call kernel32._EnterSysLevel(408cf320) ret=408a5527 000a:Ret kernel32._EnterSysLevel() retval=0000000c ret=408a5527 000a:Call kernel32._LeaveSysLevel(408cf320) ret=408a56c3 000a:Ret kernel32._LeaveSysLevel() retval=00000000 ret=408a56c3 000a:Ret gdi32.GetObjectType() retval=00000003 ret=409ee125 000a:Call ntdll.RtlEnterCriticalSection(40a20700) ret=409fe8b0 000a:Ret ntdll.RtlEnterCriticalSection() retval=00000000 ret=409fe8b0 err:ntdll:RtlpWaitForCriticalSection section 0x40334040 "?" wait timed out in thread 000a, blocked by 0009, retrying (60 sec) --------------------------------------------------------------------
which I don't understand given the definition
-------------------------------------------------------------------- HWND WINAPI CreateDialogParamA( HINSTANCE hInst, LPCSTR name, HWND owner, DLGPROC dlgProc, LPARAM param ) { HRSRC hrsrc; LPCDLGTEMPLATEA ptr;
if (!(hrsrc = FindResourceA( hInst, name, (LPSTR)RT_DIALOG ))) return 0; if (!(ptr = (LPCDLGTEMPLATEA)LoadResource(hInst, hrsrc))) return 0; return CreateDialogIndirectParamA( hInst, ptr, owner, dlgProc, param ); } --------------------------------------------------------------------
After LoadResource returns, I would expect a call to CreateDialogIndirectParamA instead of the SysLevels etc. Could somebody explain this, please?
Thanks a lot, Feri.
"Ferenc" == Ferenc Wagner wferi@afavant.elte.hu writes:
... Ferenc> which I don't understand given the definition
Ferenc> ---------------------------------------------------------------- Ferenc> HWND WINAPI CreateDialogParamA( HINSTANCE hInst, LPCSTR name, Ferenc> HWND owner, DLGPROC dlgProc, LPARAM param ) { HRSRC hrsrc; Ferenc> LPCDLGTEMPLATEA ptr;
Ferenc> if (!(hrsrc = FindResourceA( hInst, name, (LPSTR)RT_DIALOG Ferenc> ))) return 0; if (!(ptr = (LPCDLGTEMPLATEA)LoadResource(hInst, Ferenc> hrsrc))) return 0; return CreateDialogIndirectParamA( hInst, Ferenc> ptr, owner, dlgProc, param ); } Ferenc> ----------------------------------------------------------------
Ferenc> After LoadResource returns, I would expect a call to Ferenc> CreateDialogIndirectParamA instead of the SysLevels etc. Could Ferenc> somebody explain this, please?
Intra DLL calls are not looged by relay debugging. So you don't see the CreateDialogIndirectParamA call in a relay log. Maybe +dialog may help. Otherwise instrument the calls with more messages.
Bye
Relay only shows you when a DLL boundary is crossed (ie. an inter DLL call), not when a DLL calls a function internal to itself.
Mike
Ferenc Wagner wrote:
After LoadResource returns, I would expect a call to CreateDialogIndirectParamA instead of the SysLevels etc. Could somebody explain this, please?
Thanks a lot, Feri.
Mike, Uwe, thanks for the quick reply! Now I got to the end of X11DRV_CreateDC (TRACEs added by me):
wine_tsx11_lock(); TRACE("physDev=%p\n", physDev); physDev->gc = XCreateGC( gdi_display, physDev->drawable, 0, NULL ); TRACE("XCreateGC returned %p\n", physDev->gc); XSetGraphicsExposures( gdi_display, physDev->gc, False ); XSetSubwindowMode( gdi_display, physDev->gc, IncludeInferiors ); XFlush( gdi_display ); wine_tsx11_unlock();
and --debugmsg +winetest,+dialog,+dc,+x11drv,+relay shows
trace:dc:CreateDCW (driver=L"DISPLAY", device=(null), output=(null)): returning 0x7c 000a:Call x11drv.CreateDC(40347978,40347990,40def154 L"DISPLAY",00000000,00000000,00000000) ret=40899405 000a:Call ntdll.RtlAllocateHeap(40300000,00000008,0000008c) ret=409ee0e1 000a:Ret ntdll.RtlAllocateHeap() retval=40347ab8 ret=409ee0e1 000a:Call gdi32.GetObjectType(0000007c) ret=409ee125 000a:Call kernel32._EnterSysLevel(408cf340) ret=408a5547 000a:Ret kernel32._EnterSysLevel() retval=0000000c ret=408a5547 000a:Call kernel32._LeaveSysLevel(408cf340) ret=408a56e3 000a:Ret kernel32._LeaveSysLevel() retval=00000000 ret=408a56e3 000a:Ret gdi32.GetObjectType() retval=00000003 ret=409ee125 000a:Call ntdll.RtlEnterCriticalSection(40a20700) ret=409fe910 000a:Ret ntdll.RtlEnterCriticalSection() retval=00000000 ret=409fe910 trace:x11drv:X11DRV_CreateDC physDev=0x40347ab8 0009:Ret kernel32.CreateThread() retval=00000040 ret=40593e07 trace:winetest:report thread 0x40 created 0009:Call kernel32.WaitForSingleObject(0000003c,ffffffff) ret=40593e4c [5 seconds of pause here] err:ntdll:RtlpWaitForCriticalSection section 0x40333ff8 "?" wait timed out in thread 000a, blocked by 0009, retrying (60 sec)
I am going to bed now, but can somebody advice me where to look further? To provide some context, the app goes like:
DWORD WINAPI DlgThreadProc () { InitCommonControls (); dialog = CreateDialog (GetModuleHandle (NULL), MAKEINTRESOURCE (IDD_STATUS), NULL, DlgProc);
[thread 000a is executing this CrateDialog call above] [...] }
[and here is the main thread (0009)]
DlgThread = CreateThread (NULL, 0, DlgThreadProc, NULL, 0, &DlgThreadID); WINE_TRACE ("thread %p created\n", DlgThread); ret = WaitForSingleObject (initEvent, INFINITE);
This multithread business is rather new for me, I would be grateful for any insights. The cross-compiled version runs on XP all right.
Feri.
On January 7, 2004 09:19 pm, Ferenc Wagner wrote:
This multithread business is rather new for me, I would be grateful for any insights. The cross-compiled version runs on XP all right.
Sorry, it's almost 3:15am here, I don't have time to look into it, but why do you bother with multithread stuff? Is it really necessary?
"Dimitrie O. Paun" dpaun@rogers.com writes:
On January 7, 2004 09:19 pm, Ferenc Wagner wrote: [...] Sorry, it's almost 3:15am here,
Not 9:19pm? We seem to be in sync then! From my post:
Date: Thu, 08 Jan 2004 03:19:56 +0100
why do you bother with multithread stuff? Is it really necessary?
I would be glad to drop it, but how can I keep serving messages while running the tests? Sorry for being dumb.
Feri.
On January 8, 2004 06:49 am, Ferenc Wagner wrote:
I would be glad to drop it, but how can I keep serving messages while running the tests? Sorry for being dumb.
I haven't looked at the source lately, but aren't you running the programs in a different process? If so, why are they blocking winetest?
"Dimitrie O. Paun" dpaun@rogers.com writes:
On January 8, 2004 06:49 am, Ferenc Wagner wrote:
I would be glad to drop it, but how can I keep serving messages while running the tests? Sorry for being dumb.
I haven't looked at the source lately, but aren't you running the programs in a different process? If so, why are they blocking winetest?
I wanted to make the gui as unintrusive as I could. This means that the original program stayed intact apart from the status reporting functions inserted here and there which send messages to the gui. The only synchronization I need is not starting the tests until the gui is created, which is achieved by an Event object. The picture could be changed of course (it is somewhat inside-out now), but that would require splitting up the original code into separate callbacks. Not something I'm particularly fond of. The present code is still a little bit verbose, I could use DialogBox instead of CreateDialog and an explicit message loop, which are relics of the hard beginnings.
Or maybe all the above is the result of my misconceptions. Please correct me if it sounds silly; winetest is my first Windows program, after all...
Feri.
On Thu, 8 Jan 2004, Ferenc Wagner wrote:
Or maybe all the above is the result of my misconceptions. Please correct me if it sounds silly; winetest is my first Windows program, after all...
Feri, I haven't had a chance to look at the code. All I know is that it's better to not mix GUI stuff with threads, especially when it's not necessary. I prefer to keep things simple, this way more people can participate. But of course, I comment without even seeing the code, so please take this with a huge grain of salt.
"Ferenc" == Ferenc Wagner wferi@afavant.elte.hu writes:
... Ferenc> kernel32.WaitForSingleObject(0000003c,ffffffff) ret=40593e4c [5 Somewhere before an CreateEvent Call with a return value of 0000003c must happen. Look at that event and why it doesn't trigger.
Bye
Uwe Bonnes bon@elektron.ikp.physik.tu-darmstadt.de writes:
"Ferenc" == Ferenc Wagner wferi@afavant.elte.hu writes:
... Ferenc> kernel32.WaitForSingleObject(0000003c,ffffffff) ret=40593e4c [5
Somewhere before an CreateEvent Call with a return value of 0000003c must happen. Look at that event and why it doesn't trigger.
You are right, there is. I create the event before forking off the dialog thread, which calls CreateDialog then SetEvent, which I didn't show you in the source snippets, only the Wait which you quoted. But I think it was not this Wait which timed out, but the tsx11_lock in CreateDialog. For me it seems XCreateDC does not return (the one I quoted from the Wine source). I mean, sometimes. Because the same program works now... I did not even recompile it, honest. I am going mad. Yesterday night it was 100% reproducible. Instead of this:
000a:Ret gdi32.GetObjectType() retval=00000003 ret=409ee125 000a:Call ntdll.RtlEnterCriticalSection(40a20700) ret=409fe8b0 000a:Ret ntdll.RtlEnterCriticalSection() retval=00000000 ret=409fe8b0 trace:x11drv:X11DRV_CreateDC physDev=[I lost the number] err:ntdll:RtlpWaitForCriticalSection section 0x40334040 "?" wait timed out in thread 000a, blocked by 0009, retrying (60 sec)
now I get
000a:Ret gdi32.GetObjectType() retval=00000003 ret=409ee125 000a:Call ntdll.RtlEnterCriticalSection(40a20700) ret=409fe910 000a:Ret ntdll.RtlEnterCriticalSection() retval=00000000 ret=409fe910 trace:x11drv:X11DRV_CreateDC physDev=0x40347ab8 trace:x11drv:X11DRV_CreateDC XCreateGC returned 0x101322a8 000a:Call ntdll.RtlLeaveCriticalSection(40a20700) ret=409fe934 000a:Ret ntdll.RtlLeaveCriticalSection() retval=00000000 ret=409fe934 000a:Ret x11drv.CreateDC() retval=00000001 ret=40899405
I've got the impression, that my network connection (remote X) is slower now, but not sure... Will see if it break again.
Feri.
Ferenc Wagner wferi@afavant.elte.hu writes:
For me it seems XCreateDC does not return (the one I quoted from the Wine source). I mean, sometimes. Because the same program works now... I did not even recompile it, honest. I am going mad. Yesterday night it was 100% reproducible.
Making progress. The thing does not depend on time or weather, but instead on the terminal I'm using. Different X extensions, color depth, whatever. On --debugmsg +all logs
$ diff -u run_head.log lock_async.log [...] +0009:trace:opengl:X11DRV_OpenGL_Init GLX is up and running error_base = 77 [...] -0009:trace:x11settings:X11DRV_Settings_AddOneMode initialized mode 0: 1024x768x16 @0 Hz (NoRes) +0009:trace:x11settings:X11DRV_Settings_AddOneMode initialized mode 0: 1024x768x32 @0 Hz (NoRes) [...] +0009:trace:xrender:X11DRV_XRender_Init Xrender is up and running error_base = 179 [...] -0009:trace:xrender:X11DRV_XRender_Init Xrender is not available on your XServer, client side rendering with the core protocol instead. [...] -0009:Ret x11drv.GetDeviceCaps() retval=00000010 ret=40899a22 +0009:Ret x11drv.GetDeviceCaps() retval=00000018 ret=40899a22 [...] -0009:trace:x11drv:X11DRV_CreateBitmap (0x68) 36x18 16 bpp +0009:trace:x11drv:X11DRV_CreateBitmap (0x68) 36x18 24 bpp [...]
Does it ring the bell for anybody? It's getting far too deep for me... The whole logs are available at http://afavant.elte.hu/~wferi/wine/%7Brun_head,lock_async%7D.log
Feri.
Ferenc Wagner wferi@afavant.elte.hu writes:
Making progress. The thing does not depend on time or weather, but instead on the terminal I'm using. Different X extensions, color depth, whatever. On --debugmsg +all logs
Probably yet another Xlib locking bug, try commenting out the XInitThreads call in x11drv_main.c to see if it makes a difference. What X version are you running?
Alexandre Julliard julliard@winehq.org writes:
Ferenc Wagner wferi@afavant.elte.hu writes:
Making progress. The thing does not depend on time or weather, but instead on the terminal I'm using. Different X extensions, color depth, whatever. On --debugmsg +all logs
Probably yet another Xlib locking bug, try commenting out the XInitThreads call in x11drv_main.c to see if it makes a difference.
Yes, it does, the programs runs normally with that line commented out.
What X version are you running?
XFree86 4.2.0. Tell me if you are interested in further logs or whatever. I will probably submit this code now that I know the error is elsewhere. Btw, is something wrong with my LoadStringA tests? They pass here...
Feri.
Ferenc Wagner wferi@afavant.elte.hu writes:
XFree86 4.2.0. Tell me if you are interested in further logs or whatever.
OK, there's a known locking problem in Xrender in Xfree 4.2, so that's why (in fact there are many Xrender bugs in that version, you may want to upgrade).
Anyway, we'll probably have to get rid of XInitThreads for now, and leave Linux threading a few more years to catch up. After all Windows has only had working threads for what, 10 years now. Sigh...
Btw, is something wrong with my LoadStringA tests? They pass here...
No, it just got drowned out by other patches. I'll move it back up in the queue.
Alexandre Julliard julliard@winehq.org writes:
OK, there's a known locking problem in Xrender in Xfree 4.2, so that's why (in fact there are many Xrender bugs in that version, you may want to upgrade).
The terminals aren't mine, and as you may already know I'm using 4.1, which is flawless, so I'm safe.
Anyway, we'll probably have to get rid of XInitThreads for now, and leave Linux threading a few more years to catch up. After all Windows has only had working threads for what, 10 years now. Sigh...
Smelling some sarcasm here... right?
Btw, is something wrong with my LoadStringA tests?
I'll move it back up in the queue.
Thanks, I've seen the commit.
Feri. :)
Khm. Now I've got
X Error of failed request: BadWindow (invalid Window parameter) Major opcode of failed request: 15 (X_QueryTree) Resource id in failed request: 0x4003ac Serial number of failed request: 258 Current serial number in output stream: 258 err:ntdll:RtlpWaitForCriticalSection section 0x40ac0700 "../../../src/dlls/x11drv/x11drv_main.c: X11DRV_CritSection" wait timed out in thread 000a, blocked by 0009, retrying (60 sec) wine: Unhandled exception (thread 000a), starting debugger... err:win32:_EnterSysLevel (0x408b0b00, level 2): Holding 0x4096f340, level 3. Expect deadlock! err:win32:_EnterSysLevel (0x408b0b00, level 2): Holding 0x4096f340, level 3. Expect deadlock! err:win32:_EnterSysLevel (0x408b0b00, level 2): Holding 0x4096f340, level 3. Expect deadlock! err:win32:_EnterSysLevel (0x408b0b00, level 2): Holding 0x4096f340, level 3. Expect deadlock! err:win32:_EnterSysLevel (0x408b0b00, level 2): Holding 0x4096f340, level 3. Expect deadlock! err:ntdll:RtlpWaitForCriticalSection section 0x40ac0700 "../../../src/dlls/x11drv/x11drv_main.c: X11DRV_CritSection" wait timed out in thread 000a, blocked by 0009, retrying (60 sec) err:seh:EXC_DefaultHandling Unhandled exception code c0000194 flags 0 addr 0x401a56e0
But I can't reproduce it.
Feri.
Ferenc Wagner wferi@afavant.elte.hu writes:
Alexandre Julliard julliard@winehq.org writes:
What X version are you running?
XFree86 4.2.0.
This is the server version on the terminal. Wine is linked with xlibs_4.1.0-16woody1.
"Ferenc" == Ferenc Wagner wferi@afavant.elte.hu writes:
Ferenc> Ferenc Wagner wferi@afavant.elte.hu writes: >> Alexandre Julliard julliard@winehq.org writes: >> >>> What X version are you running? >> XFree86 4.2.0.
Ferenc> This is the server version on the terminal. Wine is linked with Ferenc> xlibs_4.1.0-16woody1.
Ouch! That sounds like reporting a bug win wine-1999xxxx ...
Bye
Ferenc Wagner wrote:
Hi,
I feel rather stupid, but need help understanding this. I managed to screw up winetest so that it runs into trouble. The relay trace goes like (indented by examine-relay)
I don't understand why it crashes... if it is any help here is a very simple program with two threads:
http://vmlinux.org/jakov/uptime/ http://vmlinux.org/jakov/uptime/uptime.cpp http://vmlinux.org/jakov/uptime.zip
Jakobi