Discussion:
Problem report: SHRINKER.ERR, fix to DEVICE_Open/CreateFileA?
Robert Baruch
2005-08-30 22:38:51 UTC
Permalink
This was an error I got when running a self-installing executable,
power-structure-demo.exe, available from www.write-brain.com (a demo for
Power Structure).

A error box appears with title SHRINKER.ERR and message:

(path)\power-structure-demo.exe (3.4)
(time&date) - Pager initialisation error 2 - File not found

and then the program quits.


Running with --debugmsg +all,+relay,+text,+string shows the following
trace (only the part I think is significant):

----BEGIN TRACE----

0806d388:Call kernel32.CreateFileA(40612b20
"\\\\.\\SHRINK34.LDR",00000000,00000000,00000000,00000003,04000000,00000000)
ret=00761731
0806d388:trace:file:CreateFileA \\.\SHRINK34.LDR QUERY_ACCESS OPEN_EXISTING
0806d388:fixme:win32:DEVICE_Open Unknown/unsupported VxD SHRINK34.LDR.
Try --winver nt40 or win31 !
0806d388:Ret kernel32.CreateFileA() retval=ffffffff ret=00761731
0806d388:Call kernel32.GetWindowsDirectoryA(40616d3c,00000104) ret=0076180d
0806d388:trace:string:lstrcpynA (0x40616d3c, "C:\\WINDOWS", 260)
0806d388:Ret kernel32.GetWindowsDirectoryA() retval=0000000a ret=0076180d
0806d388:Call kernel32.GetTempFileNameA(40612b1c
"C:\\WINDOWS\\",0075c538 "000",00000000,40616d3c) ret=007617b2
0806d388:trace:file:CreateFileA C:\WINDOWS\000cf6e.tmp GENERIC_WRITE
CREATE_NEW
0806d388:trace:dosfs:DOSFS_GetFullName C:\WINDOWS\000cf6e.tmp (last=0)
0806d388:trace:string:lstrcpynA (0x406119ec, "/mnt/dos", 1024)
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos,WINDOWS\000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos,WINDOWS\000cf6e.tmp)
-> windows (WINDOWS)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos/windows,000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:warn:dosfs:DOSFS_FindUnixName '000cf6e.tmp' not found in
'/mnt/dos/windows'
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_GetFullName returning
/mnt/dos/windows/000cf6e.tmp =
C:\WINDOWS\000cf6e.tmp
0806d388:trace:dosfs:GetDriveTypeA ("C:\\WINDOWS\\000cf6e.tmp")
0806d388: create_file( access=40000000, inherit=0, sharing=00000000,
create=1, attrs=00000080, drive_type=3,
filename="/mnt/dos/windows/000cf6e.tmp" )
0806d388: create_file() = 0 { handle=52 }
0806d388:trace:file:FILE_GetTempFileName created C:\WINDOWS\000cf6e.tmp
0806d388: close_handle( handle=52 )
0806d388: close_handle() = 0 { fd=-1 }
0806d388:trace:dosfs:DOSFS_GetFullName C:\WINDOWS\000cf6e.tmp (last=0)
0806d388:trace:string:lstrcpynA (0x40612234, "/mnt/dos", 1024)
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos,WINDOWS\000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos,WINDOWS\000cf6e.tmp)
-> windows (WINDOWS)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos/windows,000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos/windows,000cf6e.tmp)
-> 000cf6e.tmp (000CF6E.TMP)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_GetFullName returning
/mnt/dos/windows/000cf6e.tmp =
C:\WINDOWS\000CF6E.TMP
0806d388:trace:file:FILE_GetTempFileName returning C:\WINDOWS\000cf6e.tmp
0806d388:Ret kernel32.GetTempFileNameA() retval=0000cf6e ret=007617b2
0806d388:Call kernel32.CreateFileA(40616d3c
"C:\\WINDOWS\\000cf6e.tmp",40000000,00000000,00000000,00000002,00000080,00000000)
ret=00761013
0806d388:trace:file:CreateFileA C:\WINDOWS\000cf6e.tmp GENERIC_WRITE
CREATE_ALWAYS
0806d388:trace:dosfs:DOSFS_GetFullName C:\WINDOWS\000cf6e.tmp (last=0)
0806d388:trace:string:lstrcpynA (0x40612210, "/mnt/dos", 1024)
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos,WINDOWS\000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos,WINDOWS\000cf6e.tmp)
-> windows (WINDOWS)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos/windows,000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos/windows,000cf6e.tmp)
-> 000cf6e.tmp (000CF6E.TMP)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_GetFullName returning
/mnt/dos/windows/000cf6e.tmp =
C:\WINDOWS\000CF6E.TMP
0806d388:trace:dosfs:GetDriveTypeA ("C:\\WINDOWS\\000CF6E.TMP")
0806d388: create_file( access=40000000, inherit=0, sharing=00000000,
create=2, attrs=00000080, drive_type=3,
filename="/mnt/dos/windows/000cf6e.tmp" )
0806d388: create_file() = 0 { handle=52 }
0806d388:Ret kernel32.CreateFileA() retval=00000034 ret=00761013
0806d388:Call
kernel32.WriteFile(00000034,40612c38,00003288,40612c04,00000000)
ret=00761063
0806d388:trace:file:WriteFile 52 0x40612c38 12936 0x40612c04 (nil)
0806d388: get_handle_fd( handle=52, access=40000000 )
0806d388: *fd* 52 -> 16
0806d388: get_handle_fd() = 0 { fd=-1, type=1 }
0806d388: set_handle_info( handle=52, flags=0, mask=0, fd=10 )
0806d388: set_handle_info() = 0 { old_flags=0, cur_fd=10 }
0806d388:Ret kernel32.WriteFile() retval=00000001 ret=00761063
0806d388:Call kernel32.CloseHandle(00000034) ret=00760f0d
0806d388: close_handle( handle=52 )
0806d388: close_handle() = 0 { fd=10 }
0806d388:Ret kernel32.CloseHandle() retval=00000001 ret=00760f0d
0806d388:Call kernel32.CreateFileA(40612b20
"\\\\.\\C:\\WINDOWS\\000cf6e.tmp",00000000,00000000,00000000,00000003,04000000,00000000)
ret=00761731
0806d388:trace:file:CreateFileA \\.\C:\WINDOWS\000cf6e.tmp QUERY_ACCESS
OPEN_EXISTING
0806d388:fixme:win32:DEVICE_Open Unknown/unsupported VxD
C:\WINDOWS\000cf6e.tmp. Try --winver nt40 or win31 !
0806d388:Ret kernel32.CreateFileA() retval=ffffffff ret=00761731
0806d388:Call kernel32.DeleteFileA(40616d3c "C:\\WINDOWS\\000cf6e.tmp")
ret=00761911
0806d388:trace:file:DeleteFileA 'C:\WINDOWS\000cf6e.tmp'
0806d388:trace:dosfs:DOSFS_GetFullName C:\WINDOWS\000cf6e.tmp (last=1)
0806d388:trace:string:lstrcpynA (0x40612384, "/mnt/dos", 1024)
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos,WINDOWS\000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos,WINDOWS\000cf6e.tmp)
-> windows (WINDOWS)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_FindUnixName /mnt/dos/windows,000cf6e.tmp
0806d388:trace:heap:HeapAlloc (403b0000,00000002,0000022c): returning
4042ef68
0806d388:trace:dosfs:DOSFS_FindUnixName (/mnt/dos/windows,000cf6e.tmp)
-> 000cf6e.tmp (000CF6E.TMP)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:dosfs:DOSFS_GetFullName returning
/mnt/dos/windows/000cf6e.tmp =
C:\WINDOWS\000CF6E.TMP
0806d388:Ret kernel32.DeleteFileA() retval=00000001 ret=00761911
0806d388:Call kernel32.GetLastError() ret=00760303
0806d388:Ret kernel32.GetLastError() retval=00000002 ret=00760303
0806d388:Call kernel32.GetLocalTime(40612bf8) ret=00761d66
0806d388:Ret kernel32.GetLocalTime() retval=00000000 ret=00761d66
0806d388:Call kernel32.GetLocalTime(40612bf8) ret=00761cd4
0806d388:Ret kernel32.GetLocalTime() retval=00000000 ret=00761cd4
0806d388:Call
kernel32.FormatMessageA(00001000,00000000,00000002,00000400,0075d54b,000000c8,00000000)
ret=00760493
0806d388:trace:resource:FormatMessageA
(0x1000,(nil),2,0x400,0x75d54b,200,(nil))0806d388:trace:resource:load_messageA
instance = 40667000, id = 00000002, buffer = (nil), length = 100
0806d388:trace:resource:RES_FindResource2 (40667000, 0000000b, 00000001,
0400, W, PE)
0806d388:trace:resource:RES_LoadResource (40667000, 406ac8c0, PE)
0806d388:trace:resource:LockResource (406974e0)
0806d388:trace:resource:load_messageA - strlen=20
0806d388:trace:heap:HeapAlloc (403b0000,00000002,00000018): returning
4042ef68
0806d388:trace:resource:load_messageA instance = 40667000, id =
00000002, buffer = 0x4042ef68, length = 21
0806d388:trace:resource:RES_FindResource2 (40667000, 0000000b, 00000001,
0400, W, PE)
0806d388:trace:resource:RES_LoadResource (40667000, 406ac8c0, PE)
0806d388:trace:resource:LockResource (406974e0)
0806d388:trace:resource:load_messageA - strlen=20
0806d388:trace:string:lstrcpynA (0x4042ef68, "File not found\n", 20)
0806d388:trace:resource:load_messageA 'File not found
' copied !
0806d388:trace:heap:HeapAlloc (403b0000,0000000a,00000064): returning
4042ef8c
0806d388:trace:heap:HeapReAlloc (403b0000,0000000a,4042ef8c,000000c8):
returning 4042ef8c
0806d388:trace:resource:FormatMessageA -- "File not found\r\n"
0806d388:trace:string:lstrcpynA (0x75d54b, "File not found\r\n", 200)
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef8c): returning TRUE
0806d388:trace:heap:HeapFree (403b0000,00000002,4042ef68): returning TRUE
0806d388:trace:resource:FormatMessageA -- returning 16
0806d388:Ret kernel32.FormatMessageA() retval=00000010 ret=00760493
0806d388:Call kernel32.GetModuleHandleA(40612bf4 "USER32") ret=0075fbdf
0806d388:Ret kernel32.GetModuleHandleA() retval=406e2000 ret=0075fbdf
0806d388:Call kernel32.GetProcAddress(406e2000,0075b05c "MessageBoxA")
ret=0075fbfd
0806d388:trace:win32:MODULE_GetProcAddress (406e2000,MessageBoxA)
0806d388:trace:win32:PE_FindExportedFunction (MessageBoxA)
0806d388:Ret kernel32.GetProcAddress() retval=4077f8e0 ret=0075fbfd
0806d388:Call user32.MessageBoxA(00000000,0075d4e0 "C:\\My
Documents\\installs\\power-structure-demo.exe (3.4) 12/06/01 15:05:02 -
Page"...,0075b3e8 "SHRINKER.ERR",00002030) ret=0075fc1a
0806d388:warn:dialog:MessageBoxA Messagebox


----END TRACE----


The program apparently tries to open a file called \\.\SHRINK34.LDR,
which fails because SHRINK34.LDR doesn't exist.

The next thing the program does is create a temporary file
(C:\WINDOWS\000cf6e.tmp here), write 0x3288 bytes of stuff to it
(successfully), close it, and then try to re-open it with \\.\ prepended
to the filename. That fails, resulting in the message box.

CreateFileA (files/file.c) will handle filenames prepended with \\.\
specially. If the file begins with \\.\pipe\ then we open a pipe. If the
filename is a DOS device, we open that. Otherwise we fall through to
DEVICE_Open (win32/device.c) which checks to see if the file is a known
VxD. In this trace, it fails.

I've been looking through the Microsoft documentation. In the
documentation for opening VxD's (
http://msdn.microsoft.com/library/default.asp?url=/library/en-us/win32/devio_886c.asp)
it says:

"CreateFile checks for a filename extension to determine whether VxDName
specifies a file. If a filename extension (such as .VXD) is present,
the function looks for the file in the standard search path. In the
following example, CreateFile looks for the SAMPLE.VXD file in the
standard search path." (example: \\.\SAMPLE.VXD)

In addition, under the documentation for CreateFile
(http://msdn.microsoft.com/library/default.asp?url=/library/en-us/fileio/filesio_7wmd.asp)
it says:

"There is no trailing backslash in a drive name. The string "\\.\c:\"
refers to the root directory of drive C."

So could it be that in DEVICE_Open or CreateFileA, opening a file
prepended with \\.\ that starts with a drive letter and has a filename
extension should just open the file?

--Rob
Robert Baruch
2005-08-30 22:38:51 UTC
Permalink
Well, I made the modification to the source code. This time the program
got past opening the file after it was written to. The program then
deleted the file, and then tried to do a DeviceIoControl on it:

0806b0a8:Ret kernel32.CreateFileA() retval=00000038 ret=00761731
0806b0a8:Call kernel32.DeleteFileA(40606d3c "C:\\WINDOWS\\000e914.tmp")
ret=00761911
0806b0a8:trace:file:DeleteFileA 'C:\WINDOWS\000e914.tmp'
0806b0a8:trace:dosfs:DOSFS_GetFullName C:\WINDOWS\000e914.tmp (last=1)
0806b0a8:trace:string:lstrcpynA (0x40602380, "/mnt/dos", 1024)
0806b0a8:trace:dosfs:DOSFS_FindUnixName /mnt/dos,WINDOWS\000e914.tmp
0806b0a8:trace:heap:HeapAlloc (403a0000,00000002,0000022c): returning
4041ef38
0806b0a8:trace:dosfs:DOSFS_FindUnixName (/mnt/dos,WINDOWS\000e914.tmp)
-> windows (WINDOWS)
0806b0a8:trace:heap:HeapFree (403a0000,00000002,4041ef38): returning TRUE
0806b0a8:trace:dosfs:DOSFS_FindUnixName /mnt/dos/windows,000e914.tmp
0806b0a8:trace:heap:HeapAlloc (403a0000,00000002,0000022c): returning
4041ef38
0806b0a8:trace:dosfs:DOSFS_FindUnixName (/mnt/dos/windows,000e914.tmp)
-> 000e914.tmp (000E914.TMP)
0806b0a8:trace:heap:HeapFree (403a0000,00000002,4041ef38): returning TRUE
0806b0a8:trace:dosfs:DOSFS_GetFullName returning
/mnt/dos/windows/000e914.tmp =
C:\WINDOWS\000E914.TMP
0806b0a8:Ret kernel32.DeleteFileA() retval=00000001 ret=00761911
0806b0a8:Call
kernel32.DeviceIoControl(00000038,00000001,00000000,00000000,40606e40,00000010,40606e50,00000000)
ret=00761943
0806b0a8:trace:win32:DeviceIoControl
(56,1,(nil),0,0x40606e40,16,0x40606e50,(nil))
0806b0a8: get_file_info( handle=56 )
0806b0a8: get_file_info() = 0 { type=1, attr=32, access_time=1007675668,
write_time=1007675668, size_high=0, size_low=12936, links=0,
index_high=769, index_low=902562, serial=00000000 }
0806b0a8:Ret kernel32.DeviceIoControl() retval=00000000 ret=00761943
0806b0a8:Call kernel32.GetLastError() ret=00760303
0806b0a8:Ret kernel32.GetLastError() retval=00000057 ret=00760303


This last error means "Invalid Parameter".

So I take back my thought that \\.\filename.ext should just open the
file as a regular file. I think it should be opening the file as a VxD,
installing it if it isn't already installed. How that's supposed to work
is beyond me, but I'll see if I can learn about how it should be done.

--Rob
Uwe Bonnes
2005-08-30 22:38:51 UTC
Permalink
Robert Baruch <***@starband.net> wrote:
:...

: So I take back my thought that \\.\filename.ext should just open the
: file as a regular file. I think it should be opening the file as a VxD,
: installing it if it isn't already installed. How that's supposed to work
: is beyond me, but I'll see if I can learn about how it should be done.

Wine can't run VXDs. Running with --winver nt40 shouldn't use the VXD.
However the shrinker code is obfuscated to the top and last time I tried
some shrinker file with nt40 wine failed too.

Bye
--
Uwe Bonnes ***@elektron.ikp.physik.tu-darmstadt.de

Institut fuer Kernphysik Schlossgartenstrasse 9 64289 Darmstadt
--------- Tel. 06151 162516 -------- Fax. 06151 164321 ----------
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Hi Uwe,

Thanks for the reply. I read your thread on VXD's from January 2001 and
now I understand that Wine can't support just any VXD.

Is "SHRINKER" some kind of decompressor? A long long time ago in a
galaxy far far away I wrote a utility which would decompress an MSDOS
self-decompressing-exe file that had been compressed by some utility I
never got the name of. Would there be any interest in some kind of patch
to Wine which would let this particular VXD's job be done within Wine?
Something that would detect the shrinker VXD and immediately act to
emulate it -- say, DEVICE_Open would look into the VXD to see if it's
name was SHRINK34?

I used winedbg to break the program just before it deletes the VXD, and
then used IDA to look inside the VXD. It has no API's, and a single
ioctl routine, which has five possible calls. Is there any interest in
pursuing this further?

--Rob
Andreas Mohr Usenet 10/01
2005-08-30 22:38:52 UTC
Permalink
Post by Robert Baruch
Hi Uwe,
Thanks for the reply. I read your thread on VXD's from January 2001 and
now I understand that Wine can't support just any VXD.
Is "SHRINKER" some kind of decompressor? A long long time ago in a
galaxy far far away I wrote a utility which would decompress an MSDOS
self-decompressing-exe file that had been compressed by some utility I
never got the name of. Would there be any interest in some kind of patch
to Wine which would let this particular VXD's job be done within Wine?
Something that would detect the shrinker VXD and immediately act to
emulate it -- say, DEVICE_Open would look into the VXD to see if it's
name was SHRINK34?
Yep, SHRINKER is some kind of decompressor.
Yes, that might actually be possible.
Post by Robert Baruch
I used winedbg to break the program just before it deletes the VXD, and
then used IDA to look inside the VXD. It has no API's, and a single
ioctl routine, which has five possible calls. Is there any interest in
pursuing this further?
There are probably some decompressors on the internet for these
Shrinker apps, too.
You might want to get hold of (public) source for these decompressors,
find out about SHRINK34 VxD behaviour, intercept it and use the decompressor
code in Wine instead.
--
Andreas Mohr, Renningen, Germany
In case you need to contact me after expiry of temporary email address:
my eternal (hopefully) email address is frqr2001 at the domain sneakemail.com
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Hi Andreas,

Thanks for the info. I looked around on google and deja, and basically
found that the tools people have written to unshrink Shrinkered files
are h4x0r toolz, so they don't come with source code and the authors'
websites disappear like cockroaches when you turn on the light. I'll
keep looking but in the meantime I'm going to take a stab at figuring
out the algorithm myself from the listing.

Thanks,

--Rob
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Well, you have a point. I know the app works well under Windows 2000
(under VMWare), but when I run it under wine in NT mode the app just
spins. I should probably spend a few cycles looking at the NT spin, in
case it turns out it's an easier problem to solve than emulating the VXD.

Thanks for the advice,

--Rob
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
A quick look at running the app under --winver nt40 shows two problems.
It hits the first problem and wants to display a SHRINKER.ERR dialog box
saying "Dispatcher initialisation error". However, when wine tries to
display that message box, it looks like the app spins -- it eats up all
of the CPU -- when the app calls x11drv.LoadOEMResource. These are the
last lines of the relay trace:

0806d398:Call window proc 0x40726520
(hwnd=00010023,msg=WM_GETDLGCODE,wp=00000000,lp=00000000)
0806d398:Ret window proc 0x40726520
(hwnd=00010023,msg=WM_GETDLGCODE,wp=00000000,lp=00000000) retval=00000100
0806d398:Call x11drv.CreateWindow(00010024,405047dc,00000001) ret=40752b77
0806d398:Call window proc 0x407050b0
(hwnd=00010024,msg=WM_NCCREATE,wp=00000000,lp=405047dc)
0806d398:Call x11drv.SetWindowText(00010024,4042f914 L"&OK") ret=40733366
0806d398:Ret x11drv.SetWindowText() retval=00000001 ret=40733366
0806d398:Ret window proc 0x407050b0
(hwnd=00010024,msg=WM_NCCREATE,wp=00000000,lp=405047dc) retval=00000001
0806d398:Call window proc 0x407050b0
(hwnd=00010024,msg=WM_NCCALCSIZE,wp=00000000,lp=40504488)
0806d398:Ret window proc 0x407050b0
(hwnd=00010024,msg=WM_NCCALCSIZE,wp=00000000,lp=40504488) retval=00000300
0806d398:Call window proc 0x407050b0
(hwnd=00010024,msg=WM_CREATE,wp=00000000,lp=405047dc)
0806d398:Call x11drv.LoadOEMResource(00007ff7,00000001) ret=40731272

Running with +all shows the LoadOEMResource calls results in an
exception and a spin:

0806d398:trace:resource:LoadImageW (0x0000,0x7ff7,0,0,0,0x00000000)
0806d398:Call x11drv.LoadOEMResource(00007ff7,00000001) ret=40731272
0806d398:trace:heap:HeapAlloc (403b0000,00000002,0000008c): returning
4042f938
0806d398:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806d398: queue_exception_event( first=1,
record={context={flags=00000000,eax=40503f3c,ebx=40bbe870,ecx=0805e9b8,edx=40bb4b38,esi=00000000,edi=4042f938,ebp=40501e24,eip=40bb3dfc,esp=404ffdfc,eflags=00010216,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,float={00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x40bb3dfc,params={1,404ffdf8}}
)
0806d398: queue_exception_event() = 0 { handle=0 }
0806d398:trace:seh:EXC_CallHandler calling handler at (nil)
code=c0000005 flags=0
0806d398:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806d398: queue_exception_event( first=1,
record={context={flags=405047f0,eax=40504b18,ebx=40110dc4,ecx=40504b58,edx=40504c44,esi=40504bc8,edi=4010dae6,ebp=40504b34,eip=00000000,esp=40504b04,eflags=00010216,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=40504710,dr1=40070a49,dr2=00000000,dr3=00000000,dr6=0000000c,dr7=00000100,float={40104440,40504794,4039c2e0,40110dc4,403b0cf1,400ed2f4,405047ac,403b0cf1,403b0cf1,40070c36,40110dc4,403b0d12,40772580,405047c8,40110dc4,40070c67,00000002,403b0ce8,0000006f,00000045,403b08e0,40110dc4,0000002a,40772580,00000082,00000020,00000000,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=(nil),params={0,0}}
)
0806d398: queue_exception_event() = 0 { handle=0 }
0806d398:trace:seh:EXC_CallHandler calling handler at 0x40070d60
code=c0000005 flags=0
0806d398:trace:seh:EXC_CallHandler handler returned 2

(and the last two traces repeat ad infinitum)


Running the app under winedbg results in an almost immediate page fault,
but LoadOEMResource is not in the backtrace! However, it also shows that
address 0x40bb3dfc (the reported exception eip) is in libXpm.so.4 (I'm
running X 4.0.3) :(

--Rob
Pavel Troller
2005-08-30 22:38:52 UTC
Permalink
Post by Robert Baruch
A quick look at running the app under --winver nt40 shows two problems.
It hits the first problem and wants to display a SHRINKER.ERR dialog box
saying "Dispatcher initialisation error". However, when wine tries to
display that message box, it looks like the app spins -- it eats up all
of the CPU -- when the app calls x11drv.LoadOEMResource. These are the
Hi!
I have a very similar problem. It's not related to shrinker, but to
LoadOEMResource. I'm trying to install an app (Child's Czech graphical
programming system Baltik) and it segfaults. Closer look shows exactly
the same behavior of LoadOEMResource.

0806ea10:Call window proc 0x406c1d9c (hwnd=00010029,msg=WM_CREATE,wp=00000000,lp=404d4554)
0806ea10:trace:win32:_EnterSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count before 0
0806ea10:trace:win32:_EnterSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count after 1
0806ea10:trace:win32:_LeaveSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count before 1
0806ea10:trace:win32:_LeaveSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count after 0
0806ea10:trace:win32:_EnterSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count before 0
0806ea10:trace:win32:_EnterSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count after 1
0806ea10:trace:win32:_LeaveSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count before 1
0806ea10:trace:win32:_LeaveSysLevel (0x40749d2c, level 2): thread 0x806ea10 (fs 008f, pid 17074) count after 0
0806ea10:trace:resource:LoadImageW (0x0000,0x7ff7,0,0,0,0x00000000)
0806ea10:Call x11drv.LoadOEMResource(00007ff7,00000001) ret=406edd92
0806ea10:trace:heap:HeapAlloc (40390000,00000002,0000008c): returning 403f9cf8
0806ea10:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806ea10: queue_exception_event( first=1, record={context={flags=00000000,eax=404d1cf0,ebx=40981658,ecx=00000031,edx=404d1c74,esi=00000000,edi=404d3d14,ebp=403f9cf8,eip=40974ece,esp=404cdb80,eflags=00010202,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,float={00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x40974ece,params={1,404cdb7c}} )
0806ea10: queue_exception_event() = 0 { handle=0 }
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x40389af8 code=c0000005 flags=0
0806ea10:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806ea10: queue_exception_event( first=1, record={context={flags=401138a0,eax=404d476e,ebx=400ff684,ecx=00000034,edx=00000057,esi=400fcd5f,edi=404d49e6,ebp=40389af8,eip=40389b00,esp=404d4914,eflags=00010202,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=0000000c,dr1=404d4518,dr2=404d433c,dr3=400689a1,dr6=402bf834,dr7=404d47c0,float={402bf834,404d47c8,40390cf9,40389af8,402bf834,404d47d8,402d3226,40389af8,40390d1a,404d440c,402d2894,40389af8,404d4424,402bf834,404d47fc,402bf834,404d4804,403910ef,00000000,402bf834,404d4814,000003d6,402cea86,404d4424,40730fa0,404d4590,402cea6d,404d4424}},rec={code=c0000005,flags=0,rec=(nil),addr=0x40389b00,params={1,b4f24034}} )
0806ea10: queue_exception_event() = 0 { handle=0 }
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x40068c90 code=c0000005 flags=0
0806ea10:trace:seh:EXC_CallHandler handler returned 2
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x402cea86 code=c0000005 flags=10
0806ea10:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806ea10: queue_exception_event( first=1, record={context={flags=404d40e0,eax=0000000e,ebx=400ff684,ecx=00000035,edx=404d4790,esi=400fcd5d,edi=404d42fc,ebp=402cea86,eip=402cea99,esp=404d424c,eflags=00010216,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=402bf834,dr1=404d40e8,dr2=402bf834,dr3=404d40f0,dr6=402bf834,dr7=404d40f8,float={40390d26,ffffffff,00000000,65363034,32396464,402bf834,404d4114,402bf834,404d411c,403846c0,00000000,402bf834,404d412c,000003c9,40390d26,403846c0,00000000,00000000,00000000,40390000,00000000,00000000,00000000,00000000,00000000,40390d26,40390d26,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x402cea99,params={1,e}} )

And the trace then also shows repetitive patterns, however not ad infinitum,
after about 10 seconds it segfaults (generating about 265 Megs of log).
Maybe You wasn't patient enough or my machine is faster :-)

It is also interesting that the same call is made once before and it doesn't
make any harm:

0806ea10:Call user32.LoadBitmapA(00000000,00007ff7) ret=00438315
0806ea10:trace:resource:LoadImageW (0x0000,0x7ff7,0,0,0,0x00000000)
0806ea10:Call x11drv.LoadOEMResource(00007ff7,00000001) ret=406edd92
0806ea10:trace:heap:HeapAlloc (40390000,00000002,0000008c): returning 403f0f94
0806ea10:trace:win32:_EnterSysLevel (0x407eb904, level 3): thread 0x806ea10 (fs 008f, pid 17074) count before 0
0806ea10:trace:win32:_EnterSysLevel (0x407eb904, level 3): thread 0x806ea10 (fs 008f, pid 17074) count after 1
0806ea10:trace:heap:HeapAlloc (40390000,00000002,00000038): returning 403f102c
0806ea10:trace:gdi:GDI_AllocObject (0130): enter 1
0806ea10:trace:gdi:GDI_ReleaseObj (0130): leave 1
0806ea10:trace:win32:_LeaveSysLevel (0x407eb904, level 3): thread 0x806ea10 (fs 008f, pid 17074) count before 1
0806ea10:trace:win32:_LeaveSysLevel (0x407eb904, level 3): thread 0x806ea10 (fs 008f, pid 17074) count after 0
0806ea10:trace:heap:HeapFree (40390000,00000002,403f0f94): returning TRUE
0806ea10:Ret x11drv.LoadOEMResource() retval=00000130 ret=406edd92
0806ea10:Ret user32.LoadBitmapA() retval=00000130 ret=00438315

With regards, Pavel Troller
Uwe Bonnes
2005-08-30 22:38:52 UTC
Permalink
Robert Baruch <***@starband.net> wrote:
: Hi Uwe,

: Thanks for the reply. I read your thread on VXD's from January 2001 and
: now I understand that Wine can't support just any VXD.

: Is "SHRINKER" some kind of decompressor? A long long time ago in a
: galaxy far far away I wrote a utility which would decompress an MSDOS
: self-decompressing-exe file that had been compressed by some utility I
: never got the name of. Would there be any interest in some kind of patch
: to Wine which would let this particular VXD's job be done within Wine?
: Something that would detect the shrinker VXD and immediately act to
: emulate it -- say, DEVICE_Open would look into the VXD to see if it's
: name was SHRINK34?

: I used winedbg to break the program just before it deletes the VXD, and
: then used IDA to look inside the VXD. It has no API's, and a single
: ioctl routine, which has five possible calls. Is there any interest in
: pursuing this further?

Well, there general saying in the wine community is that VXDs are win95
things and will go away, as MS-Os'es are moving to the NT. So gettting
wine's behaviour right to run the non VXD shrunker parts would be another
good thing.

However I have seen VXD with regard to dongle protexted software also with
the NT incarnation of wine and I thinks that the VXD is really requested
when in NT mode,

Bye
--
Uwe Bonnes ***@elektron.ikp.physik.tu-darmstadt.de

Institut fuer Kernphysik Schlossgartenstrasse 9 64289 Darmstadt
--------- Tel. 06151 162516 -------- Fax. 06151 164321 ----------
Dan Kegel
2005-08-30 22:38:52 UTC
Permalink
... Would there be any interest in some kind of patch
to Wine which would let this particular VXD's job be done within Wine?
Something that would detect the shrinker VXD and immediately act to
emulate it -- say, DEVICE_Open would look into the VXD to see if it's
name was SHRINK34?
I used winedbg to break the program just before it deletes the VXD, and
then used IDA to look inside the VXD. It has no API's, and a single
ioctl routine, which has five possible calls. Is there any interest in
pursuing this further?
The only VxD's worth considering emulating are those used by
popular applications which do not work under Windows NT/2000/XP,
and which do very simple, limited things.
A good example is a VxD call to retrieve a MAC address
used by a common Win9x-only copy-protection scheme.

That limits the number of VxD's worth emulating down severely.

Does the app using SHRINKER not work under NT?
- Dan
Uwe Bonnes
2005-08-30 22:38:52 UTC
Permalink
Dan Kegel <***@ixiacom.com> wrote:
: Robert Baruch wrote:
:> ... Would there be any interest in some kind of patch
:> to Wine which would let this particular VXD's job be done within Wine?
:> Something that would detect the shrinker VXD and immediately act to
:> emulate it -- say, DEVICE_Open would look into the VXD to see if it's
:> name was SHRINK34?
:>
:> I used winedbg to break the program just before it deletes the VXD, and
:> then used IDA to look inside the VXD. It has no API's, and a single
:> ioctl routine, which has five possible calls. Is there any interest in
:> pursuing this further?

: The only VxD's worth considering emulating are those used by
: popular applications which do not work under Windows NT/2000/XP,
: and which do very simple, limited things.
: A good example is a VxD call to retrieve a MAC address
: used by a common Win9x-only copy-protection scheme.

: That limits the number of VxD's worth emulating down severely.

: Does the app using SHRINKER not work under NT?

As I tried to tell, shrinker tries to protext itself and with wine it stumbles.

But if Robert feels worth implementing the VXD (in a clean way), he should go on.

Bye
--
Uwe Bonnes ***@elektron.ikp.physik.tu-darmstadt.de

Institut fuer Kernphysik Schlossgartenstrasse 9 64289 Darmstadt
--------- Tel. 06151 162516 -------- Fax. 06151 164321 ----------
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Hi Pavel,

Can you run your app under winedbg? When I run my app under winedbg, it
segfaults inside the application code with a bad read access. The
specific instruction it faults on is movl 0x10(%esi),%eax (aka mov
[esi+0x10],eax for IDA users). I'm curious to know if your app uses the
same library as mine...

--Rob
Pavel Troller
2005-08-30 22:38:52 UTC
Permalink
Post by Robert Baruch
Hi Pavel,
Can you run your app under winedbg? When I run my app under winedbg, it
segfaults inside the application code with a bad read access. The
specific instruction it faults on is movl 0x10(%esi),%eax (aka mov
[esi+0x10],eax for IDA users). I'm curious to know if your app uses the
same library as mine...
--Rob
Hi!
If run under winedbg, my app crashes differently than if run without it.
It crashes very soon, probably not in LoadOEMResource.
It's wrong that I can't C&P from the winedbg window, I would paste the register and
stack dumps.
However, it's a page fault on read access to 0x000001f4 in 32bit code,
there are 5 stack entries, the last two in USER32.DLL.GetTaskmanWindow (in libuser32.so)
The offending instruction is movl 0x1f4(%eax),%ebx and eax is 0x0, which explains the
fault address. I didn't compile with debugging on so I can't supply the source code
fragment which makes the crash :-(.
With regards, Pavel
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Hi Pavel,

Right, my app also crashes in a different place under winedbg, although
it crashes in the same winedbg place under gdb.

I took a closer look at wine --winver nt40 --debugmsg +all.

I found something interesting. If I search for queue_exception, I find
that there is an exception raised before the LoadOEMCall, about
328klines in:

0806d398:Call
kernel32.VirtualProtect(00459000,00000018,00000002,40616e74) ret=0075fd82
0806d398:trace:virtual:VirtualProtect 0x459000 00000018 00000002
0806d398:trace:virtual:VIRTUAL_SetProt 0x459000-0x459fff c-r--
View: 0x400000 - 0x765fff 28
0x400000 - 0x400fff c-r--
0x401000 - 0x458fff c----
0x459000 - 0x459fff c-r--
0x45a000 - 0x758fff c----
0x759000 - 0x765fff c-rw-
0806d398:Ret kernel32.VirtualProtect() retval=00000001 ret=0075fd82
0806d398:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806d398: queue_exception_event( first=1,
record={context={flags=00000000,eax=00002000,ebx=40110dc4,ecx=404260f0,edx=40426174,esi=00456000,edi=00000000,ebp=40616e68,eip=00760dcd,esp=40616e48,eflags=00010206,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,float={00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x760dcd,params={0,456010}}
)
0806d398: queue_exception_event() = 0 { handle=0 }
0806d398:trace:seh:EXC_CallHandler calling handler at 0x761b10
code=c0000005 flags=0
0806d398:Call kernel32.SetLastError(00000000) ret=00760711
0806d398:Ret kernel32.SetLastError() retval=00000000 ret=00760711
0806d398:Call kernel32.GetLastError() ret=00760303
0806d398:Ret kernel32.GetLastError() retval=00000000 ret=00760303
0806d398:Call kernel32.CloseHandle(00000028) ret=00760f0d
0806d398: close_handle( handle=40 )
0806d398: close_handle() = 0 { fd=10 }
0806d398:Ret kernel32.CloseHandle() retval=00000001 ret=00760f0d
0806d398:Call kernel32.GetLocalTime(40504a5c) ret=00761d66
0806d398:Ret kernel32.GetLocalTime() retval=00000000 ret=00761d66
0806d398:Call kernel32.GetLocalTime(40504a5c) ret=00761cd4
0806d398:Ret kernel32.GetLocalTime() retval=00000000 ret=00761cd4
0806d398:Call kernel32.GetModuleHandleA(40504a58 "USER32") ret=0075fbdf
0806d398:Ret kernel32.GetModuleHandleA() retval=406e2000 ret=0075fbdf
0806d398:Call kernel32.GetProcAddress(406e2000,0075b05c "MessageBoxA")
ret=0075fbfd
0806d398:trace:win32:MODULE_GetProcAddress (406e2000,MessageBoxA)
0806d398:trace:win32:PE_FindExportedFunction (MessageBoxA)
0806d398:Ret kernel32.GetProcAddress() retval=4077f8e0 ret=0075fbfd
0806d398:Call user32.MessageBoxA(00000000,0075d4e0 "C:\\My
Documents\\power-structure-demo.exe
(3.4) 12/08/01 16:19:00 - Dispatcher in"...,0075b3e8
"SHRINKER.ERR",00002030) ret=0075fc1a
0806d398:warn:dialog:MessageBoxA Messagebox


The eip mentioned in the queue_exception_event trace is the same eip
that winedbg (and gdb) segfault in. Notice the SHRINKER.ERR message that
comes afterwards. Also notice the exception handler at 0x761b10. This is
also inside the application, so it looks like the app sets up an
exception handler, and is all set to display an error message box.

Then comes another exception, about 900 lines later:

0806d398:trace:gdi:GDI_ReleaseObj (004c): leave 1
0806d398:trace:win32:_LeaveSysLevel (0x4082dfc4, level 3): thread
0x806d398 (fs 008f, pid 24366) count before 1
0806d398:trace:win32:_LeaveSysLevel (0x4082dfc4, level 3): thread
0x806d398 (fs 008f, pid 24366) count after 0
0806d398:trace:palette:GetSystemPaletteEntries hdc=004c,start=0,count=0
0806d398:trace:resource:RES_FindResource2 (000000b6, 0000000e,
40764cceL"", 0000, W, PE)
0806d398:trace:resource:RES_FindResource2 (00400000, 0000000e,
40764cceL"", 0000, W, PE)
0806d398:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806d398: queue_exception_event( first=1,
record={context={flags=402d40e8,eax=0045f000,ebx=40110dc4,ecx=0045f000,edx=0000000e,esi=0000000e,edi=0045f010,ebp=40503f98,eip=40096688,esp=40503f88,eflags=00010216,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=4050401c,dr1=40504020,dr2=00000000,dr3=00000000,dr6=402d40e8,dr7=40504030,float={40504034,405042e8,402d40e8,40504040,402d40e8,40504048,ffffffff,00000000,ffffffff,402d40e8,4050405c,40504060,402d40e8,40504068,4010447e,40773882,400ed2fd,402d40e8,4050407c,40504080,402d40e8,40504088,4050408c,402d40e8,40504094,402d40e8,4050409c,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x40096688,params={0,45f00c}}
)
0806d398: queue_exception_event() = 0 { handle=0 }
0806d398:trace:seh:EXC_CallHandler calling handler at 0x400714d0
code=c0000005 flags=0
0806d398:trace:seh:EXC_RtlUnwind code=c0000005 flags=2
0806d398:trace:seh:EXC_CallHandler calling handler at 0x40070d60
code=c0000005 flags=2
0806d398:trace:seh:EXC_CallHandler handler returned 1
0806d398:warn:resource:RES_FindResource page fault

This time eip is in pe_resource.c in libntdll.so, the find_entry_by_id
method. The exception is handled by NTDLL.DLL.__wine_exception_handler
in libntdll.so.

Finally, about 2000 lines later, our friend the LoadOEMResource
exception occurs.

So we have three exceptions in a row. The first is apparently
intercepted by the application. The second is generated by trying to
display the message box popped up by the first exception. The third is
generated in LoadOEMResource, *probably* long after the application was
supposed to die from the second exception.

Does your trace show the same thing?

--Rob
Post by Pavel Troller
Hi!
If run under winedbg, my app crashes differently than if run
without > it.
Post by Pavel Troller
It crashes very soon, probably not in LoadOEMResource.
It's wrong that I can't C&P from the winedbg window, I would paste
the register and
Post by Pavel Troller
stack dumps.
However, it's a page fault on read access to 0x000001f4 in 32bit code,
there are 5 stack entries, the last two in
USER32.DLL.GetTaskmanWindow > (in libuser32.so)
Post by Pavel Troller
The offending instruction is movl 0x1f4(%eax),%ebx and eax is 0x0,
which explains the
Post by Pavel Troller
fault address. I didn't compile with debugging on so I can't supply
the source code
Post by Pavel Troller
fragment which makes the crash :-(.
With regards, Pavel
Pavel Troller
2005-08-30 22:38:52 UTC
Permalink
Post by Robert Baruch
Hi Pavel,
Right, my app also crashes in a different place under winedbg, although
it crashes in the same winedbg place under gdb.
I took a closer look at wine --winver nt40 --debugmsg +all.
I found something interesting. If I search for queue_exception, I find
that there is an exception raised before the LoadOEMCall, about
My first exception comes about 74k lines and it looks like
0806ea10:Call kernel32.VirtualFree(41428000,00004000,00004000) ret=004016fb
0806ea10:trace:virtual:VirtualFree 0x41428000 00004000 4000
0806ea10:trace:virtual:VIRTUAL_SetProt 0x41428000-0x4142bfff -----
View: 0x41420000 - 0x4151ffff (valloc)
0x41420000 - 0x41427fff c-rW-
0x41428000 - 0x4151ffff -----
0806ea10:Ret kernel32.VirtualFree() retval=00000001 ret=004016fb
0806ea10:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806ea10: queue_exception_event( first=1, record={context={flags=00000000,eax=00000000,ebx=414243b0,ecx=004464f8,edx=41426424,esi=414243b0,edi=00000000,ebp=405e5c54,eip=00462533,esp=405e5bd4,eflags=00010246,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,float={00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x462533,params={0,1f4}} )
0806ea10: queue_exception_event() = 0 { handle=0 }
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x46257b code=c0000005 flags=0
0806ea10:Call user32.LoadStringA(00400000,0000ffd3,404d4358,00000400) ret=00404c19
0806ea10:trace:resource:LoadStringA instance = 400000, id = ffd3, buffer = 404d4358, length = 1024
0806ea10:trace:heap:HeapAlloc (40390000,00000002,00000800): returning 403fd838
0806ea10:trace:resource:LoadStringW instance = 400000, id = ffd3, buffer = 403fd838, length = 1024
0806ea10:trace:resource:RES_FindResource2 (00400000, 00000006, 00000ffe, 0000, W, PE)
0806ea10:trace:resource:RES_LoadResource (00400000, 00472ac0, PE)
0806ea10:trace:resource:LockResource (00476b48)
0806ea10:trace:resource:LoadStringW strlen = 4
0806ea10:trace:resource:LoadStringW L"Read" loaded !
0806ea10:trace:resource:LoadStringA "Read" loaded !
0806ea10:trace:heap:HeapFree (40390000,00000002,403fd838): returning TRUE
0806ea10:Ret user32.LoadStringA() retval=00000004 ret=00404c19
0806ea10:Call kernel32.VirtualQuery(00462533,404d48c0,0000001c) ret=0040a6e8
0806ea10:Ret kernel32.VirtualQuery() retval=0000001c ret=0040a6e8
0806ea10:Call kernel32.GetModuleFileNameA(00400000,404d47bb,00000105) ret=0040a70a
0806ea10:trace:string:lstrcpynA (0x404d47bb, "D:\\setup.exe", 261)
0806ea10:trace:module:GetModuleFileNameA D:\setup.exe
0806ea10:Call user32.LoadStringA(00400000,0000ffdf,404d4350,00000400) ret=00404c19
0806ea10:trace:resource:LoadStringA instance = 400000, id = ffdf, buffer = 404d4350, length = 1024
0806ea10:trace:heap:HeapAlloc (40390000,00000002,00000800): returning 403fd838
0806ea10:trace:resource:LoadStringW instance = 400000, id = ffdf, buffer = 403fd838, length = 1024
0806ea10:trace:resource:RES_FindResource2 (00400000, 00000006, 00000ffe, 0000, W, PE)
0806ea10:trace:resource:RES_LoadResource (00400000, 00472ac0, PE)
0806ea10:trace:resource:LockResource (00476b48)
0806ea10:trace:resource:LoadStringW strlen = 63
0806ea10:trace:resource:LoadStringW L"Access violation at address %p in module '%s'. %s of address %p" loaded !
0806ea10:trace:resource:LoadStringA "Access violation at address %p in module '%s'. %s of address %p" loaded !
0806ea10:trace:heap:HeapFree (40390000,00000002,403fd838): returning TRUE
0806ea10:Ret user32.LoadStringA() retval=0000003f ret=00404c19

The program catches it and tries to inform the user that something wrong happened.
My second one is about 2500 lines later:

0806ea10:Call ntdll.RtlLeaveCriticalSection(004665e8) ret=00419d5a
0806ea10:Ret ntdll.RtlLeaveCriticalSection() retval=00000000 ret=00419d5a
0806ea10:trace:seh:EXC_RtlRaiseException code=c0000005 flags=0
0806ea10: queue_exception_event( first=1, record={context={flags=00000000,eax=00000000,ebx=00462580,ecx=00413358,edx=41424394,esi=400fcd5d,edi=405e5bd4,ebp=405e5c54,eip=00462808,esp=405e5bec,eflags=00010246,cs=0023,ds=002b,es=002b,fs=008f,gs=0000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,float={00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000}},rec={code=c0000005,flags=0,rec=(nil),addr=0x462808,params={0,284}} )
0806ea10: queue_exception_event() = 0 { handle=0 }
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x462c68 code=c0000005 flags=0
0806ea10:trace:seh:EXC_CallHandler handler returned 1
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x41f723 code=c0000005 flags=0
0806ea10:trace:seh:EXC_CallHandler handler returned 1
0806ea10:trace:seh:EXC_CallHandler calling handler at 0x41f734 code=c0000005 flags=0
0806ea10:Call user32.LoadStringA(00400000,0000ffd3,404d4358,00000400) ret=00404c19
0806ea10:trace:resource:LoadStringA instance = 400000, id = ffd3, buffer = 404d4358, length = 1024
0806ea10:trace:heap:HeapAlloc (40390000,00000002,00000800): returning 403f9898
0806ea10:trace:resource:LoadStringW instance = 400000, id = ffd3, buffer = 403f9898, length = 1024
0806ea10:trace:resource:RES_FindResource2 (00400000, 00000006, 00000ffe, 0000, W, PE)
0806ea10:trace:resource:RES_LoadResource (00400000, 00472ac0, PE)
0806ea10:trace:resource:LockResource (00476b48)
0806ea10:trace:resource:LoadStringW strlen = 4
0806ea10:trace:resource:LoadStringW L"Read" loaded !
0806ea10:trace:resource:LoadStringA "Read" loaded !
0806ea10:trace:heap:HeapFree (40390000,00000002,403f9898): returning TRUE
0806ea10:Ret user32.LoadStringA() retval=00000004 ret=00404c19
0806ea10:Call kernel32.VirtualQuery(00462808,404d48c0,0000001c) ret=0040a6e8
0806ea10:Ret kernel32.VirtualQuery() retval=0000001c ret=0040a6e8
0806ea10:Call kernel32.GetModuleFileNameA(00400000,404d47bb,00000105) ret=0040a70a
0806ea10:trace:string:lstrcpynA (0x404d47bb, "D:\\setup.exe", 261)
0806ea10:trace:module:GetModuleFileNameA D:\setup.exe
0806ea10:Ret kernel32.GetModuleFileNameA() retval=0000000c ret=0040a70a
0806ea10:Call user32.LoadStringA(00400000,0000ffdf,404d4350,00000400) ret=00404c19
0806ea10:trace:resource:LoadStringA instance = 400000, id = ffdf, buffer = 404d4350, length = 1024
0806ea10:trace:heap:HeapAlloc (40390000,00000002,00000800): returning 403f9898
0806ea10:trace:resource:LoadStringW instance = 400000, id = ffdf, buffer = 403f9898, length = 1024
0806ea10:trace:resource:RES_FindResource2 (00400000, 00000006, 00000ffe, 0000, W, PE)
0806ea10:trace:resource:RES_LoadResource (00400000, 00472ac0, PE)
0806ea10:trace:resource:LockResource (00476b48)
0806ea10:trace:resource:LoadStringW strlen = 63
0806ea10:trace:resource:LoadStringW L"Access violation at address %p in module '%s'. %s of address %p" loaded !
0806ea10:trace:resource:LoadStringA "Access violation at address %p in module '%s'. %s of address %p" loaded !
0806ea10:trace:heap:HeapFree (40390000,00000002,403f9898): returning TRUE
0806ea10:Ret user32.LoadStringA() retval=0000003f ret=00404c19

It looks very similar to the previous one...
Post by Robert Baruch
Finally, about 2000 lines later, our friend the LoadOEMResource
exception occurs.
Here too, but after the LoadOEMResource there comes many many many
recursive exceptions until the hard segfault (out of stack ?)
Post by Robert Baruch
So we have three exceptions in a row. The first is apparently
intercepted by the application. The second is generated by trying to
display the message box popped up by the first exception. The third is
generated in LoadOEMResource, *probably* long after the application was
supposed to die from the second exception.
Does your trace show the same thing?
So, in principle, the same opera but different actors :-) It seems to me that
the app crashes when it tries to open its window, so it wants to report it
but crashes again when it tries to open the popup and also catches it and tries
to report it... Then it catches an exception in LoadOEMResource and it's
so much out of order that it catches new exceptions just in the beginning
of exception handling and this probably exhausts the stack up to the final
hard segfault.
With regards, Pavel
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
More information on exception #2. The offending function is:

/**********************************************************************
* find_entry_by_id
*
* Find an entry by id in a resource directory
*/
static const IMAGE_RESOURCE_DIRECTORY *find_entry_by_id( const
IMAGE_RESOURCE_DIRECTORY *dir,
WORD id, const
void *root )
{
const IMAGE_RESOURCE_DIRECTORY_ENTRY *entry;
int min, max, pos;

entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);
min = dir->NumberOfNamedEntries;
max = min + dir->NumberOfIdEntries - 1;
while (min <= max)
{
pos = (min + max) / 2;
if (entry[pos].u1.s2.Id == id)
return (IMAGE_RESOURCE_DIRECTORY *)((char *)root +
entry[pos].u2.s3.OffsetToDirectory);
if (entry[pos].u1.s2.Id > id) max = pos - 1;
else min = pos + 1;
}
return NULL;
}


Where the offending line is

min = dir->NumberOfNamedEntries;

It looks like the call was made with dir = 0x0045F000, id = 0xE, and I'm
not sure about root.

Probably find_entry_by_id was called from either PE_FindResourceW or
PE_FindResourceExW, possibly through find_entry_by_nameW, which was
called by RES_FindResource2, which is the last trace before the exception.

If I could get winedbg/gdb to continue past the first exception but stop
at the second, I might be able to find out more :(

--Rob
lawson_whitney at juno.com ()
2005-08-30 22:38:52 UTC
Permalink
Post by Robert Baruch
If I could get winedbg/gdb to continue past the first exception but stop
at the second, I might be able to find out more :(
--Rob
Is it a first chance exception? Tried pass? IIRC, wine does not stop
on it, but winedbg does, so that is what it would be in the best of all
possible worlds.

Lawson

Constants aren't, and variables won't.
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Hooray, I got gdb to do what I need, to skip the first exception and
break before the second.

The key commands are:

gdb (winepath)/bin/wine
set args --winver nt40 yourapp
handle SIGSEGV nostop pass
b main
run
This loads all the shared libraries, and now we can set more breakpoints
in those libraries. Set a breakpoint where wine handles exceptions, and
break EXC_RtlRaiseException
cont
Now the first exception should be hit. We continue again to hit the
cont
And now I have a trace where the second exception will be called:

Continuing.

Program received signal SIGSEGV, Segmentation fault.

Breakpoint 3, EXC_RtlRaiseException (rec=0x404f3c60, context=0x404f3cdc)
at exception.c:176
176 TRACE( "code=%lx flags=%lx\n", rec->ExceptionCode,
rec->ExceptionFlags );
(gdb) where
#0 EXC_RtlRaiseException (rec=0x404f3c60, context=0x404f3cdc) at
exception.c:176
#1 0x40076748 in do_segv (context=0x404f3cdc, trap_code=14,
cr2=0x45f00c, err_code=4)
at signal_i386.c:711
#2 0x40076ada in segv_handler (__signal=11, __context=
{sc_gs = 0, __gsh = 0, sc_fs = 143, __fsh = 0, sc_es = 43, __esh
= 0, sc_ds = 43, __dsh = 0, sc_edi = 4583440, sc_esi = 4583424, sc_ebp =
1078935716, sc_esp = 1078935700, sc_ebx = 1074829380, sc_edx = 4583424,
sc_ecx = 3117568, sc_eax = 14, sc_trapno = 14, sc_err = 4, sc_eip =
1074344288, sc_cs = 35, __csh = 0, sc_eflags = 66050, esp_at_signal =
1078935700, sc_ss = 43, __ssh = 0, i387 = 0, oldmask = 0, cr2 =
4583436}) at signal_i386.c:882
#3 <signal handler called>
#4 find_entry_by_id (dir=0x45f000, id=14, root=0x45f000) at
pe_resource.c:83
#5 0x4009322e in find_entry_by_nameW (dir=0x45f000, name=0xe,
root=0x45f000)
at pe_resource.c:115
#6 0x400934b4 in PE_FindResourceW (hmod=4194304, name=0x4074c30e, type=0xe)
at pe_resource.c:239
#7 0x40094083 in RES_FindResource2 (hModule=4194304, type=0xe "",
name=0x4074c30e "",
lang=0, bUnicode=1, bRet16=0) at resource.c:197
#8 0x40093f4d in RES_FindResource2 (hModule=182, type=0xe "",
name=0x4074c30e "", lang=0,
bUnicode=1, bRet16=0) at resource.c:171
#9 0x40094140 in RES_FindResource (hModule=182, type=0xe "",
name=0x4074c30e "", lang=0,
bUnicode=1, bRet16=0) at resource.c:220
#10 0x40094453 in FindResourceW (hModule=182, name=0x4074c30e, type=0xe)
at resource.c:360
#11 0x40718664 in CURSORICON_Load (hInstance=182, name=0x4074c30e,
width=32, height=32,
colors=256, fCursor=0, loadflags=32832) at cursoricon.c:735
#12 0x4071ade0 in LoadImageW (hinst=4194304, name=0x4074c30e, type=1,
desiredx=32,
desiredy=0, loadflags=32832) at cursoricon.c:2261
#13 0x4071a086 in LoadIconW (hInstance=4194304, name=0x4074c30e) at
cursoricon.c:1765
#14 0x4070ff55 in STATIC_LoadIconW (hwnd=65570, name=0x4074c30e) at
static.c:146
#15 0x40710278 in StaticWndProc_common (hwnd=65570, uMsg=129, wParam=0,
lParam=1078937708,
unicode=1) at static.c:254
#16 0x407104b1 in StaticWndProcW (hWnd=65570, uMsg=129, wParam=0,
lParam=1078937708)
at static.c:347
#17 0x4074070b in WINPROC_wrapper () at winproc.c:120
#18 0x40740796 in WINPROC_CallWndProc (proc=0x4071047c <StaticWndProcW>,
hwnd=65570, msg=129,
wParam=0, lParam=1078937708) at winproc.c:173
#19 0x4074635e in CallWindowProcW (func=0x4071047c <StaticWndProcW>,
hwnd=65570, msg=129,
wParam=0, lParam=1078937708) at winproc.c:2659
#20 0x406e6509 in call_window_proc (hwnd=65570, msg=129, wparam=0,
lparam=1078937708,
unicode=1) at message.c:1141
#21 0x406e700a in SendMessageTimeoutW (hwnd=65570, msg=129, wparam=0,
lparam=1078937708,
flags=0, timeout=4294967295, res_ptr=0x404f4540) at message.c:1529
#22 0x406e7277 in SendMessageW (hwnd=65570, msg=129, wparam=0,
lparam=1078937708)
at message.c:1610
#23 0x40b1b62e in X11DRV_CreateWindow (hwnd=65570, cs=0x404f486c,
unicode=1) at window.c:882
#24 0x4073abec in WIN_CreateWindowEx (cs=0x404f486c, classAtom=49159,
type=WIN_PROC_32W)
at win.c:1177
#25 0x4073b154 in CreateWindowExW (exStyle=4, className=0x4074e8e8,
windowName=0x4074c30e,
style=1342177283, x=16, y=40, width=32, height=32, parent=65569,
menu=1088,
instance=4194304, data=0x0) at win.c:1392
#26 0x4071ed0c in DIALOG_CreateControls (hwnd=65569, template=0x4074c314 "",
dlgTemplate=0x404f4958, hInst=0, win32=1) at dialog.c:487
#27 0x4071f891 in DIALOG_CreateIndirect (hInst=0, dlgTemplate=0x4074c2f8
"\003", owner=0,
dlgProc=0x4072bae0 <MSGBOX_DlgProc>, param=1078938108,
procType=WIN_PROC_32A, modal=1)
at dialog.c:874
#28 0x4071ffb5 in DialogBoxIndirectParamA (hInstance=0,
template=0x4074c2e0, owner=0,
dlgProc=0x4072bae0 <MSGBOX_DlgProc>, param=1078938108) at dialog.c:1189
#29 0x4072bc2f in MessageBoxA (hWnd=0,
text=0x75d4e0 "C:\\My Documents\\power-structure-demo.exe (3.4)
12/08/01 18:31:47 - Dispatcher initialisation error trapping
exceptions", title=0x75b3e8 "SHRINKER.ERR", type=8240)
at msgbox.c:294
#30 0x0075fc1a in ?? ()
#31 0x007604e6 in ?? ()
#32 0x6f442079 in ?? ()
Cannot access memory at address 0x4d5c3a43
(gdb)


That's pretty cool. So the second exception gets thrown while the
program is trying to pop up the message box caused by the first
exception. I can crawl up the stack trace to list out the line that the
exception occurs:

(gdb) up
#1 0x40076748 in do_segv (context=0x404f3cdc, trap_code=14,
cr2=0x45f00c, err_code=4)
at signal_i386.c:711
711 EXC_RtlRaiseException( &rec, context );
(gdb) up
#2 0x40076ada in segv_handler (__signal=11, __context=
{sc_gs = 0, __gsh = 0, sc_fs = 143, __fsh = 0, sc_es = 43, __esh
= 0, sc_ds = 43, __dsh = 0, sc_edi = 4583440, sc_esi = 4583424, sc_ebp =
1078935716, sc_esp = 1078935700, sc_ebx = 1074829380, sc_edx = 4583424,
sc_ecx = 3117568, sc_eax = 14, sc_trapno = 14, sc_err = 4, sc_eip =
1074344288, sc_cs = 35, __csh = 0, sc_eflags = 66050, esp_at_signal =
1078935700, sc_ss = 43, __ssh = 0, i387 = 0, oldmask = 0, cr2 =
4583436}) at signal_i386.c:882
882 get_cr2_value(HANDLER_CONTEXT),
get_error_code(HANDLER_CONTEXT) );
(gdb) up
#3 <signal handler called>
(gdb) up
#4 find_entry_by_id (dir=0x45f000, id=14, root=0x45f000) at
pe_resource.c:83
83 min = dir->NumberOfNamedEntries;
(gdb)


That's what I thought in the first place. I'll try to print out dir:

(gdb) p dir
$14 = (IMAGE_RESOURCE_DIRECTORY *) 0xc0000005


Huh? The stack trace says the argument is 0x45f000, not 0xc0000005.

So I'll re-run the program, but this time I'll add a breakpoint at
pe_resource.c:find_entry_by_id (just entering "find_entry_by_id" results
in gdb setting the breakpoint in a file other than pe_resource):

(gdb) run
The program being debugged has been started already.
Start it from the beginning? (y or n) y

Starting program: /usr/local/wine/bin/wine --winver nt40
"/home/baruch/wine-c/My Documents/power-structure-demo.exe"

Program received signal SIGSEGV, Segmentation fault.

Breakpoint 3, EXC_RtlRaiseException (rec=0x404f4bc8, context=0x404f4c44)
at exception.c:176
176 TRACE( "code=%lx flags=%lx\n", rec->ExceptionCode,
rec->ExceptionFlags );
(gdb) break pe_resource.c:find_entry_by_id
Breakpoint 7 at 0x40093156: file pe_resource.c, line 82.
(gdb) cont
Continuing.

Breakpoint 7, find_entry_by_id (dir=0x40768240, id=0, root=0x40768240)
at pe_resource.c:82
82 entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);
(gdb)
Continuing.

Breakpoint 7, find_entry_by_id (dir=0x40768790, id=16393,
root=0x40768240) at pe_resource.c:82
82 entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);
(gdb)
Continuing.

Breakpoint 7, find_entry_by_id (dir=0x40768790, id=0, root=0x40768240)
at pe_resource.c:82
82 entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);
(gdb)
Continuing.

Breakpoint 7, find_entry_by_id (dir=0x40768790, id=1024,
root=0x40768240) at pe_resource.c:82
82 entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);
(gdb)
Continuing.

Breakpoint 7, find_entry_by_id (dir=0x45f000, id=0, root=0x45f000) at
pe_resource.c:82
82 entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);

(gdb) p dir
$16 = (IMAGE_RESOURCE_DIRECTORY *) 0x45f000


Better.

(gdb) p *dir
$17 = {Characteristics = 0, TimeDateStamp = 0, MajorVersion = 0,
MinorVersion = 0,
NumberOfNamedEntries = 0, NumberOfIdEntries = 0}

Hmm. gdb is able to dereference dir. So what's going on?


(gdb) step
78 {
(gdb) step
82 entry = (const IMAGE_RESOURCE_DIRECTORY_ENTRY *)(dir + 1);
(gdb) step
83 min = dir->NumberOfNamedEntries;
(gdb) p dir
$18 = (IMAGE_RESOURCE_DIRECTORY *) 0x45f000

So far so good.


(gdb) step

Program received signal SIGSEGV, Segmentation fault.

Breakpoint 3, EXC_RtlRaiseException (rec=0x404f3c60, context=0x404f3cdc)
at exception.c:176
176 TRACE( "code=%lx flags=%lx\n", rec->ExceptionCode,
rec->ExceptionFlags );


What the #&@*#?!

Looking at the assembly listing for find_entry_by_id, I can see that dir
is stored in edx, and that edx contains 0xc0000005 at the time the
signal handler breaks. So maybe that explains why gdb reported dir as
0xc0000005:

(gdb) info scope pe_resource.c:find_entry_by_id
Scope for pe_resource.c:find_entry_by_id:
Symbol dir is an argument at stack/frame offset 8, length 4.
Symbol id is an argument at stack/frame offset 12, length 4.
Symbol root is an argument at stack/frame offset 16, length 4.
Symbol dir is a local variable in register $edx, length 4.
Symbol id is a local variable at frame offset -14, length 2.
Symbol entry is a local variable at frame offset -12, length 4.
Symbol min is a local variable in register $ecx, length 4.
Symbol max is a local variable in register $esi, length 4.
Symbol pos is a local variable in register $eax, length 4.


So for some reason gdb duplicates the arguments as local variables, and
then uses the local variable reference to print arguments :P Maybe this
is the general optimized-code-trace problem.

Anyway, we still haven't explained why the segfault in the first place!

At this point I'm out of ideas. Why would gdb be able to deference dir
manually, but generate a segfault when running that line?

--Rob
gerard patel
2005-08-30 22:38:52 UTC
Permalink
On Sat, 08 Dec 2001 19:52:40 -0500, Robert Baruch
<***@starband.net> wrote:

<snip>
Post by Robert Baruch
(gdb) p dir
$14 = (IMAGE_RESOURCE_DIRECTORY *) 0xc0000005
Huh? The stack trace says the argument is 0x45f000, not 0xc0000005.
<snip>

FYI Win32 uses a structure to control exception handling,
structure including a code tagging the exception type.
0xc0000005 is the code that Win32 exception handling uses
for a memory access violation.

[***@duron wine]$ cd include/
[***@duron include]$ grep -i c0000005 *.h
winnt.h:#define STATUS_ACCESS_VIOLATION 0xC0000005

Gerard

Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Hmm. I'm just throwing this out there. Maybe the problem will always
happen when the application wants to catch an exception but wine catches
it instead, and then some internal data structures get trashed when the
app resumes?

--Rob
Robert Baruch
2005-08-30 22:38:52 UTC
Permalink
Oh, I think I see now. There was a call to VIRTUAL_SetProt, which
protected memory mapped regions of memory, before the first exception:

0806d398:trace:virtual:VIRTUAL_SetProt 0x459000-0x459fff c-r--
View: 0x400000 - 0x765fff 28
0x400000 - 0x400fff c-r--
0x401000 - 0x458fff c----
0x459000 - 0x459fff c-r--
0x45a000 - 0x758fff c----
0x759000 - 0x765fff c-rw-

And address 0x45f000 is inside of a c---- segment. So I think maybe
that's why the second exception gets thrown when we attempt to read from
that address. I guess gdb somehow is able to ignore the protections, or
maybe doesn't handle mapped memory well.

So does wine need to be fixed? Is this a wacky Microsoft bug, where
Linux really pays attention to protections and Windows doesn't?

Well, there's still that original exception to look at...

--Rob
Loading...