Hello again!
Running Origin6.0 with WINEDEBUG="+snoop,+relay" with and without native msvcrt, tailing, cutting and wc-ing and finally diffing the output I found the following:
First of all using the native version I get some msvcrt._EH_prolog calls I can't find in the builtin version.
all window-procs have such calls:
native: ret kernel32.94() retval=00000009 ret=7f6c5a5c call window proc 0x6c231b81 (hwnd=0x1003a,msg=wm_settext,wp=00000000,lp=7fadedd4) call msvcrt._eh_prolog(7f6cf147,0001003a,0000000c,00000000,7fadedd4 "microcal origin - i ret msvcrt._eh_prolog() retval=7db10190 ret=6c231b8b call msvcrt._eh_prolog(6c231b9c,6c23b419,6c231b81,6c231b81,7fadf8ec,6c2c2cfe,ffffffff0009 ret ntdll.rtlentercriticalsection() retval=00000000 ret=7e6563d2 call ntdll.rtlleavecriticalsection(7e69a888) ret=7e656412 ret ntdll.rtlleavecriticalsection() retval=00000000 ret=7e656412 \mnt\privat\origin6\untitled",7f6ee620,0001003a,0000000c, ...) ret=6c2310b5 ret msvcrt._eh_prolog() retval=7db10190 ret=6c2310b5 call kernel32.tlsgetvalue(00000003) ret=6c231018 ret kernel32.tlsgetvalue() retval=7fdd7a88 ret=6c231018 call msvcrt._eh_prolog(6c23138a,00000000,6c231be9,0001003a,7fadeba8,6c231bba,0001003a,0000000c,00000000,7fadedd4 "microcal origin - i ret msvcrt._eh_prolog() retval=7db10190 ret=6c23112a call kernel32.tlsgetvalue(00000003) ret=6c231018 ret kernel32.tlsgetvalue() retval=7fdd7a88 ret=6c231018 call kernel32.tlsgetvalue(00000003) ret=6c231018 ret kernel32.tlsgetvalue() retval=7fdd7a88 ret=6c231018 call msvcrt._eh_prolog(6c231bfb,7d9366c0,0001003a,0000000c,00000000,7fadedd4 "microcal origin - i ret msvcrt._eh_prolog() retval=7db10190 ret=6c231c09 call kernel32.tlsgetvalue(00000003) ret=6c231018
builtin: call window proc 0x6c231b81 (hwnd=0x1003a,msg=wm_settext,wp=00000000,lp=7fadedd4) call kernel32.tlsgetvalue(00000003) ret=6c231018
This is another example not concerting window procs:
native: call kernel32.lstrlena(7fadecc0 "microcal origin") ret=6c2338d7 ret kernel32.lstrlena() retval=0000000f ret=6c2338d7 call msvcrt._eh_prolog(6c2319c6,0000000f,7fadedd0,7fd299fc,6c23393c,0000000f,0000000f,7fadedd0,6c2338f9,0000000f,7fadecc0 "microcal origin",7fadedd0,6c2338e0,0000000f,7fadecc0 "microcal origin",0000000f, ...) ret=6c231aeb ret msvcrt._eh_prolog() retval=7db101a9 ret=6c231aeb call ntdll.rtlentercriticalsection(6c300088) ret=6c231b03
same as builtin: call kernel32.lstrlena(7fadecc0 "microcal origin") ret=6c2338d7 ret kernel32.lstrlena() retval=0000000f ret=6c2338d7 call ntdll.rtlentercriticalsection(6c300088) ret=6c231b03
From mfc there is also such a call:
native: call mfc42.6374(0000000c,00000000,7fadedd4 "microcal origin - i call mfc42.5163(0000000c,00000000,7fadedd4 "microcal origin - i call msvcrt._eh_prolog(7db101db,0000000c,00000000,7fadedd4 "microcal origin - i ret msvcrt._eh_prolog() retval=7db101f4 ret=6c231d16 call ntdll.rtlentercriticalsection(6c300220) ret=6c23178e
builtin: call mfc42.6374(0000000c,00000000,7fadedd4 "microcal origin - i call mfc42.5163(0000000c,00000000,7fadedd4 "microcal origin - i call ntdll.rtlentercriticalsection(6c300220) ret=6c23178e
Then there is also a difference when calling ftime():
native: (line 16240) call msvcrt.memcpy(7d945558 "untitled",7fe5e27a "untitled",00000008) ret=6c233905 ret msvcrt.memcpy() retval=7d945558 ret=6c233905 ret mfc42.860() retval=7d943dc0 ret=7f81a080 call outl60.labutil_str2date(00000000,00000003,00000000) ret=7f81a0fe call msvcrt._ftime() ret=7f74100d call kernel32.getsystemtimeasfiletime(7fadedf0) ret=78026aad call ntdll.ntquerysystemtime(7fadec80) ret=7fd08e30 ret kernel32.getsystemtimeasfiletime() retval=01c5f531 ret=78026aad ret msvcrt._ftime() retval=438cd1d8 ret=7f74100d call msvcrt.localtime() ret=7f74103e call kernel32.getlasterror() ret=78002699 ret kernel32.getlasterror() retval=00000000 ret=78002699 call kernel32.tlsgetvalue(00000002) ret=780026a7 ret kernel32.tlsgetvalue() retval=7d930088 ret=780026a7 call kernel32.setlasterror(00000000) ret=780026b8 ret kernel32.setlasterror() retval=00000000 ret=780026b8 ret msvcrt.localtime() retval=7d9306f8 ret=7f74103e
builtin: (line 16632) call msvcrt.memcpy(7fe7dff8,7fe637e2,00000008) ret=6c233905 ret msvcrt.memcpy() retval=7fe7dff8 ret=6c233905 ret mfc42.860() retval=7fe7aac0 ret=7f81a080 call outl60.labutil_str2date(00000000,00000003,00000000) ret=7f81a0fe call msvcrt._ftime(7f75b778) ret=7f74100d call kernel32.gettimezoneinformation(7fadec9c) ret=7e886be4 call ntdll.rtlquerytimezoneinformation(7fadec9c) ret=7fd09bce ret ntdll.rtlquerytimezoneinformation() retval=00000000 ret=7fd09bce call ntdll.ntquerysystemtime(7fadebc0) ret=7fd08e30 ret kernel32.gettimezoneinformation() retval=00000000 ret=7e886be4 call kernel32.getsystemtimeasfiletime(7faded48) ret=7e886bf3 call ntdll.ntquerysystemtime(7fadebe0) ret=7fd08e30 ret ntdll.ntquerysystemtime() retval=00000000 ret=7fd08e30 ret kernel32.getsystemtimeasfiletime() retval=01c5f530 ret=7e886bf3 ret msvcrt._ftime() retval=00000000 ret=7f74100d call msvcrt.localtime(7f75b748) ret=7f74103e call kernel32.filetimetolocalfiletime(7faded48,7faded40) ret=7e886e9a call ntdll.rtlsystemtimetolocaltime(7fadeba4,7fadebac) ret=7fd09f03 ret ntdll.rtlsystemtimetolocaltime() retval=00000000 ret=7fd09f03 ret kernel32.filetimetolocalfiletime() retval=00000001 ret=7e886e9a call kernel32.filetimetosystemtime(7faded40,7faded30) ret=7e886ea4 call ntdll.rtltimetotimefields(7fadebb0,7fadeba0) ret=7fd09572 ret ntdll.rtltimetotimefields() retval=0000016f ret=7fd09572 ret kernel32.filetimetosystemtime() retval=00000001 ret=7e886ea4 call kernel32.gettimezoneinformation(7fadec84) ret=7e886fd1 call ntdll.rtlquerytimezoneinformation(7fadec84) ret=7fd09bce ret ntdll.rtlquerytimezoneinformation() retval=00000000 ret=7fd09bce call ntdll.ntquerysystemtime(7fadeb98) ret=7fd08e30 ret ntdll.ntquerysystemtime() retval=00000000 ret=7fd08e30 ret kernel32.gettimezoneinformation() retval=00000000 ret=7e886fd1 ret msvcrt.localtime() retval=7e8ae660 ret=7f74103e
And the native msvcrt seems to use an internal _ftol
native:
call msvcrt._cipow() ret=7f82aaf9 ret msvcrt._cipow() retval=40f00020 ret=7f82aaf9 call msvcrt._ftol() ret=7f82a67a ret msvcrt._ftol() retval=00000001 ret=7f82a67a
builtin:
call msvcrt._cipow() ret=7f82aaf9 ret msvcrt._cipow() retval=00000001 ret=7f82aaf9 call ntdll._ftol() ret=7f82a67a ret ntdll._ftol() retval=0000000000000001 ret=7f82a67a
By the way... what is the difference between "retval" and "ret"? It sounds the same.
There are still some megs in front of me... Perhaps you could comment my discoveries so far. Personally I think they aren't very important, but I really don't know much about the win32 api, so I can't tell...
Ciao,
Olaf Leidinger
"Olaf" == Olaf Leidinger leidola@newcon.de writes:
...
Olaf> By the way... what is the difference between "retval" and "ret"? Olaf> It sounds the same.
ret means the address of the piece of code calling the function retval is the actual return value of the function returning to the caller. With a void function (like ftime time.c: * _ftime (MSVCRT.@) time.c:void _ftime(struct MSVCRT__timeb *buf) ) it doesn't make sense.
B.t.w., vararg functions (look in msvcrt.spec) don't appear in the relay trace.
Olaf> There are still some megs in front of me... Perhaps you could Olaf> comment my discoveries so far. Personally I think they aren't very Olaf> important, but I really don't know much about the win32 api, so I Olaf> can't tell...
The difference in the cipow seems of importance ( math.c:double _CIpow(void) ). I am not sure about a double as retval. Perhaps you can instrument dll/msvcrt/math.c with the patch below and run with (additional or exclusive) WINEDEBUG=+msvrt and look if the arguments and result look right.
Happy bughunting
Hello again!
Sorry for not sending an answer but there where some exercises waiting for me ;-(
Origin doesn't work with CrossOver 5 on my machine, so the problem isn't solved for me. Still using the native dll saving works fine.
And here is the next part of my investigation:
Now the _cipow function call again with the patch:
native: 0009:call msvcrt._cipow() ret=7f82aaf9 0009:ret msvcrt._cipow() retval=40f00020 ret=7f82aaf9 0009:call msvcrt._ftol() ret=7f82a67a 0009:ret msvcrt._ftol() retval=00000001 ret=7f82a67a
builtin: 0009:call msvcrt._cipow() ret=7f82aaf9 trace:msvcrt:_cipow x 10.000000 y 5.000000 trace:msvcrt:_cipow z 100000.000000 0009:ret msvcrt._cipow() retval=00000001 ret=7f82aaf9 0009:call ntdll._ftol() ret=7f82a67a 0009:ret ntdll._ftol() retval=0000000000000001 ret=7f82a67a
I also found a different behaviour of the putc function. In most cases the putc's look like this one:
native: 0009:call msvcrt.putc(00000000,78037ca8) ret=7f822012 0009:call ntdll.rtlentercriticalsection(7d937a18) ret=78001075 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=78001075 0009:call ntdll.rtlleavecriticalsection(7d937a18) ret=780012b1 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=780012b1 0009:ret msvcrt.putc() retval=00000000 ret=7f822012
builtin: 0009:call msvcrt.putc(00000000,7d724018) ret=7f822012 0009:ret msvcrt.putc() retval=00000000 ret=7f822012
But sometimes the builtin one does a writefile:
native: 0009:call msvcrt.putc(0000000a,78037ca8) ret=7f82b869 0009:call ntdll.rtlentercriticalsection(7d937a18) ret=78001075 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=78001075 0009:call ntdll.rtlleavecriticalsection(7d937a18) ret=780012b1 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=780012b1 0009:ret msvcrt.putc() retval=0000000a ret=7f82b869 0009:call ok60.?onbeforeprojectsave@cokaccess@@uaehg@z(<unknown, check return>) ret=7f7f35f2
builtin: 0009:call msvcrt.putc(0000000a,7d724018) ret=7f82b869 0009:call kernel32.writefile(00000018,7fe636f0,0000000e,7fadeec0,00000000) ret=7e876a07 0009:call ntdll.ntwritefile(00000018,00000000,00000000,00000000,7fadedc8,7fe636f0,0000000e,00000000,00000000) ret=7fcc4389 0009:ret ntdll.ntwritefile() retval=00000000 ret=7fcc4389 0009:ret kernel32.writefile() retval=00000001 ret=7e876a07 0009:ret msvcrt.putc() retval=0000000a ret=7f82b869 0009:call ok60.?onbeforeprojectsave@cokaccess@@uaehg@z(<unknown, check return>) ret=7f7f35f2
The ftell-function also calls rtlentercriticalsection:
native: 0009:call msvcrt.ftell(78037ca8) ret=7f81f030 0009:call ntdll.rtlentercriticalsection(7d937a18) ret=78001075 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=78001075 0009:call ntdll.rtlentercriticalsection(7d920188) ret=780124b6 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=780124b6 0009:call kernel32.setfilepointer(00000018,00000000,00000000,00000001) ret=78012115 0009:call ntdll.wine_server_handle_to_fd(00000018,00000000,7fadee1c,00000000) ret=7fcc36f1
builtin: 0009:call msvcrt.ftell(7d724018) ret=7f81f030 trace:msvcrt:_lseeki64 :fd (3) handle (0x18) trace:msvcrt:_lseeki64 :fd (3) to 300000018 pos seek_cur 0009:call kernel32.setfilepointerex(00000018,00000000,00000000,7fadee80,00000001) ret=7e8766dc 0009:call ntdll.wine_server_handle_to_fd(00000018,00000000,7fadeda4,00000000) ret=7fcc36f1
Then there is a bit stange part. It happens during a lot of putc calls...
native: (line 32599) 0009:call msvcrt.putc(00000000,78037ca8) ret=7f822012 0009:call ntdll.rtlentercriticalsection(7d937a18) ret=78001075 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=78001075 0009:call ntdll.rtlleavecriticalsection(7d937a18) ret=780012b1 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=780012b1 0009:ret msvcrt.putc() retval=00000000 ret=7f822012 0009:call msvcrt.putc(fffffffb0009:call ntdll.rtlentercriticalsection(7e699888) ret=7e6553d2 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=7e6553d2 0009:call ntdll.rtlleavecriticalsection(7e699888) ret=7e655412 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=7e655412 ,78037ca8) ret=7f822012 0009:call ntdll.rtlentercriticalsection(7d937a18) ret=78001075 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=78001075 0009:call ntdll.rtlleavecriticalsection(7d937a18) ret=780012b1 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=780012b1 0009:ret msvcrt.putc() retval=000000fb ret=7f822012 0009:call msvcrt.putc(ffffffff0009:call ntdll.rtlentercriticalsection(7e699888) ret=7e6553d2 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=7e6553d2 0009:call ntdll.rtlleavecriticalsection(7e699888) ret=7e655412 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=7e655412 ,78037ca8) ret=7f822012 0009:call ntdll.rtlentercriticalsection(7d937a18) ret=78001075 0009:ret ntdll.rtlentercriticalsection() retval=00000000 ret=78001075 0009:call ntdll.rtlleavecriticalsection(7d937a18) ret=780012b1 0009:ret ntdll.rtlleavecriticalsection() retval=00000000 ret=780012b1 0009:ret msvcrt.putc() retval=000000ff ret=7f822012 0009:call msvcrt.putc(00000019,78037ca8) ret=7f822012 ...
builtin: (line 32376) 0009:call msvcrt.putc(00000000,7d724018) ret=7f822012 0009:ret msvcrt.putc() retval=00000000 ret=7f822012 0009:call msvcrt.putc(fffffffb,7d724018) ret=7f822012 0009:ret msvcrt.putc() retval=fffffffb ret=7f822012 0009:call msvcrt.putc(ffffffff,7d724018) ret=7f822012 0009:ret msvcrt.putc() retval=ffffffff ret=7f822012
I also get the three putc's of the builtin version but after that there are about 7000 lines of putc-calls like above and NO MORE putc calls at all in the builtin version. Also the output of the native debug output is a bit "diverted" (two calls in one line!). Till the lines above I can't see any differences (except the ones I already reported).
Might the missing RtlEnterCriticalSection calls lead to a problem? Isn't the wine msvcrt thread-safe?
If anyone is interested in the logs, I've put them onto my webspace :
http://gordon.cip.physik.uni-saarland.de/~oleid/origin6_builtin.log.bz2 http://gordon.cip.physik.uni-saarland.de/~oleid/origin6_native.log.bz2
Thanks a lot!
Ciao,
Olaf Leidinger
-
Olaf Leidinger -
Uwe Bonnes