http://bugs.winehq.org/show_bug.cgi?id=31279
Bug #: 31279 Summary: SafeDisc: driver crashes under certain circumstances Product: Wine Version: 1.5.9 Platform: x86 OS/Version: Mac OS X Status: UNCONFIRMED Severity: normal Priority: P2 Component: ntoskrnl AssignedTo: wine-bugs@winehq.org ReportedBy: cdavis@mymail.mines.edu Classification: Unclassified
I've been testing various old games on my Mac. Quite a few of them need SafeDisc protection. Unfortunately, for some reason, the driver, SECDRV.SYS, keeps crashing under certain circumstances. (Good thing we run drivers in user mode then... ;) This of course renders any games (that meets these certain conditions) unplayable without a crack. Trouble is, I'm not sure exactly what those circumstances are.
Here's what I do know about which games do what:
Age of Empires II: The Age of Kings: driver crashes Age of Empires II: The Conquerors: driver crashes Age of Empires II: The Conquerors (with SECDRV from C&C:YR): driver crashes Age of Empires II: The Age of Kings (with Conquerors installed): driver crashes Age of Empires II: The Age of Kings (with SECDRV from C&C:YR): driver still crashes Command & Conquer 2: Tiberian Sun (with Firestorm expansion): OK (surprisingly); base C&C2 is probably OK, too Command & Conquer: Red Alert 2: won't install at all due to #30155 Command & Conquer: Red Alert 2 (with either workaround from #30155): still won't install because the driver crashes Command & Conquer: Red Alert 2: Yuri's Revenge: OK (but can't install without RA2)
It looks like this actually has nothing to do with the actual version of SafeDisc, but which code paths get hit in the driver. Unfortunately, the driver is, of course, obfuscated with every trick in the book.
I'll attach a log +tid,+relay,+seh,+services,+winedevice,+ntoskrnl from running AoE2 in an otherwise-clean prefix.
http://bugs.winehq.org/show_bug.cgi?id=31279
Charles Davis cdavis@mymail.mines.edu changed:
What |Removed |Added ---------------------------------------------------------------------------- Keywords| |obfuscation
http://bugs.winehq.org/show_bug.cgi?id=31279
--- Comment #1 from Charles Davis cdavis@mymail.mines.edu 2012-07-21 20:48:50 CDT --- Created attachment 41093 --> http://bugs.winehq.org/attachment.cgi?id=41093 Log +tid,+relay,+seh,+services,+winedevice,+ntoskrnl from trying to start AoE2
http://bugs.winehq.org/show_bug.cgi?id=31279
K1773R K1773R@darkgamex.ch changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |K1773R@darkgamex.ch
http://bugs.winehq.org/show_bug.cgi?id=31279
--- Comment #2 from K1773R K1773R@darkgamex.ch 2012-07-22 05:11:34 CDT --- Created attachment 41098 --> http://bugs.winehq.org/attachment.cgi?id=41098 debug info from charles davis
Log +tid,+relay,+seh,+services,+winedevice,+ntoskrnl from trying to start AoE2
ive added it with the XZ mime set unlike u set it as plaintext ;)
greetings
http://bugs.winehq.org/show_bug.cgi?id=31279
--- Comment #3 from K1773R K1773R@darkgamex.ch 2012-07-22 05:13:55 CDT --- btw, pls resubmited the two test results, i messed up sry ;)
http://bugs.winehq.org/show_bug.cgi?id=31279
Anastasius Focht focht@gmx.net changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |focht@gmx.net
--- Comment #4 from Anastasius Focht focht@gmx.net 2012-07-22 08:51:50 CDT --- Hello,
SafeDisc bugs with no version should be avoided. Please run the 'ProtectionID' tool (http://pid.gamecopyworld.com/) to determine the exact SafeDisc version and paste the output of the tool. Example output in bug report: http://bugs.winehq.org/show_bug.cgi?id=27417
I see you already added a custom trace message to logs.
Good one:
--- snip --- 002c:trace:ntoskrnl:process_ioctl ioctl ef002407 device 0x11ad80 in_size 1300 out_size 1552 002c:Call ntdll.NtGetTickCount() ret=404a0e26 002c:Ret ntdll.NtGetTickCount() retval=00002256 ret=404a0e26 002c:Call driver dispatch 0x546328 (device=0x11ad80,irp=0x53f14c) 002c:trace:seh:raise_exception code=c0000005 flags=0 addr=0x54287f ip=0054287f tid=002c 002c:trace:seh:raise_exception info[0]=00000000 002c:trace:seh:raise_exception info[1]=00821008 002c:trace:seh:raise_exception eax=00821008 ebx=404a1f6c ecx=00000000 edx=0053f14c esi=00000000 edi=0011ad80 002c:trace:seh:raise_exception ebp=0053efec esp=0053efac cs=0017 ds=001f es=001f fs=1017 gs=0037 flags=00010202 002c:trace:seh:call_vectored_handlers calling handler at 0x4049db30 code=c0000005 flags=0 002c:trace:seh:call_vectored_handlers handler at 0x4049db30 returned ffffffff 002c:trace:seh:raise_exception code=c0000005 flags=0 addr=0x542884 ip=00542884 tid=002c 002c:trace:seh:raise_exception info[0]=00000000 002c:trace:seh:raise_exception info[1]=00821018 002c:trace:seh:raise_exception eax=00821018 ebx=00000100 ecx=00000000 edx=0053f14c esi=00000000 edi=0011ad80 002c:trace:seh:raise_exception ebp=0053efec esp=0053efac cs=0017 ds=001f es=001f fs=1017 gs=0037 flags=00010206 002c:trace:seh:call_vectored_handlers calling handler at 0x4049db30 code=c0000005 flags=0 002c:trace:seh:call_vectored_handlers handler at 0x4049db30 returned ffffffff 002c:trace:ntoskrnl:__regs_IofCompleteRequest 0x53f14c 0 002c:trace:ntoskrnl:IoCompleteRequest 0x53f14c 0 002c:Ret driver dispatch 0x546328 (device=0x11ad80,irp=0x53f14c) retval=00000000 --- snip ---
Bad one:
--- snip --- 002c:trace:ntoskrnl:process_ioctl ioctl ef002407 device 0x11ad80 in_size 1300 out_size 1552 002c:Call ntdll.NtGetTickCount() ret=404a0e26 002c:Ret ntdll.NtGetTickCount() retval=00002257 ret=404a0e26 002c:Call driver dispatch 0x546328 (device=0x11ad80,irp=0x53f14c) 002c:trace:seh:raise_exception code=c0000005 flags=0 addr=0x54287f ip=0054287f tid=002c 002c:trace:seh:raise_exception info[0]=00000000 002c:trace:seh:raise_exception info[1]=00821008 002c:trace:seh:raise_exception eax=00821008 ebx=404a1f6c ecx=00000000 edx=0053f14c esi=00000000 edi=0011ad80 002c:trace:seh:raise_exception ebp=0053efec esp=0053efac cs=0017 ds=001f es=001f fs=1017 gs=0037 flags=00010202 002c:trace:seh:call_vectored_handlers calling handler at 0x4049db30 code=c0000005 flags=0 002c:err:int:emulate_instruction cannot emulate instruction at 0x54287f: 8b 002c:trace:seh:call_vectored_handlers handler at 0x4049db30 returned 0 002c:trace:seh:call_stack_handlers calling handler at 0x7bc7c450 code=c0000005 flags=0 002c:Call KERNEL32.UnhandledExceptionFilter(0053e548) ret=7bc7c485 wine: Unhandled page fault on read access to 0x00821008 at address 0x54287f (thread 002c), starting debugger... 002c:trace:seh:start_debugger Starting debugger "winedbg --auto 38 84" --- snip ---
Dumping the first 3 opcode bytes using TRACE() in emulate_instruction would certainly help. Please add a trace doing that before the switch:
http://source.winehq.org/git/wine.git/blob/57e4e608dcd73b36f1084e0cfcb7cf092...
Create another +tid,+relay,+seh,+services,+winedevice,+ntoskrnl trace log with patch applied and attach it with correct mime type set.
Regards
http://bugs.winehq.org/show_bug.cgi?id=31279
Charles Davis cdavis@mymail.mines.edu changed:
What |Removed |Added ---------------------------------------------------------------------------- Attachment #41093|0 |1 is obsolete| |
--- Comment #5 from Charles Davis cdavis@mymail.mines.edu 2012-07-22 15:12:08 CDT --- Created attachment 41115 --> http://bugs.winehq.org/attachment.cgi?id=41115 New log with +tid,+relay,+seh,+services,+winedevice,+ntoskrnl,+int from trying to start AoE2
In reply to comment #4:
SafeDisc bugs with no version should be avoided. Please run the 'ProtectionID' tool (http://pid.gamecopyworld.com/) to determine the exact SafeDisc version and paste the output of the tool.
OK. Here's the SafeDisc versions of all the programs I've mentioned:
Command & Conquer: Tiberian Sun -> 1.11.000 C&C: TS Firestorm -> ?? (probably still 1.x) Age of Empires II: The Age of Kings -> 1.50.020 AoE2: The Conquerors -> 1.45.011 (lower than AoK?) C&C: Red Alert 2 -> 2.05.030 C&C: RA2 Yuri's Revenge -> 2.40.010
Dumping the first 3 opcode bytes using TRACE() in emulate_instruction would
certainly help.
Please add a trace doing that before the switch:
http://source.winehq.org/git/wine.git/blob/57e4e608dcd73b36f1084e0cfcb7cf092...
Create another +tid,+relay,+seh,+services,+winedevice,+ntoskrnl trace log with patch applied and attach it with correct mime type set.
Done. I also added a dump of the IOCTL's input buffer, which might help you figure out exactly what SafeDisc was doing before it crashed. (And this time, the compressed log file should have the right MIME type. :)
http://bugs.winehq.org/show_bug.cgi?id=31279
K1773R K1773R@darkgamex.ch changed:
What |Removed |Added ---------------------------------------------------------------------------- Attachment #41098|0 |1 is obsolete| |
http://bugs.winehq.org/show_bug.cgi?id=31279
Anastasius Focht focht@gmx.net changed:
What |Removed |Added ---------------------------------------------------------------------------- Summary|SafeDisc: driver crashes |Age of Empires II SafeDisc |under certain circumstances |v1.x driver crashes in IDT | |check (INT1/3 hooks)
--- Comment #6 from Anastasius Focht focht@gmx.net 2012-07-22 17:24:59 CDT --- Hello,
let's target "Age of Empires II" series with SafeDisc 1.x driver otherwise this gets really messed up mixing different versions/games.
The internal driver version seems to be 1.6.0
--- snip --- in_buff: 00000001 00000006 00000000 0000003d db8ce543 4f190d3a a82e94fd 3cbb7c84 --- snip ---
--- snip --- typedef struct _SECDRV_IOC_IN_BUFFER { DWORD dwVersionMajor; DWORD dwVersionMinor; DWORD dwVersionPatch;
DWORD dwCommand; BYTE bVerificationData[0x400];
DWORD cbUserData; BYTE bUserData[0x100]; } SECDRV_IOC_IN_BUFFER, *PSECDRV_IOC_IN_BUFFER; --- snip ---
The command code is 0x3d -> SECDRV_CMD_INFO_IDT
--- snip --- 003e:Call driver dispatch 0x546328 (device=0x11ad80,irp=0x53f14c) 003e:trace:seh:raise_exception code=c0000005 flags=0 addr=0x54287f ip=0054287f tid=003e 003e:trace:seh:raise_exception info[0]=00000000 003e:trace:seh:raise_exception info[1]=7c2f0008 003e:trace:seh:raise_exception eax=7c2f0008 ebx=404a1fdc ecx=00000000 edx=0011ad80 esi=00000145 edi=0053f14c 003e:trace:seh:raise_exception ebp=0053efec esp=0053efac cs=0017 ds=001f es=001f fs=1017 gs=0037 flags=00010202 003e:trace:seh:call_vectored_handlers calling handler at 0x4049db30 code=c0000005 flags=0 003e:trace:int:emulate_instruction Opcode bytes: 8b 18 83 c0 10 8b 003e:err:int:emulate_instruction cannot emulate instruction at 0x54287f: 8b 003e:trace:seh:call_vectored_handlers handler at 0x4049db30 returned 0 003e:trace:seh:call_stack_handlers calling handler at 0x7bc7c450 code=c0000005 flags=0 --- snip ---
Opcodes translated to assembly snippet:
--- snip --- 8B18 MOV EBX,DWORD PTR DS:[EAX] 83C0 10 ADD EAX,10 8B?? MOV EAX,??? --- snip ---
The referenced memory address 0x7c2f0008 is most likely the address that ought to be the INT1 IDT entry (idtbase+8 = INT1).
SafeDisc checks the distance between INT1 and INT3 vectors to find kernel debuggers like SoftICE that hook them (subtracts base addresses specified in INT1 and INT3 descriptors without selectors and checks the difference against specific value).
Can you add more trace output to: http://source.winehq.org/git/wine.git/blob/57e4e608dcd73b36f1084e0cfcb7cf092...
(dump of values like "addr", "idtr.base", "idtr.limit")
Regards
http://bugs.winehq.org/show_bug.cgi?id=31279
Charles Davis cdavis@mymail.mines.edu changed:
What |Removed |Added ---------------------------------------------------------------------------- Attachment #41115|0 |1 is obsolete| |
--- Comment #7 from Charles Davis cdavis@mymail.mines.edu 2012-07-22 18:55:52 CDT --- Created attachment 41120 --> http://bugs.winehq.org/attachment.cgi?id=41120 New log with +tid,... from Age of Empires II
Here.
Interesting. It looks like the address it's trying to read is before the IDT even starts:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c31b000, limit=0x1006) at 0x54287f
Why would that be? There are two others before it:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c2f0000, lim it=0x1004) at 0x54287f 003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0018, base=0x7c2f0000, lim it=0x1004) at 0x542884
so for some reason, we're pulling the rug from under SECDRV.
http://bugs.winehq.org/show_bug.cgi?id=31279
--- Comment #8 from Charles Davis cdavis@mymail.mines.edu 2012-07-22 19:47:30 CDT --- (In reply to comment #7)
Created attachment 41120 [details] New log with +tid,... from Age of Empires II
Here.
Interesting. It looks like the address it's trying to read is before the IDT even starts:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c31b000, limit=0x1006) at 0x54287f
Why would that be? There are two others before it:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c2f0000, lim it=0x1004) at 0x54287f 003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0018, base=0x7c2f0000, lim it=0x1004) at 0x542884
so for some reason, we're pulling the rug from under SECDRV.
*smacks head* Now I know why!
get_idtr() is implemented like so:
static inline struct idtr get_idtr(void) { struct idtr ret; #ifdef __GNUC__ __asm__( "sidtl %0" : "=m" (ret) ); #else [...] #endif return ret; }
So on i386, it reads the actual IDTR. But I'm running this on a multi-core system--where (at least on Mac OS) each CPU has its own IDT! Therefore, when it executes the SIDT instruction, it gets a different result depending on which CPU it happens to be running on.
When SECDRV reads the IDTR, it caches the value somewhere, and calculates the address of each descriptor based on that cached value. But we don't, on the assumption that an SIDT is cheap. Thus, when the scheduler happens to pick a different CPU for SECDRV to run on, the value returned by get_idtr() differs from SECDRV's cached value. Wine thinks that SECDRV's access to the #DB and #BP descriptors is out-of-bounds and refuses to emulate the read. The AV then propagates and SECDRV crashes.
This suggests one of two fixes. One is to force the WineDevice process--or at least the thread running the NTOSKRNL loop--onto one CPU. The other is to cache the IDTR ourselves on the first read, so we always use the same IDT base and limit when checking if a MOV is from the IDT.
http://bugs.winehq.org/show_bug.cgi?id=31279
--- Comment #9 from Anastasius Focht focht@gmx.net 2012-07-22 19:57:43 CDT --- Hello,
--- quote --- Interesting. It looks like the address it's trying to read is before the IDT even starts:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c31b000, limit=0x1006) at 0x54287f
Why would that be? There are two others before it:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c2f0000, lim it=0x1004) at 0x54287f 003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0018, base=0x7c2f0000, lim it=0x1004) at 0x542884 --- quote ---
The limits look very strange (invalid). Maybe this is an OSX specific thing, I'm not familiar with that OS. Can you compile and execute this short C program:
--- snip sidt.c --- #include <stdio.h>
struct { unsigned short limit; unsigned int base; } __attribute__ ((packed)) idtr;
int main(int argc, char **argv) { asm ("sidt %0" : "=m" (idtr)); printf("IDTR base at 0x%X\n",(int)idtr.base); printf("IDTR limit 0x%X\n",(int)idtr.limit); return 0; } --- snip sidt.c ---
One thing that comes to my mind is that IDT's are per CPU core. If the IDT addresses are different between cores and the thread is migrated to different cores in between two "sidt" calls then this kind of thing (IDT base change) might happen.
You could try:
$ taskset -c 0 ./sidt $ taskset -c 1 ./sidt $ taskset -c 2 ./sidt $ taskset -c 3 ./sidt
and see if the IDT bases are the same to rule out such kind of problem.
EDIT: You actually had the same idea while I was writing this ;-)
Regards
http://bugs.winehq.org/show_bug.cgi?id=31279
--- Comment #10 from Charles Davis cdavis@mymail.mines.edu 2012-07-22 20:39:13 CDT --- (In reply to comment #9)
Hello,
--- quote --- Interesting. It looks like the address it's trying to read is before the IDT even starts:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c31b000, limit=0x1006) at 0x54287f
Why would that be? There are two others before it:
003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0008, base=0x7c2f0000, lim it=0x1004) at 0x54287f 003e:trace:int:emulate_instruction mov idt,xxx (0x7c2f0018, base=0x7c2f0000, lim it=0x1004) at 0x542884 --- quote ---
The limits look very strange (invalid). Maybe this is an OSX specific thing, I'm not familiar with that OS. Can you compile and execute this short C program:
--- snip sidt.c --- #include <stdio.h>
struct { unsigned short limit; unsigned int base; } __attribute__ ((packed)) idtr;
int main(int argc, char **argv) { asm ("sidt %0" : "=m" (idtr)); printf("IDTR base at 0x%X\n",(int)idtr.base); printf("IDTR limit 0x%X\n",(int)idtr.limit); return 0; } --- snip sidt.c ---
Sure enough, every time I run this program, I get a different result.
That last digit in the limit is strange, but it doesn't seem to be a problem in practice. I haven't had any IDT-related panics :). I suspect it's got something to do with the number of the CPU that owns that particular IDT. So far I've seen 1000h, 1002h, 1004h, and 1006h. I have four physical cores, so that makes sense.
One thing that comes to my mind is that IDT's are per CPU core. If the IDT addresses are different between cores and the thread is migrated to different cores in between two "sidt" calls then this kind of thing (IDT base change) might happen.
You could try:
$ taskset -c 0 ./sidt $ taskset -c 1 ./sidt $ taskset -c 2 ./sidt $ taskset -c 3 ./sidt
and see if the IDT bases are the same to rule out such kind of problem.
Unfortunately, I just remembered that it's not generally possible to force a thread onto one particular CPU on Mac OS. (So, there's no 'taskset' command. I believe that's a Linux-ism anyway.) The best one can do on Mac OS is put your threads in an "affinity group", whereby your threads are tagged with a number; then the scheduler runs the threads on whatever CPUs are closest to each other in terms of memory locality (at least, that's how it's supposed to work). (This of course makes it impossible to sanely implement Windows-style thread affinity handling on Mac OS, which kinda makes me mad. Maybe I should start using Linux...)
By the way, in case you're wondering, using the affinity tag API is no help. I still see four different base/limit combinations.
This also means that forcing the NTOSKRNL thread onto a particular CPU is out.
EDIT: You actually had the same idea while I was writing this ;-)
Regards
http://bugs.winehq.org/show_bug.cgi?id=31279
Charles Davis cdavis@mymail.mines.edu changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|UNCONFIRMED |RESOLVED Resolution| |UPSTREAM
--- Comment #11 from Charles Davis cdavis@mymail.mines.edu 2012-07-22 22:33:06 CDT --- Well, it turns out SECDRV really wasn't caching the IDTR like I thought. Which is even worse, because it means there's a race between SECDRV and Wine reading the IDTR. If the scheduler changes the CPU NTOSKRNL is running on between the time SECDRV reads the IDTR and the time Wine reads the IDTR, SECDRV and Wine will end up reading different IDTR values.
I even tried to get Wine to remember all four IDTR values, and check each one. But it's still subject to this same data race. This sucks.
So after trying to fix this problem in Wine multiple times, I'm convinced now there are only two ways to make it work, and both of them require changing the kernel:
1. The easy way: make the kernel use the same IDT for all cores. Probably not realistic. I'm sure there's a good reason each core has its own IDT. (At the very least, it seems to be used to distinguish one processor from another.) 2. The hard way: implement "strong" affinity (i.e. the kind that Windows and Linux implement), as opposed to the "weak" kind Mac OS currently has. Then we can force the NTOSKRNL thread onto a specific CPU and avoid the race.
I'll see about implementing 2 and getting my patch upstreamed for the next version of Mac OS. For now, I'll just have to run a modified kernel.
http://bugs.winehq.org/show_bug.cgi?id=31279
Brandon Corujo haku08879@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |haku08879@gmail.com
https://bugs.winehq.org/show_bug.cgi?id=31279
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED
--- Comment #12 from Austin English austinenglish@gmail.com --- Closing.
https://bugs.winehq.org/show_bug.cgi?id=31279
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|CLOSED |RESOLVED
--- Comment #13 from Austin English austinenglish@gmail.com --- This was inadvertently caught up in my unclosed bugs filter. NOTOURBUG should only be closed when fixed upstream.
Setting back to RESOLVED NOTOURBUG.
Sorry for the spam.
-
wine-bugs＠winehq.org