Re: [lmi] Drastic slowdown related to wine upgrade?

[Vadim Zeitlin]

On Fri, 25 Jan 2019 14:13:57 +0000 Greg Chicares <address@hidden> wrote:

GC> Since I upgraded from wine-3.x to wine-4.x the other day, the time it takes 
to
GC> run this command:
GC>   time make $coefficiency check_concinnity
GC>   make $coefficiency check_concinnity  3.50s user 0.98s system 8% cpu 
52.817 total
GC> has grown remarkably, from a few seconds to nearly a minute.
GC> Suppressing the
GC> xmllint command in that makefile target reduces the time to about four 
seconds,
GC> so that (pipelined) command is the culprit.
[...]
GC> which suggests that using wine in a pipeline is the problem:
GC> 
GC> /opt/lmi/src/lmi[0]$time (for z in *.cns *.ill *.xrc *.xsd; \               
GC>   do \
GC>     wine /opt/lmi/local/bin/xmllint --encode ASCII $z \
GC>     | tr --delete '\r' \
GC>     | diff \
GC>       --ignore-blank-lines \
GC>       --ignore-matching-lines='<\?xml' \
GC>       --unified=0 \
GC>       $z - \
GC>       || echo "... in file $z"; \
GC>   done;)
[...]
GC> I copied and pasted those exact command lines into the older chroot;
GC> here's a tabulation of the results:
GC> 
GC>   * wine-4.x
GC> ( for [...]; wine /opt/lmi/local/bin/xmllint  ASCI)  0.60s user 0.82s 
system 3% cpu 46.509 total
GC> ( for [...]; /usr/bin/xmllint --encode ASCII $z | )  0.09s user 0.07s 
system 83% cpu 0.197 total
GC>   * wine-1.x
GC> ( for [...]; wine /opt/lmi/local/bin/xmllint  ASCI)  0.48s user 0.65s 
system 75% cpu 1.486 total
GC> ( for [...]; /usr/bin/xmllint --encode ASCII $z | )  0.10s user 0.06s 
system 85% cpu 0.179 total
GC> 
GC> which clearly seems to establish that there's a wine regression here.
GC> 
GC> Vadim--Can you reproduce this in your 32-bit chroot?

 I don't have the old version of WINE any more, so I can't confirm that
it's a regression but I definitely can confirm that the latest version is
much, much slower. The commands I compared were:

[X*]: xmllint --encode ASCII *.cns *.ill *.xrc *.xsd >/dev/null
[FX]: for z in *.cns *.ill *.xrc *.xsd; do; /usr/bin/xmllint --encode ASCII $z; 
done
[PL]: ... the full multiline pipeline with tr and diff from above ...

and here are the minimal times of 10 iterations of each, except for the
last one, which I only ran twice as I wasn't patient enough to wait for ~6
minutes for 10 iterations to finish:

X* native:       0.02
FX native:       0.12
PL native:       0.13
X* WINE:         0.50
FX WINE:         1.21
PL WINE:        34.14

 Of course, running xmllint in a loop is noticeably slower than running it
just once because there is the program startup overhead and when running it
in a loop under WINE there is also the overhead of WINE's own startup. But
the slowness of the last command can't be explained by this...

GC> A web search for
GC>   winehq pipeline slow
GC> finds nothing clearly relevant, while
GC>   wine pipeline slow
GC> finds articles about petroleum pipelines near vineyards. But if you
GC> see the same problem I see, then it's probably worthwhile to devise
GC> a simple test case that the winehq or debian people can reproduce,
GC> because this may expose a serious problem that they don't know about.

 I guess I should do this, although I don't really know here is the problem
coming from. It's clearly not related to xmllint, as I can reproduce the
same kind of dramatic slowdown using just "cmd /c type sample.cns" instead.
And it's not related to "tr" because the same thing happens if I replace it
with cat. And it's not related to zsh as the same thing happens with bash.

 So my minimal reproducible example is that

        time (wine cmd /c type 'c:\windows\win.ini' >/dev/null)

takes 0.02s while

        time (wine cmd /c type 'c:\windows\win.ini' | cat >/dev/null)

takes 1.2s.

 If I open the bug with this, which "last good" WINE version should I
report? I.e. you wrote that you upgraded from wine-3.x, but would you
remember what was the value of "x"? Was it 3.0.3 from Stretch backports?

 Thanks,
VZ