On 08/30/11 10:33, Alan W. Irwin wrote: > On 2011-08-30 08:20+1000 Ben Peddell wrote: >> Some things I have seen while investigating: >> >> I created a program which had a startup that immediately called >> ExitProcess to attempt to eliminate most of the initialization of the >> process being forked. >> >> On Windows 7 x64 SP1 on an AMD 5050e: >> bash.exe takes about 22.2ms to fork. >> make.exe takes about 8.8ms to fork. >> cmd.exe takes about 5.9ms to fork. >> >> Under wine 1.2.1 on linux 2.6.38 on an AMD 5050e: >> bash.exe takes about 236ms to fork nothing, and 182ms to fork /bin/true. >> make.exe takes about 77ms to fork nothing, and 25ms to fork /bin/true. >> wine-cmd takes about 9ms to fork nothing. >> >> Under wine-git on linux 2.6.38 on an AMD 5050e: >> bash.exe takes about 190ms to fork nothing, and 147ms to fork /bin/true >> make.exe takes about 71ms to fork nothing and 20ms to fork /bin/true. >> wine-cmd takes about 9ms to fork nothing. > > Just out of curiosity do you have any explanation of why /bin/true provided > faster make.exe results than your quick-exiting programme both for > wine-1.2.1 and wine-git?
I suspect that the fork/exec emulation detects if the executable is a MSYS executable, and if so, takes a fast path, skipping a lot of the initialization that the MSYS executable would have done. > >> >> Even the native bash takes twice as long to fork as make - 1.1ms vs >> 0.5ms. >> >> It looks to me like the fork emulation in MSYS is encountering a >> bottleneck, and not actual process creation. > > I assume you meant "encountering a _wine_ bottleneck" since clearly > above your MSYS tests of make.exe and bash.exe on Windows don't have > the large startup latencies you encounter with wine-1.2 and wine-git. > > How does the MSYS version of make (make.exe that you tried above) > compare in this regard with the MinGW version of make > (MinGW/bin/mingw32-make.exe) that specifically excludes everything to > do with MSYS? My guess is you will encounter a similar wine > bottleneck for this case as well, but it is worth verifying that. I suspect mingw32-make uses fork() emulation when launching MSYS programs, and CreateProcess() otherwise - the execution time for msys-echo and msys-true are on par with those under msys-make, and the execution time for ExitProcess.exe is on par with that under wine-cmd. > > And now you have done a clean comparison with the same software stack > it is clear that wine-git somewhat reduces the bottleneck compared to > wine-1.2. Thus, I expect my own planned clean comparisons to show the > same. So I have changed the subject line appropriately. > > Now, if someone could just figure out what the wine bottleneck is that > is causing these severe start-up latencies for Windows applications.... A modification of the timestamp patch from Bernhard Loos should help us find what calls are taking the longest. bash: running /bin/echo: +0ms:0024:Call KERNEL32.CreateProcessA(bash) => tid 0028 +8ms:0028:Call KERNEL32.__wine_kernel_init() +11ms:0024:Call KERNEL32.WaitForMultipleObjects() +21ms:0028:DLLs loading +43ms:0028:Process starting +45ms:0028:Call KERNEL32.SetEvent() => wake 0024 +45ms:0024:Call KERNEL32.WriteProcessMemory() +45ms:0028:Call KERNEL32.WaitForSingleObject() write-process-memory 10 times, totalling 500kB +134ms:0024:Ret KERNEL32.WriteProcessMemory() +134ms:0028:Ret KERNEL32.SetFileApisToANSI() ??? +148ms:0028:Call KERNEL32.CreateProcessA(echo) => tid 002b +155ms:002b:Call KERNEL32.__wine_kernel_init() +157ms:0028:Ret KERNEL32.CreateProcessA() +158ms:0028:Call KERNEL32.WaitForMultipleObjects() +163ms:002b:DLLs loading +163ms:002b:Process starting +169ms:0028:Call KERNEL32.ExitProcess() +172ms:002b:Call KERNEL32.ExitProcess() bash: running ExitProcess.exe: +0ms:0024:Call KERNEL32.CreateProcessA(bash) => tid 0034 +7ms:0034:Call KERNEL32.__wine_kernel_init() +11ms:0024:Call KERNEL32.WaitForMultipleObjects() +20ms:0034:DLLs loading +42ms:0034:Process starting +44ms:0034:Call KERNEL32.SetEvent() => wake 0024 +44ms:0024:Call KERNEL32.WriteProcessMemory() +44ms:0034:Call KERNEL32.WaitForSingleObject() write-process-memory 10 times, totalling 500kB +130ms:0024:Ret KERNEL32.WriteProcessMemory() +130ms:0034:Ret KERNEL32.WaitForSingleObject() looking at attributes of a whole heap of directories... +215ms:0034:Call KERNEL32.CreateProcessA(ExitProcess.exe) => tid 0037 +221ms:0037:Call KERNEL32.__wine_kernel_init() +223ms:0034:Ret KERNEL32.CreateProcessA() +224ms:0034:Call KERNEL32.WaitForMultipleObjects() +224ms:0037:Call KERNEL32.ExitProcess() +225ms:0034:Call KERNEL32.ExitProcess() -- Ben Peddell IT Support Bowen, Collinsville, Proserpine and Home Hill Catholic schools http://klightspeed.killerwolves.net/