Need help interpreting debug log for Wine hard loop

[Sean Millichamp]

I hope this isn't too off-topic for the wine-devel list but I asked for
debugging help on wine-users a couple of days ago and got no reply so
maybe that isn't the right place to ask about debugging help?  I bought
and use Codeweaver's Crossover product to drive Office and have fiddled
with Wine briefly on and off over the years but other then that I am
mostly a Wine newbie.

I am trying to make an old Windows 3.1 application work and it appears
to be causing Wine to go into a hard loop while loading.  For what it's
worth, this application is called "Travex" and is used in the health
care industry.  I think it uses the Win 3.1 era Borland GUI toolkit in
case it matters.

I followed the directions on the website for debugging and have a
--debugmsg warn+all +loaddll output that I only can vaguely interpret.

Wine enters the hard loop somewhere following the debug log.  I tried
debug logs at various other levels including a relay log/trace (though I
have no idea what it is) and +all and under those levels the same output
keeps getting outputted to the log as Wine loops.

I am not a Windows developer although I have done a little with C under
Linux.  Is there anyone who could help me figure out what is going
wrong?  I'd be happy to make the logs available for http or send them in
email.  Unfortunately, I can't provide the application itself due to
licensing issues (it's a commercial package).

I have tested it with Wine from RH 7.3, Wine from 10/01 CVS, and
Codeweavers Crossover Office 1.0 (just for kicks).  All three exhibit
the same behavior.  I tried the Wine from 10/01 in both Win98 and Win31
behavior mode.  No change.

The application runs just fine in Windows 98.  I installed it in my
fake_windows in Wine and have tried running it from there as well as my
real Windows partition.  No change.

Any help would be greatly appreciated.  Thanks in advance.

Sean

[Miguel Feitosa]

Hi Sean,

I recently tried to get a Borland Gui win3.1 app to run
without success.

Actually, all apps of this type that I tried failed when
initializing with problems relative to GUI construction.

try
wine --debugmsg +relay

and see if you have [like I did] a situation where

1) A new window call was succesffully executed, a handle was assigned

2) A call that does something with the window gets executed and fails
with an invalid window handle exception.

This was repeated in all the apps I tried.

Something between 1 and 2 was corrupting the windows.
The window did start rendering though.

Sorry not to be specific , the wine history pages may
have some of the emails I sent at the time [march-02].

Send me some logs and I will try to remember if they
have the same problem that I had..

Miguel Feitosa

On Thu, 2002-10-03 at 17:03, Sean Millichamp wrote:
> I hope this isn't too off-topic for the wine-devel list but I asked for
> debugging help on wine-users a couple of days ago and got no reply so
> maybe that isn't the right place to ask about debugging help?  I bought
> and use Codeweaver's Crossover product to drive Office and have fiddled
> with Wine briefly on and off over the years but other then that I am
> mostly a Wine newbie.
>
> I am trying to make an old Windows 3.1 application work and it appears
> to be causing Wine to go into a hard loop while loading.  For what it's
> worth, this application is called "Travex" and is used in the health
> care industry.  I think it uses the Win 3.1 era Borland GUI toolkit in
> case it matters.
>
> I followed the directions on the website for debugging and have a
> --debugmsg warn+all +loaddll output that I only can vaguely interpret.
>
> Wine enters the hard loop somewhere following the debug log.  I tried
> debug logs at various other levels including a relay log/trace (though I
> have no idea what it is) and +all and under those levels the same output
> keeps getting outputted to the log as Wine loops.
>
> I am not a Windows developer although I have done a little with C under
> Linux.  Is there anyone who could help me figure out what is going
> wrong?  I'd be happy to make the logs available for http or send them in
> email.  Unfortunately, I can't provide the application itself due to
> licensing issues (it's a commercial package).
>
> I have tested it with Wine from RH 7.3, Wine from 10/01 CVS, and
> Codeweavers Crossover Office 1.0 (just for kicks).  All three exhibit
> the same behavior.  I tried the Wine from 10/01 in both Win98 and Win31
> behavior mode.  No change.
>
> The application runs just fine in Windows 98.  I installed it in my
> fake_windows in Wine and have tried running it from there as well as my
> real Windows partition.  No change.
>
> Any help would be greatly appreciated.  Thanks in advance.
>
> Sean

[Sean Millichamp]

On Thu, 2002-10-03 at 16:24, Miguel Feitosa wrote:
> try
> wine --debugmsg +relay

Hi Miguel.  Thanks for you quick reply!  I just did the above and have
the results.
> and see if you have [like I did] a situation where
> -
>
> A new window call was succesffully executed, a handle was assigned
> -
>
> A call that does something with the window gets executed and fails
>
> with an invalid window handle exception.
>
> This was repeated in all the apps I tried.

I'm afraid that I don't know how to interpret what I have :(.

Here is what appears to be looping:
08ec96c8:Call USER.109: PEEKMESSAGE(0487:e792,0000,0000,0000,0001) ret=05bf:24ed ds=05d7
08ec96c8:Call x11drv.MsgWaitForMultipleObjectsEx(00000000,00000000,00000000,00000000,00000000) ret=406f5146
08ec96c8:Call kernel32.WaitForMultipleObjectsEx(00000000,00000000,00000000,00000000,00000000) ret=4090873b
08ec96c8:Ret  kernel32.WaitForMultipleObjectsEx() retval=00000102 ret=4090873b
08ec96c8:Ret  x11drv.MsgWaitForMultipleObjectsEx() retval=00000102 ret=406f5146
08ec96c8:Call kernel32._ConfirmSysLevel(40725b9c) ret=406d4c63
08ec96c8:Ret  kernel32._ConfirmSysLevel() retval=00000000 ret=406d4c63
08ec96c8:Call kernel32.GetThreadQueue16(00000000) ret=406cb82d
08ec96c8:Ret  kernel32.GetThreadQueue16() retval=000004f7 ret=406cb82d
08ec96c8:Call kernel32.GlobalLock16(000004f7) ret=406cb85e
08ec96c8:Ret  kernel32.GlobalLock16() retval=40315f00 ret=406cb85e
08ec96c8:Call kernel32.GetThreadQueue16(00000000) ret=406cb82d
08ec96c8:Ret  kernel32.GetThreadQueue16() retval=000004f7 ret=406cb82d
08ec96c8:Call kernel32.GlobalLock16(000004f7) ret=406cb85e
08ec96c8:Ret  kernel32.GlobalLock16() retval=40315f00 ret=406cb85e
08ec96c8:Call kernel32.ReleaseThunkLock(40e12a70) ret=406f51b4
08ec96c8:Ret  kernel32.ReleaseThunkLock() retval=00000000 ret=406f51b4
08ec96c8:Call kernel32.RestoreThunkLock(00000002) ret=406f51c7
08ec96c8:Ret  kernel32.RestoreThunkLock() retval=00000000 ret=406f51c7
08ec96c8:Ret  USER.109: PEEKMESSAGE() retval=0000 ret=05bf:24ed ds=05d7

This block (I don't know if I caught the start or not) appears to loop
indefinitely until I hit CTRL-C.  It generated over 60 MB of logs in
just a few seconds.  Each iteration the values above appear to be
exactly the same.
> Something between 1 and 2 was corrupting the windows.
> The window did start rendering though.

I never have seen anything appear on the screen.  The program's
installer worked just fine but the program itself has yet to draw
anything under Wine.
> Sorry not to be specific , the wine history pages may
> have some of the emails I sent at the time [march-02].

I will do some research and see what I come up with.
> Send me some logs and I will try to remember if they
> have the same problem that I had..

Well, as I said above, it's about 60 MB.  Although I'm sure I could trim
it down if I cut out everything after it began looping I still think it
would be quite large.  If you are still interested I will try to clean
it up a little, bzip it and send it your way.

Thanks very much for the help.

Sean

[Miguel Feitosa]

This is different than what I had.
My app usualy failed with calls to GDI, interwined with x11drv.
Very few messages from  the kernel...
Can you try to relay just the GDI part....
Miguel

[Alexandre Julliard]

Sean Millichamp  writes:
> Here is what appears to be looping:
> 08ec96c8:Call USER.109: PEEKMESSAGE(0487:e792,0000,0000,0000,0001) ret=05bf:24ed ds=05d7
> [...]
> 08ec96c8:Ret  USER.109: PEEKMESSAGE() retval=0000 ret=05bf:24ed ds=05d7

That's a standard PeekMessage loop. My first guess is that this is the
application main loop but for some reason the main window didn't get
displayed, so it doesn't get any messages. Look before the loop for a
failing CreateWindow or ShowWindow call.

[Miguel Feitosa]

I think my app failed after CreateWindow.
Could be SHowWindow...
Miguel

On Thu, 2002-10-03 at 19:03, Alexandre Julliard wrote:
> Sean Millichamp  writes:
> > Here is what appears to be looping:
> > 08ec96c8:Call USER.109: PEEKMESSAGE(0487:e792,0000,0000,0000,0001) ret=05bf:24ed ds=05d7
> > [...]
> > 08ec96c8:Ret  USER.109: PEEKMESSAGE() retval=0000 ret=05bf:24ed ds=05d7
>
> That's a standard PeekMessage loop. My first guess is that this is the
> application main loop but for some reason the main window didn't get
> displayed, so it doesn't get any messages. Look before the loop for a
> failing CreateWindow or ShowWindow call.
>
> -- 
> Alexandre Julliard
> [e-mail]

[Sean Millichamp]

On Thu, 2002-10-03 at 18:03, Alexandre Julliard wrote:
> Sean Millichamp  writes:
> > Here is what appears to be looping:
> > 08ec96c8:Call USER.109: PEEKMESSAGE(0487:e792,0000,0000,0000,0001) ret=05bf:24ed ds=05d7
> > [...]
> > 08ec96c8:Ret  USER.109: PEEKMESSAGE() retval=0000 ret=05bf:24ed ds=05d7
>
> That's a standard PeekMessage loop. My first guess is that this is the
> application main loop but for some reason the main window didn't get
> displayed, so it doesn't get any messages. Look before the loop for a
> failing CreateWindow or ShowWindow call.

Alexandre, thanks very much for responding.  I took a look through the
relay log again and I found only one CreateWindow call.  It returned
with a value of "1" if I am reading the log correctly.  I'm afraid I
know nothing of the Windows API so I don't know if that means success or
failure.  I have attached the section of the log around that
call/return.

The only mention of ShowWindow in the entire relay log is during a
GetProcAddress call (so it knows where the call was dynamically
loaded?).  That makes sense though since I never actually see any
drawing on the screen.  I'm presuming ShowWindow is the call that
actually displays the window after CreateWindow is done preparing it.

I also went through again and found what I believe is the start of the
USER.109 PEEKMESSAGE() loop.  The first couple of iterations are
slightly different from the others and each other.  After the third time
it just repeats the exact same calls.  I have attached that section up
to the section that just repeats as well.

Is any of this making sense?  I'm sorry that I don't know anything about
the Windows API :(.  If I did I feel like I would be able to get farther
with this on my own.

Thanks,
Sean

[Sean Millichamp]

On Fri, 2002-10-04 at 09:39, Sean Millichamp wrote:
> failure.  I have attached the section of the log around that
> call/return.

Someone was kind enough to point out to me that I forgot to attach the
logs, so here they are.

Thanks,
Sean