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.
Hello All,
I wrote this some time ago:
Dr J A Gow wrote:
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
Since then I have been doing some more digging into the problem and have come up with a test that triggers the bugs: i.e. passes on Windows and fails on Wine (latest CVS). Looking at the failure mode I feel that it has the potential to break a _lot_ of apps.
It is as I thought that there is some issue with the object destructor for the storage object being called and not actually releasing the object. I have attached the complete patch to the tests for storage32 to this message if anyone could try it I would be grateful, but I will just describe some of the reasoning behind it first.
It seems that the problem is not the grfMode with which the file is opened, but a reference counting method used within storage32. A call to the destructor of the storage object is not destroying the object - with it left open the error appears when a subsequent call to open the storage object fails with access issues because the previous one is left open. So, I introduced this test that exactly mimics the behaviour of the app. To do this, I needed a storage object that contained a stream, so I wrote code in the appropriate conformance test module to create one:
r = StgOpenStorage( filename, NULL, STGM_TRANSACTED | STGM_WRITE | STGM_SHARE_DENY_WRITE, NULL, 0, &stg); ok(r==S_OK, "StgOpenStorage failed\n"); if(stg) { static const WCHAR stmname[] = { 'w','i','n','e','t','e','s','t',0}; IStream *stm = NULL;
r = IStorage_CreateStream( stg, stmname, STGM_WRITE | STGM_SHARE_EXCLUSIVE, 0, 0, &stm ); ok(r == S_OK, "CreateStream should succeed\n");
if(stm) { r=IStorage_Commit(stg,STGC_DEFAULT); ok(r==S_OK, "StorageCommit failed\n");
}
// Windows reference counting seems different....
r = IStorage_Release(stg); ok(r == 0, "wrong ref count"); printf("- ref count = %lx\n",r);
if(r) { r = IStorage_Release(stg); ok(r == 0, "wrong ref count"); printf(" - ref count = %lx\n",r); }
}
It was here where I got the surprise! I expected this code to work on both Wine and Windows, so the next part of the patch could trigger the bug. However I found that on Windows, the first call to IStorage_Release returns zero, and the storage object is destroyed. Under Wine however, the first call to IStorage_Release returns 1 but does not destroy the object - the second call to IStorage_Release returns zero and destroys the object. It appears that Windows takes no notice of reference counts when the IStorage destructor is called! I only discovered this because in the original test code I had two calls to IStorage_Release straight after each other without the if(r) test: and although it worked on Wine it segfaulted on Windows due to the 'stg' object being destroyed on the first call. This proved the difference in behaviour.
Now on to the second part of the test, that attempted to re-open the closed storage object, then open the stream within it:
/* Easy-PC test 2 - this looks for the OpenStream mode check. Fails under Wine */
r = StgOpenStorage( filename, NULL, 0x00010020, NULL, 0, &stg); ok(r==S_OK, "StgOpenStorage failed\n"); if(stg) { static const WCHAR stmname[] = { 'w','i','n','e','t','e','s','t',0}; IStream *stm = NULL;
r = IStorage_OpenStream( stg, stmname, 0, STGM_SHARE_EXCLUSIVE|STGM_READWRITE, 0, &stm ); ok(r == S_OK, "OpenStream should succeed - "); printf("rc from OpenStream : %lx\n",r);
r = IStorage_Release(stg); ok(r == 0, "wrong ref count\n"); }
Again, this works on Windows, but the OpenStream call fails with an access denied error on Wine. This is the exact mode of the bug in the app.
Could one of the ole32 developers please contact me: I am happy to work with them to resolve this problem as I need this app to work under Wine, but not being a Windows programmer I am not fully familiar with the storage API. In the meantime I will continue my investigation and see if I can fix this directly, but I am sure it will happen sooner if I could work with the ole32 developer.
Many thanks for listening. The patch is below, I will submit this for inclusion in CVS.
John.
Index: wine/dlls/ole32/tests/storage32.c =================================================================== RCS file: /home/wine/wine/dlls/ole32/tests/storage32.c,v retrieving revision 1.14 diff -u -p -r1.14 storage32.c --- wine/dlls/ole32/tests/storage32.c 6 Oct 2005 11:38:45 -0000 1.14 +++ wine/dlls/ole32/tests/storage32.c 8 Feb 2006 18:17:03 -0000 @@ -448,6 +448,77 @@ static void test_open_storage(void) ok(r == 0, "wrong ref count\n"); }
+ + + // + // EASY-PC TESTS + // + // There are two bugs related to Wine and Easy-PC. This pair of tests + // triggers the first of the two. + // + // These tests trigger the same bug in Wine that Easy-PC does. They: + // + // 1) Open a storage file, write a stream to it, commit it and then close + // the file. This is just so we have a storage file with a stream in + // it. This operation itself does not trigger the bug. + // + // 2) It then performs the action that triggers the bug. It opens the + // storage file with a grfMode of 0x00010020 + // (STGM_TRANSACTED|STGM_READ|STGM_SHARE_DENY_WRITE). It then opens + // a stream in the file with a grfMode of STGM_SHARE_EXCLUSIVE|STGM_READWRITE + // This test works under Windows, but fails under Wine. + + + /* Easy-PC bug test 1 - this Creates a stream within an object and should not fail*/ + + r = StgOpenStorage( filename, NULL, STGM_TRANSACTED | STGM_WRITE | STGM_SHARE_DENY_WRITE, NULL, 0, &stg); + ok(r==S_OK, "StgOpenStorage failed\n"); + if(stg) + { + static const WCHAR stmname[] = { 'w','i','n','e','t','e','s','t',0}; + IStream *stm = NULL; + + r = IStorage_CreateStream( stg, stmname, STGM_WRITE | STGM_SHARE_EXCLUSIVE, + 0, 0, &stm ); + ok(r == S_OK, "CreateStream should succeed\n"); + + if(stm) { + r=IStorage_Commit(stg,STGC_DEFAULT); + ok(r==S_OK, "StorageCommit failed\n"); + + } + + // Windows reference counting seems different.... + + r = IStorage_Release(stg); + ok(r == 0, "wrong ref count"); printf("- ref count = %lx\n",r); + + if(r) { + r = IStorage_Release(stg); + ok(r == 0, "wrong ref count"); printf(" - ref count = %lx\n",r); + } + + } + + /* Easy-PC test 2 - this looks for the OpenStream mode check. Fails under Wine */ + + r = StgOpenStorage( filename, NULL, 0x00010020, NULL, 0, &stg); + ok(r==S_OK, "StgOpenStorage failed\n"); + if(stg) + { + static const WCHAR stmname[] = { 'w','i','n','e','t','e','s','t',0}; + IStream *stm = NULL; + + r = IStorage_OpenStream( stg, stmname, 0, STGM_SHARE_EXCLUSIVE|STGM_READWRITE, 0, &stm ); + ok(r == S_OK, "OpenStream should succeed - "); printf("rc from OpenStream : %lx\n",r); + + r = IStorage_Release(stg); + ok(r == 0, "wrong ref count\n"); + } + + // + // End of Easy-PC bug test. + r = DeleteFileW(filename); ok(r, "file didn't exist\n"); }
Dr J A Gow wrote:
It is as I thought that there is some issue with the object destructor for the storage object being called and not actually releasing the object. I have attached the complete patch to the tests for storage32 to
I have just had another thought on this and wonder if anyone could confirm it: Shouldn't destruction of the parent IStorage object automatically destroy all IStream objects opened within it? This seems to be the way Windows works as far as I can tell so far. Wine does not do this, requiring all child IStreams to be closed before the final call to the destructor of IStorage will actually release the memory (and file) associated with it. Any ideas?
John.
Dr J A Gow wrote:
Dr J A Gow wrote:
It is as I thought that there is some issue with the object destructor for the storage object being called and not actually releasing the object. I have attached the complete patch to the tests for storage32 to
I have just had another thought on this and wonder if anyone could confirm it: Shouldn't destruction of the parent IStorage object automatically destroy all IStream objects opened within it? This seems to be the way Windows works as far as I can tell so far. Wine does not do this, requiring all child IStreams to be closed before the final call to the destructor of IStorage will actually release the memory (and file) associated with it. Any ideas?
Releasing memory behind your back in generally a bad thing, but if Windows does that then that's what we should do too.
-
Dr J A Gow -
Robert Shearman