[wine-devel] Re: Severe startup latencies for Windows applications run under wine

[Alan W. Irwin]

On 2011-09-01 01:25+1000 Ben Peddell wrote:

> On 31/08/2011 3:12 AM, Dan Kegel wrote:
>> Try oprofile instead.
>>
>> ( A really old intro is at
>> http://www.winehq.org/wwn/249#oprofile%20&%20Wine )
>>
>
> Using oprofile, testing 500 iterations of ExitProcess.exe with
> msys-bash under wine:
>
> About 2/3 of the active processor time was in wineserver.
> About 90% of that was spent in the kernel.
> At least 50% of that time was spent in code related related to
> ptrace(), which is ultimately called by
> wineserver::write_process_memory().
>
> The other 1/3 of the active processor time was in wine-preloader.
> About 70% of that was spent in the kernel.
>
> 500 iterations took about 100s to complete at about 100% usage of 1
> CPU core.
>
> msys-bash uses WriteProcessMemory() to copy 500kB during an emulated
> fork.  This equates to about 125000 ptrace(PTRACE_POKEDATA,...)
> syscalls, each of which takes about 0.8us on linux 2.6.38.
>

Hi Ben:

Let me remind you and others here why I am so interested in these results.

I am a strong advocate of free software on all platforms (not just
Linux) so I went out of my way to make sure my recent ephcom-2.0.2
release built and gave good test results on MinGW/MSYS/Wine (the only Windows
platform accessible to me).  And that complete success on one Windows
platform was confirmed by somebody else on a MinGW/MSYS/Microsoft
Windows XP platform.

However, the 0.5-second command startup latency under Wine makes
software builds under MinGW/MSYS/Wine extraordinarily inconvenient.
The problem is that build systems such as autotools and cmake (and
presumably the rest as well) all break down the configuration task
into many tiny tasks and similarly for the build itself under make.
So when each of those tiny tasks take 0.5 seconds to complete the
result is an extraordinary slowdown of the build.  ephcom-2.0.2 is
actually a pretty simple package so this wasn't too bad an issue in
that case, but to test my build environment on MinGW/MSYS/wine, I
recently attempted to build cmake (a C++ application in its own right
that can be built using the windows binary version of cmake).  That
build was a success, but the whole build took more than an hour (as
opposed to ~10 minutes under Linux).

(Much) worse, yet, that hour constituted a denial of service attack on the
Linux box underneath (and the same for the ephcom-2.0.2 build although
substantially shorter duration in that case).  During that time
everything on the Linux desktop slowed to a crawl.  For example, in a
(pysol) Linux solitaire game I attempted, each card dealt took about a
second (!) to complete. Switching from one desktop to another took
seconds as well.  The "top" application showed that whatever resource
that the build under wine was consuming was not accessible to "top";
the cpu's were idle (virtually 100 per cent idle time), there was
negligible wait time, and there was nothing obviously bad in the
memory use.  (These results were all with Linux kernel "Linux raven
2.6.32-5-amd64 #1 SMP Fri Sep 9 20:23:16 UTC 2011 x86_64 GNU/Linux"
from Debian squeeze.)

I am aware that you can build Windows software directly from Linux,
but I am not going to use that alternative because for potential users
of my software on all Windows platforms I need to test the build
system of my software in a realistic Windows environment, and Wine
provides that for me.

Thus, despite the current horrible inconvenience I am going to stick
with attempting to build software under Wine. Nevertheless, I think
until this command startup latency under Wine (and especially the
corresponding denial of service attack on Linux underneath) is
reduced, most developers will avoid as much as possible attempting to
build their packages under Wine.

In sum, from my perspective it is important for the Wine developers to
figure out exactly what the issue is and deal with it.  0.5-second
command startup latencies are just not acceptable for a general
platform.

So where do we stand in that effort to find a solution?  From above,
your "500 iterations took about 100s" equates to a 0.2 second
component of the command start-up latency that you have identified.
And WriteProcessMemory() requiring 125000 syscalls at 0.8us = 0.1 seconds
just to copy 500kB sounds really bad.

Have you opened a bug report to keep track of your results?  If so, I
would like to add my own timing results there.  If not, shall I
open a bug report for my timing results that you can add to?

Alan
__________________________
Alan W. Irwin

Astronomical research affiliation with Department of Physics and Astronomy,
University of Victoria (astrowww.phys.uvic.ca).

Programming affiliations with the FreeEOS equation-of-state
implementation for stellar interiors (freeeos.sf.net); the Time
Ephemerides project (timeephem.sf.net); PLplot scientific plotting
software package (plplot.sf.net); the libLASi project
(unifont.org/lasi); the Loads of Linux Links project (loll.sf.net);
and the Linux Brochure Project (lbproject.sf.net).
__________________________

Linux-powered Science
__________________________