I'm trying to run Autocad 2004. (installation from cd "works")
current status: (/blog) http://wiki.jswindle.com/index.php/AutoCad#Forum_Comments
It starts a long way, and wine seems to handle the usual CreateFileA("\\.\NTICE") and IsDebuggerPresent() properly, and it generates and runs some dll's in the temp directory. But the program exists without any waring or error. I'm still searching for the reason, but i have several clues.
But today the log files are shorter, the above calls are missing, and instead I get an c0000119 error (STATUS_INVALID_LDT_OFFSET)
200135:0011: read_process_memory() = 0 { data={00,00,00,00} } 200136:0011: get_handle_fd( handle=0xc, access=00000002 ) 200137:0011: get_handle_fd() = 0 { fd=9, removable=0, flags=0 } 200138:0x4074fc00: 00000000 00000000 00000000 00000000 200139:0011: get_selector_entry( handle=0x2c, entry=7 ) 200140:000f: *signal* signal=19 200141:0011: get_selector_entry() = 0 { base=00000000, limit=00000000, flags=00 } 200142:fixme:ntdll:RtlNtStatusToDosErrorNoTeb no mapping for c0000119 200143:0011: get_handle_fd( handle=0xc, access=00000002 ) 200144:0011: get_handle_fd() = 0 { fd=9, removable=0, flags=0 } 200145:Backtrace: 200146:0011: get_handle_fd( handle=0xc, access=00000002 ) 200147:0011: get_handle_fd() = 0 { fd=9, removable=0, flags=0 } 200148:=>1 0xffffe002 (0xffffe002) 200149:0009:Ret ntdll.NtDelayExecution() retval=00000000 ret=4037416a 200150:0009:Ret kernel32.Sleep() retval=00000000 ret=408fc345 200151:0009:Call ntdll.NtQuerySystemInformation(0000000b,00000000,00000000,4072ef3c) ret=408fc296
I don't have any "+all" log files from yesterday, but I'm sure there was no "fixme" then.
Is Wine actually simulating the LDT stuff ?
I think I should try with a fresh install.
On Fri, 23 Jun 2006 14:13:18 +0200, Jaap Stolk wrote:
200145:Backtrace:
Hmm seems like you are seeing a mixed debugger/app trace there ... gotta be careful of that!
On 6/23/06, Mike Hearn mike@plan99.net wrote:
On Fri, 23 Jun 2006 14:13:18 +0200, Jaap Stolk wrote:
200145:Backtrace:
Hmm seems like you are seeing a mixed debugger/app trace there ... gotta be careful of that!
Ah, yes that's it. it seems one of the threads is bailing out somewhere. further up in he log: the *signal* starts:
198468:0011: get_key_value() = OBJECT_NAME_NOT_FOUND { type=-1, total=0, data={} } 198469:0011: close_handle( handle=0x28 ) 198470:0011: close_handle() = 0 { fd=-1 } 198471:0011: set_console_input_info( handle=(nil), mask=2, active_sb=(nil), history_mode=0, history_size=0, edition_mode=0, title=L"Wine Debugger" ) 198472:0011: set_console_input_info() = INVALID_PARAMETER 198473:0011: debug_process( pid=000e, attach=1 ) 198474:000f: *signal* signal=10 198475:000f: *signal* signal=19 198476:0011: debug_process() = 0 198477:000f: set_thread_context( handle=0xfffffffe, flags=00010007, suspend=1, context={flags=0001001f,eax=00000003,ebx=00000007,ecx=4074efc0,edx=00000008,esi=400321d4,edi=4074efc0,ebp=4074efd8,eip=ffffe000,esp=4074ef94,eflags=00000246,cs=0023,ds=002b,es=002b,fs=003b,gs=0033,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00000000,dr7=00000000,float={ffff037f,ffff0120,ffffffff,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,22a00000,401d8e7c,00000120}} ) 198478:000f: set_thread_context() = 0 { self=1 }
still wondering why it didn't do that yesterday.
I think i found the cause further up in the log.
178591:000f:Starting process L"c:\windows\system32\ntoskrnl.exe" ... 178596:wine_dbg_vprintf: debugstr buffer overflow (contents: '000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 20 ') 178597:000f:trace:seh:raise_exception code=80000101 flags=1 addr=0xffffe002 ...
I will look into it some more.
ExAllocatePoolWithTag( ) function in the file ntoskrnl_api.c :
I changed: WINE_TRACE("(%d %ld %.4s), semi-stub\n", PoolType, NumberOfBytes, (char*)&Tag); to: WINE_TRACE("(%d %ld %4s), semi-stub\n", PoolType, NumberOfBytes, (char*)&Tag);
Don't know how decimals are supposed to work with a string, but it didn't work for me.
Friday, June 23, 2006, 9:47:01 AM, Jaap Stolk wrote:
ExAllocatePoolWithTag( ) function in the file ntoskrnl_api.c :
I changed: WINE_TRACE("(%d %ld %.4s), semi-stub\n", PoolType, NumberOfBytes, (char*)&Tag); to: WINE_TRACE("(%d %ld %4s), semi-stub\n", PoolType, NumberOfBytes, (char*)&Tag);
Don't know how decimals are supposed to work with a string, but it didn't work for me.
You can ignore tag altogether. It's only enabled with a special registry key (on windows). And drivers have no way nor need to verify the tag. So I think you can just remove that trace. I will need to think something to stop of from crashing. Or try using wine_dbgstr_a((char*)&Tag) instead.
PS: I wasn't sure if you were using my ntoskrnl implementation or not. If you are then could you post somewhere +ntoskrnl trace? That might be helpful. Also it could be number of other things that this driver tries to do that ntoskrnl has not implementation for.
Vitaliy.
On 6/24/06, Vitaliy Margolen wine-devel@kievinfo.com wrote:
You can ignore tag altogether. It's only enabled with a special registry key (on windows). And drivers have no way nor need to verify the tag. So I think you can just remove that trace. I will need to think something to stop of from crashing. Or try using wine_dbgstr_a((char*)&Tag) instead.
ok. I have not made a real patch, but but if it pops up again i may try that.
PS: I wasn't sure if you were using my ntoskrnl implementation or not.
yes. I'm using: http://www.winehq.com/pipermail/wine-devel/2006-June/048583.html
If you are then could you post somewhere +ntoskrnl trace? That might be helpful. Also it could be number of other things that this driver tries to do that ntoskrnl has not implementation for.
It seems to work ok with autocad 2004. I think the problems are more in the safedisc itself.
I have the +all log: (16 MB) $ grep -i ':ntoskrnl:' all_log.txt 163439:0009:trace:ntoskrnl:NTOSKRNL_connect Connecting to ntoskrnl 163444:0009:trace:ntoskrnl:NTOSKRNL_connect Trying to start ntoskrnl 178596:wine_dbg_vprintf: debugstr buffer overflow (contents: '000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 20 ') 200646:0009:trace:ntoskrnl:NTOSKRNL_connect Connecting to ntoskrnl
I just noticed, after my "fix" the there are no ntoskrnl traces in the +all log. so my fix was preventing the error by crashing ntoskrnl :-(
here is the log after remofing the tag altogether: (I had to ctrl-c wine, autocad did not shutdown by itself, so I think things are improving.)
$ grep -i ':ntoskrnl:' all_log_no_tag.txt 000f:trace:ntoskrnl:ExAllocatePoolWithTag (1 16 <tag>), semi-stub 000f:trace:ntoskrnl:ExFreePool (0x401fcc18) 000f:trace:ntoskrnl:ExAllocatePoolWithTag (1 94 <tag>), semi-stub 000f:trace:ntoskrnl:ExFreePool (0x4020d220) 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 168 <tag>), semi-stub 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 20 <tag>), semi-stub 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 120 <tag>), semi-stub 000f:trace:ntoskrnl:IoCreateDevice (0x4020d220, 0, L"\Device\CdaC17BA", 51712, 0, 0, 0x407523a0) 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 24 <tag>), semi-stub 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 184 <tag>), semi-stub 000f:trace:ntoskrnl:IoCreateDevice Created device with handel 0x28 000f:trace:ntoskrnl:IoCreateSymbolicLink (L"\DosDevices\CdaC17BA" -> L"\Device\CdaC17BA") 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 24 <tag>), semi-stub 000f:trace:ntoskrnl:ExAllocatePoolWithTag (1 36 <tag>), semi-stub 000f:trace:ntoskrnl:IoCreateDevice (0x4020d220, 0, L"\Device\CdaC15BA", 61184, 0, 0, 0x40752140) 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 24 <tag>), semi-stub 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 184 <tag>), semi-stub 000f:trace:ntoskrnl:IoCreateDevice Created device with handel 0x34 000f:trace:ntoskrnl:IoCreateSymbolicLink (L"\DosDevices\CdaC15BA" -> L"\Device\CdaC15BA") 000f:trace:ntoskrnl:ExAllocatePoolWithTag (0 24 <tag>), semi-stub 000f:trace:ntoskrnl:driver_control returned from call with status 00000000
does "semi-stub" mean that this call is not fully implemented ?
Jaap.
On 6/24/06, Jaap Stolk jwstolk@gmail.com wrote:
here is the log after remofing the tag altogether: (I had to ctrl-c wine, autocad did not shutdown by itself, so I think things are improving.)
$ grep -i ':ntoskrnl:' all_log_no_tag.txt 000f:trace:ntoskrnl:ExAllocatePoolWithTag (1 16 <tag>), semi-stub 000f:trace:ntoskrnl:ExFreePool (0x401fcc18)
It looks like something is randomly failing here. I just created a new +all log file, but this time there is no reference to ntoskrnl at all. I'm going to run a full memory check just to rule things out :-)
found another one :-) I reconstructed the debug output mixed with the wine log:
------------------------------------ Unhandled exception: page fault on read access to 0x00000000 in 32-bit code (0x4062de4e). Register dump: CS:0023 SS:002b DS:002b ES:002b FS:003b GS:0033 EIP:4062de4e ESP:4074fc2c EBP:4074fe08 EFLAGS:00010212( - 00 - RIA1) EAX:4062de4c EBX:4063c8c4 ECX:400d03e8 EDX:0000004b ESI:4074fd81 EDI:00000000 Stack dump: 0x4074fc2c: 40622e4a 00000020 4074fd80 00000078 0x4074fc3c: 00000000 400d040f 400d042d 400d07e7 0x4074fc4c: 00000078 400d07e7 4063c940 00000020 0x4074fc5c: 083c7748 00000000 00ff4007 401fcb80 0x4074fc6c: 401fcac0 00000000 00000000 00000000 0x4074fc7c: 00000000 00000000 00000000 00000000 Backtrace: =>1 0x4062de4e ImagePath+0x4fc in ntoskrnl (0x4062de4e) 2 0x406226c9 __wine_spec_exe_entry+0x12d(peb=0x400d0800) [/home/jaap/wine-git/programs/ntoskrnl/../../include/wine/list.h:132] in ntoskrnl (0x406226c9) 3 0x40374eef start_process+0x11b(arg=0x0) [/home/jaap/wine-git/dlls/kernel/process.c:832] in kernel32 (0x40374eef) 4 0x4001c233 wine_switch_to_stack+0x17 in libwine.so.1 (0x4001c233) 0x4062de4e ImagePath+0x4fc in ntoskrnl: imull $0x20642528,0x0(%edi),%edx Modules: Module Address Debug info Name (41 modules) <snip> ELF 0x40605000-4063e000 Stabs ntoskrnl<elf> -PE 0x40610000-4063e000 \ ntoskrnl ------------------------------------
I'm not very experienced with Linux debug outputs but I assume "ImagePath+0x4fc" is somewhere after "static const WCHAR ImagePath[]" in ntoskrnl.c
So the problem is somewhere in load_driver( ). Is there a way to narrow it down a bit more?
Jaap.
On 6/24/06, Jaap Stolk jwstolk@gmail.com wrote:
So the problem is somewhere in load_driver( ). Is there a way to narrow it down a bit more?
using objdump I got a bit closer. (note that the exact error address my not be consistent, because I added some more trace functions to the code while testing)
objdump ntoskrnl.exe.so -S > tmp.txt ImagePath -> 0x1d7fa 0x1d7fa + 0x4fc = 0x1DCF6 0x1DCF6 -> static NTSTATUS driver_control(void)
also, combining the load address and the error location ends up somewhere there: 0x4062de4e - 0x40610000 = 0x1DE4E
1de21: 83 ec 0c sub $0xc,%esp 1de24: 52 push %edx 1de25: 8d 83 9c 02 ff ff lea 0xffff029c(%ebx),%eax 1de2b: 50 push %eax 1de2c: 8d 83 a4 01 ff ff lea 0xffff01a4(%ebx),%eax 1de32: 50 push %eax 1de33: 8d 83 c8 fe ff ff lea 0xfffffec8(%ebx),%eax 1de39: 50 push %eax 1de3a: 6a 01 push $0x1 1de3c: e8 c7 5f fe ff call 3e08 <_init+0x2c> 1de41: 83 c4 20 add $0x20,%esp 1de44: e9 3d ff ff ff jmp 1dd86 <driver_control+0x1ca> 1de49: 8b 45 b0 mov 0xffffffb0(%ebp),%eax 1de4c: 85 c0 test %eax,%eax
1de4e: 0f 84 1a ff ff ff je 1dd6e <driver_control+0x1b2>
1de54: 83 ec 08 sub $0x8,%esp 1de57: 56 push %esi 1de58: ff b5 50 fe ff ff pushl 0xfffffe50(%ebp) 1de5e: ff d0 call *%eax (it's called form here:) WINE_ERR("DispatchDeviceControl returned %lx\n", irp.IoStatus.Status); 1dd75: 8a 83 c8 fe ff ff mov 0xfffffec8(%ebx),%al 1dd7b: 83 e0 02 and $0x2,%eax 1dd7e: 84 c0 test %al,%al 1dd80: 0f 85 9b 00 00 00 jne 1de21 <driver_control+0x265>
looking at it form an other angle: I get two "raise exception".
The first one is just after user32.SetDeskWallPaper( ). I added the wallpaper patch, but it's still happening. as it happens very early in the log, it does not seem to be a problem.
I think the second one is causing the debugger to start:
000f:Ret ntoskrnl.exe.IoCreateSymbolicLink() retval=00000000 ret=407503ae 000f:trace:ntoskrnl:driver_control returned from call with status 00000000 000f:trace:seh:raise_exception code=c0000096 flags=0 addr=0x4062e04c 000f:trace:seh:raise_exception eax=4062e04c ebx=4063d964 ecx=400d03e8 edx=0000004b esi=4074fd80 edi=00000000 000f:trace:seh:raise_exception ebp=4074fe08 esp=4074fc2c cs=0023 ds=002b es=002b fs=003b gs=0033 flags=00010212 000f:trace:seh:call_stack_handlers calling handler at 0x4033ce80 code=c0000096 flags=0 <snip 13 lines> 000f:Call ntdll.RtlInitAnsiString(4074f5a0,4039d8ed "winedos.dll") ret=403500a0 <snip 22 pages> 000f:trace:module:load_builtin_callback loaded winedos.dll 0x4020d888 0x40760000
from what I could google, code=c0000096 means that a privileged instruction was found. But I don't seen anything exotic at 0x1de4e.
I think this is related: http://bugs.winehq.com/show_bug.cgi?id=3438 but winedos.dll is started after the problem, so i don't think it's causing it.
I'm still not sure how to track the error location to the correct line of source code, I recompiled ntoskrnl with -ggdb, but it already had -g, so it should contain the source line numbers right? How does wine normally handle privileged instruction ? I'm sure the safedisc code uses every privileged instruction it can, and i would not be surprised if it was throwing exceptions as a normal code path, and i suspect some of it's drivers are supposed to run in ring 0 mode.
Saturday, June 24, 2006, 3:18:03 PM, Jaap Stolk wrote:
On 6/24/06, Jaap Stolk jwstolk@gmail.com wrote:
So the problem is somewhere in load_driver( ). Is there a way to narrow it down a bit more?
using objdump I got a bit closer. (note that the exact error address my not be consistent, because I added some more trace functions to the code while testing)
objdump ntoskrnl.exe.so -S > tmp.txt
ImagePath ->> 0x1d7fa
0x1d7fa + 0x4fc = 0x1DCF6
0x1DCF6 ->> static NTSTATUS driver_control(void)
also, combining the load address and the error location ends up somewhere there: 0x4062de4e - 0x40610000 = 0x1DE4E
1de21: 83 ec 0c sub $0xc,%esp 1de24: 52 push %edx 1de25: 8d 83 9c 02 ff ff lea 0xffff029c(%ebx),%eax 1de2b: 50 push %eax 1de2c: 8d 83 a4 01 ff ff lea 0xffff01a4(%ebx),%eax 1de32: 50 push %eax 1de33: 8d 83 c8 fe ff ff lea 0xfffffec8(%ebx),%eax 1de39: 50 push %eax 1de3a: 6a 01 push $0x1 1de3c: e8 c7 5f fe ff call 3e08 <_init+0x2c> 1de41: 83 c4 20 add $0x20,%esp 1de44: e9 3d ff ff ff jmp 1dd86 <driver_control+0x1ca> 1de49: 8b 45 b0 mov 0xffffffb0(%ebp),%eax 1de4c: 85 c0 test %eax,%eax
1de4e: 0f 84 1a ff ff ff je 1dd6e <driver_control+0x1b2>
1de54: 83 ec 08 sub $0x8,%esp 1de57: 56 push %esi 1de58: ff b5 50 fe ff ff pushl 0xfffffe50(%ebp) 1de5e: ff d0 call *%eax (it's called form here:) WINE_ERR("DispatchDeviceControl returned %lx\n", irp.IoStatus.Status); 1dd75: 8a 83 c8 fe ff ff mov 0xfffffec8(%ebx),%al 1dd7b: 83 e0 02 and $0x2,%eax 1dd7e: 84 c0 test %al,%al 1dd80: 0f 85 9b 00 00 00 jne 1de21 <driver_control+0x265>
looking at it form an other angle: I get two "raise exception".
The first one is just after user32.SetDeskWallPaper( ). I added the wallpaper patch, but it's still happening. as it happens very early in the log, it does not seem to be a problem.
I think the second one is causing the debugger to start:
000f:Ret ntoskrnl.exe.IoCreateSymbolicLink() retval=00000000 ret=407503ae 000f:trace:ntoskrnl:driver_control returned from call with status 00000000 000f:trace:seh:raise_exception code=c0000096 flags=0 addr=0x4062e04c 000f:trace:seh:raise_exception eax=4062e04c ebx=4063d964 ecx=400d03e8 edx=0000004b esi=4074fd80 edi=00000000 000f:trace:seh:raise_exception ebp=4074fe08 esp=4074fc2c cs=0023 ds=002b es=002b fs=003b gs=0033 flags=00010212 000f:trace:seh:call_stack_handlers calling handler at 0x4033ce80 code=c0000096 flags=0 <snip 13 lines> 000f:Call ntdll.RtlInitAnsiString(4074f5a0,4039d8ed "winedos.dll") ret=403500a0 <snip 22 pages> 000f:trace:module:load_builtin_callback loaded winedos.dll 0x4020d888 0x40760000
from what I could google, code=c0000096 means that a privileged instruction was found. But I don't seen anything exotic at 0x1de4e.
I think this is related: http://bugs.winehq.com/show_bug.cgi?id=3438 but winedos.dll is started after the problem, so i don't think it's causing it.
I'm still not sure how to track the error location to the correct line of source code, I recompiled ntoskrnl with -ggdb, but it already had -g, so it should contain the source line numbers right? How does wine normally handle privileged instruction ? I'm sure the safedisc code uses every privileged instruction it can, and i would not be surprised if it was throwing exceptions as a normal code path, and i suspect some of it's drivers are supposed to run in ring 0 mode.
It's pretty hard to see what you doing from this pastes. Do you have time to join one of the Wine's IRC channels?
What I see there the driver tries to do soemthing that it thinks could be done running inside the kernel. But we don't run inside the kernel so those instructions do raise exception. Depending on what it's trying to do we should be able to emulate what it needs (if you applied all of my patch, especially the part to kernel/except.c
Vitaliy
On 6/25/06, Vitaliy Margolen wine-devel@kievinfo.com wrote:
It's pretty hard to see what you doing from this pastes. Do you have time to join one of the Wine's IRC channels?
never used that before. I seem to have x-chat. where do i find the correct channel ?
Saturday, June 24, 2006, 4:33:03 PM, Jaap Stolk wrote:
On 6/25/06, Vitaliy Margolen wine-devel@kievinfo.com wrote:
It's pretty hard to see what you doing from this pastes. Do you have time to join one of the Wine's IRC channels?
never used that before. I seem to have x-chat. where do i find the correct channel ?
Jaap Stolk wrote:
from what I could google, code=c0000096 means that a privileged instruction was found.
This is to be expected. DispatchDeviceControl is the function in the driver which handles the IO for the kernel (in this case our fake kernel). If it's a driver it obviously must need to do something that has to be done in ring 0, such as running a privileged instruction. For safedisc, we have some hardware emulation which will run the privileged instructions it needs. What you'll probably have to do is find the instructions the particular driver needs (you can find it in c:\windows\system32\drivers) and emulate it somehow, which may or may not be possible.
Ivan.
On 6/25/06, Ivan Leo Puoti ivanleo@gmail.com wrote:
Jaap Stolk wrote:
from what I could google, code=c0000096 means that a privileged instruction was found.
This is to be expected. DispatchDeviceControl is the function in the driver which handles the IO for the kernel (in this case our fake kernel). If it's a driver it obviously must need to do something that has to be done in ring 0, such as running a privileged instruction. For safedisc, we have some hardware emulation which will run the privileged instructions it needs. What you'll probably have to do is find the instructions the particular driver needs (you can find it in c:\windows\system32\drivers) and emulate it somehow, which may or may not be possible.
Ivan.
Thanks Ivan. I did some IRC with Vitaliy, and he came to the conclusion that the outport() code was probably the result of messed up code/stack, since the program doesn't use any hardware or locks. I will look into it tomorrow.
Jaap.
Thanks Ivan. I did some IRC with Vitaliy, and he came to the conclusion that the outport() code was probably the result of messed up code/stack, since the program doesn't use any hardware or locks. I will look into it tomorrow.
As one other possibility, and I'm not trying to suggest that it's necessarily the case: could the driver want to check if it's indeed running in ring 0 by trying to poke some "safe" port? I know it'd be weird, but since copy protection is insane in itself, who knows . . .
Cheers, Kuba
-
Ivan Leo Puoti -
Jaap Stolk -
Kuba Ober -
Mike Hearn -
Vitaliy Margolen