Regression problems in app - help with debugging?
Dr J A Gow
J.A.Gow at furrybubble.co.uk
Sun Jan 29 13:52:15 CST 2006
Hello All,
I have some regression problems relating to Wine in a commercial ECAD
app 'Easy-PC' version 9.0, available from http://www.numberone.com
The application was quite usable on Crossover Office 4.2, with just some
minor dialog corruption. Alpha versions of Wine available at the same
time (can not exactly remember which ones) could also run it
successfully. However, under the latest Wine 0.9.6, Wine CVS and CXO
5.0.1 it does not work. Note that it does not crash, it errors out
cleanly with a dialog box message.
I have been debugging the problems in this app for some time now. It is
a critical app for me as I use it in a production environment, but I do
not want to pay Microsoft for the privilege of exposing my machine to
malware. I am thus prepared to help debug Wine to get this application
running. However, my Windows programming experience is limited to device
drivers, not apps (although fluent C/C++ systems programming on other
platforms), I have hit a brick wall, possibly due to my limited
knowledge of how the Windows API works and I will need some help with this.
If anyone would like to help me debug this app (hope springs eternal!),
a demo version of the app is available free of charge from the web site
address above, and this version exhibits the same problems as the full
version.
Background
-------------
The system: Dual physical processor (not dual core) Opteron running SuSE
10.0 x86_64 SMP.
Wine: Latest 0.9.6 release, up to CVS grabbed a week or so ago.
The application installs OK and when run, puts up a GUI as expected.
However, when you try to create a new PCB or schematic, an error dialog
box is displayed indicating that the app can not read the technology
file Default.stf (schematic) or Default.ptf (pcb). This is _not_ a
permissions problem, all files are actually present and the same install
will work under CXO 4.2.
I generated and analyzed several hundred MB of logfiles over many days,
added extra debug statements to the Wine code and analyzed the
application's operation. The problem actually appears to have two
causes, and this is what I have come up with so far.
Problem 1
-----------
Application calls StgOpenStorage with a grfMode flag of 0x10020
(STGM_TRANSACTED | STGM_SHARE_DENY_WRITE). Immediately afterwards it
calls StorageBaseImpl_OpenStream with a grfMode of 0x12
(STGM_SHARE_EXCLUSIVE | STGM_READWRITE). This second call fails with an
access denied error code, after which the logs show an easily traced
error handling sequence leading to display of the error dialog mentioned
above:
0009:Call ole32.StgOpenStorage(59693db0 L"c:\\Program Files\\Number One Systems\\Easy-PC\\Technology\\Default.ptf",00000000,00010020,00000000,00000000,5821f850) ret=1022e7f0
...
...
trace:storage:StgOpenStorage <-- 00000000, IStorage 0x5b3465f8
0009:Ret ole32.StgOpenStorage() retval=00000000 ret=1022e7f0
...
...
trace:storage:StorageBaseImpl_OpenStream (0x5b3465f8, L"\0005FileType", (nil), 12, 0, 0x5821f848)
fixme:storage:StorageBaseImpl_OpenStream STORAGE ACCESS DENIED - parent 0, this 2
Note that the last fixme is one I added to find out exactly what was
going on here. Now, logic would dictate that the grfMode of the
OpenStream method call is indeed incompatible with that of its parent
storage object. However, I would have thought that the application
coders would most likely have hard-coded the grfMode flags in the
application. If so, it would seem that the app is buggy, yet this
application works on Windows! Either the app is buggy and the Win32
OLE32 implementation behaves differently, or I am missing something here.
Ok, so with no obvious solution to this problem, I decided to bypass it.
I modified the storage32.c implementation in the following way to bypass
the grfMode check:
parent_grfMode = STGM_ACCESS_MODE( This->ancestorStorage->base.openFlags );
*if* ( STGM_ACCESS_MODE( grfMode ) > STGM_ACCESS_MODE( parent_grfMode ) )
{
FIXME("StorageBase_OpenStream called with grfMode mismatch - parent %d, this %d\n",
parent_grfMode,STGM_ACCESS_MODE(grfMode));
///res = STG_E_ACCESSDENIED;/
///goto end;/
}
Obviously not a viable fix, but a hack to get it working. After
implementing this, the OpenStream call succeeded, as did subsequent
stream access. However, the app _still_ errored out in exactly the same
manner and at the same time. After more log searching, this led to the
discovery of the second problem.
Problem 2
-----------
During its loading and setup, the application repeatedly calls
StgOpenStorage on the .stf/.ptf files in question, calls OpenStream,
reads from the stream, and then finally closes the storage. I placed
tell-tales in useful locations in the file open/close handlers in the
wineserver, and could clearly see the files being opened and
subsequently closed. This open/read/close occurs correctly and in
sequence up to a certain point. At this point in the execution, the app
calls StgOpenStorage on the technology file, with the following call. It
is opened correctly, with grfMode of STGM_TRANSACTED |
STGM_SHARED_DENY_WRITE | STGM_READWRITE:
0009:Call ole32.StgOpenStorage(5821f754 L"c:\\Program Files\\Number One Systems\\Easy-PC\\Technology\\Default.ptf",00000000,00010022,00000000,00000000,5821f7f4) ret=7c17eabc
trace:storage:StgOpenStorage (L"c:\\Program Files\\Number One Systems\\Easy-PC\\Technology\\Default.ptf", (nil), 10022, (nil), 0, 0x5821f7f4)
...
...
...
trace:storage:StorageBaseImpl_AddRef (0x5b3465f8) AddRef to 1
trace:storage:StgOpenStorage <-- 00000000, IStorage 0x5b3465f8
0009:Ret ole32.StgOpenStorage() retval=00000000 ret=7c17eabc
Almost immediately, the app opens three streams in this object and
starts to access them, all successfully. There follows a whole slew of
logging statements, all of which appear sensible However, what is
strange about this access is that soon we seem to be frantically
increasing the storage object's reference pointer. This sequence appears
frequently in the code, closely spaced but interspersed with what seems
quite logical and successful calls to seek functions and memory
allocation functions:
0009:Call ntdll.RtlAllocateHeap(55890000,00000000,00000030) ret=584e498b
0009:Ret ntdll.RtlAllocateHeap() retval=55926480 ret=584e498b
trace:storage:StorageBaseImpl_AddRef (0x5b3465f8) AddRef to 9
trace:storage:StorageImpl_ReadProperty storage name: L"\0005SummaryInformation"
0009:Call ntdll.RtlAllocateHeap(55890000,00000000,00000008) ret=584e7ab3
0009:Ret ntdll.RtlAllocateHeap() retval=5594d108 ret=584e7ab3
The storage object's reference pointer is so incremented up to 19:
0009:Call ntdll.RtlAllocateHeap(55890000,00000000,00000030) ret=584e498b
0009:Ret ntdll.RtlAllocateHeap() retval=559250f8 ret=584e498b
trace:storage:StorageBaseImpl_AddRef (0x5b3465f8) AddRef to 19
trace:storage:StorageImpl_ReadProperty storage name: L"\0005SummaryInformation"
0009:Call ntdll.RtlAllocateHeap(55890000,00000000,00000008) ret=584e7ab3
0009:Ret ntdll.RtlAllocateHeap() retval=55925130 ret=584e7ab3
Finally, the code executes a
trace:storage:StgStreamImpl_Destroy (0x5b34b7e0)
trace:storage:StorageBaseImpl_Release (0x5b3465f8) ReleaseRef to 18
There follows a lot more log file, mostly concerned with set up and so
on. What I am highligting here is that between this point, and the point
of actual failure which I am going to describe shortly, there appears to
be no attempt to close the Default.ptf file, unlike the attempts further
up the logs closer to program start. I am wondering about this: is the
reference counter being incorrectly incremented here, preventing the
'Release' function from destroying the storage object and thus closing
the file? I am not sufficiently familiar with the COM storage object
stuff in Windows to know what _should_ happen here. Anyway. I will now
describe the point of failure.
Further down the log, there are several more successful opens/closes of
the technology file, with the correct mode flags. Then, finally, the app
tries to re-open the technology file with a grfMode of STGM_TRANSACTED
| STGM_SHARE_DENY_WRITE. This call fails with a sharing violation
(remember it had been left open from the previous call)
0009:Call ole32.StgOpenStorage(5971bec8 L"c:\\Program Files\\Number One Systems\\Easy-PC\\Technology\\Default.stf",00000000,00010020,00000000,00000000,5821e69c) ret=1022e7f0
....
....
0009:Ret kernel32.CreateFileW() retval=ffffffff ret=584edc8b
trace:storage:StgOpenStorage <-- 80030020, IStorage (nil)
There then follows the same error handling sequence leading to display
of the dialog.
I then thought about a simple test. I overrode the sharing mode
detection in fd.c/check_sharing() in the wineserver (again, not a real
solution). Note there are some minor differences in the code - I used a
return code so I could easily check it:
/// if ((access & FILE_UNIX_READ_ACCESS) && !(existing_sharing & FILE_SHARE_READ))/
/// rc=0;/
/// if ((access & FILE_UNIX_WRITE_ACCESS) && !(existing_sharing & FILE_SHARE_WRITE))/
/// rc=0;/
/// if ((existing_access & FILE_UNIX_READ_ACCESS) && !(sharing & FILE_SHARE_READ)) rc=0;/
/// if ((existing_access & FILE_UNIX_WRITE_ACCESS) && !(sharing & FILE_SHARE_WRITE)) rc=0;/
*if* (fd->closed->unlink[0] && !(existing_sharing & FILE_SHARE_DELETE)) rc=0;
*if* (unlink && !(sharing & FILE_SHARE_DELETE)) rc=0;
*if*(rc==0) {
fprintf(stderr,"FILEDESC - sharing mode invalid\n");
rc=1;
}
*return* rc;
and the application worked! Not only worked, but worked perfectly! The
minor dialog corruption of previous versions had completely gone! I
would like to thank the hard working people who have been working to
correct problems in Wine, and in doing so had fixed this minor dialog
problem. The only issue of note then is that the top-right hand buttons
of a maximized MDI child window do not appear until you resize the
frame. This is a minor issue though, and not of importance here.
However, what I did does not represent a real solution - I just hacked
around the problem, which itself seems subtle in nature. I looked
closely at the Microsoft documentation and the logic in check_sharing(),
even writing a program in Windows to check that at the CreateFile level
that the sharing logic in Wine is correct. It seems to be.
I am now stumped, I would really like to get this app working properly
under Wine, without bad hacks. I would appreciate any guidance from
those more experienced with the user-land Windows API. If you got this
far, many thanks for taking the time to read this long message. I have
provided only small excerpts from logs, but I can provide other parts of
the files on request if necessary.
John.
More information about the wine-devel
mailing list