Re: [lmi] Remarkable performance problem

[Greg Chicares]

On 2018-02-28 17:52, Vadim Zeitlin wrote:
> On Wed, 28 Feb 2018 17:33:47 +0000 Greg Chicares <address@hidden> wrote:
> 
> GC> Well, that's surprising--if I run the problematic census this way:
> GC>   $wine ./lmi_wx_shared --ash_nazg --data_path=/opt/lmi/data
> GC> it's as awful as yesterday, of course; but if I do it this way:
> GC>   $WINEDEBUG=warn+all wine ./lmi_wx_shared --ash_nazg 
> --data_path=/opt/lmi/data >log 2>&1
> GC> it zooms through the first couple hundred cells, and simple GUI
> GC> operations like PgDown in the census are almost instantaneous.
> 
>  Is the effect the same if you use "WINEDEBUG=-all"?

No. I tried
  WINEDEBUG=-all wine ./lmi_wx_shared --ash_nazg --data_path=/opt/lmi/data >log 
2>&1
and cancelled after it ran the first two cells, at which time the
progress meter estimated it'd take 4:41:50 longer to finish.

OTOH, when I try
  WINEDEBUG=warn+heap wine ./lmi_wx_shared --ash_nazg --data_path=/opt/lmi/data
it completes in 1563.718 s = 26 minutes. Early in that run, it predicts
a total about six minutes; the progress dialog increments smoothly,
quickly at first, and then more and more slowly. With that setting:
 - the GUI is responsive: e.g., hitting End goes to the last cell
   almost immediately--as opposed to taking about as long as I can
   hold my breath, with an empty $WINEDEBUG
 - the total time to run the census is almost as bad as with an
   empty $WINEDEBUG, even though it feels faster at first

> I'm not sure how
> exactly does this work, but maybe WINEDEBUG has some default value which
> slows things down and explicitly setting it overrides it? This seems

HKEY_CURRENT_USER\Software\Wine\Debug looks very much like the
recommendation here:
  https://wiki.winehq.org/Debug_Channels#Making_.2Brelay_less_verbose
I also have
  (Default) (value not set)
and a RelayFromExclude key there. Either these are installation
defaults, or I copied them from somewhere, most likely elsewhere
on winehq.org's site.

> unlikely because I don't see why would Wine to choose to be slow by
> default, but I have trouble thinking of any other explanations...

I can't fail to mention a possibly similar phenomenon that you've
no doubt observed: a 'release' build of some program crashes
reproducibly, but a 'debug' build created from the same sources
refuses to crash, e.g., because 'debug' flags initialize unused
storage to binary zeros. I don't imagine that's exactly what's
happening here, but perhaps there is some sort of real problem
that's masked by a nonempty $WINEDEBUG. And of course any such
real problem might stem from a defect in wine, which lends
further support to the idea of creating a debian-testing chroot.

> GC> I see some routine messages when lmi starts up, like:
> [...]
> GC> warn:mdi:get_client_info 0x19014a is not an MDI client
> 
>  This would seem to indicate a bug in wxWidgets. I wonder if it's possible
> to break on the Wine warning function to see where is this one called from?

I want to turn my attention elsewhere now, but perhaps it will
help to show that message in context:

warn:ntdll:NtQueryAttributesFile 
L"\\??\\Z:\\opt\\lmi\\bin\\file:\\Z:\\opt\\lmi\\data\\toolbar.xrc" not found 
(c000003a)
warn:ntdll:NtQueryAttributesFile 
L"\\??\\Z:\\opt\\lmi\\bin\\file:\\Z:\\opt\\lmi\\data\\policy_view.xrc" not 
found (c000003a)
warn:ntdll:NtQueryAttributesFile 
L"\\??\\Z:\\opt\\lmi\\bin\\file:\\Z:\\opt\\lmi\\data\\rounding_view.xrc" not 
found (c000003a)
warn:mdi:get_client_info 0x220140 is not an MDI client
warn:font:synthesize_bold_glyph Emboldening format 0x62697473 is not supported

It would seem to occur right after XML resources are loaded from
file, e.g., in Skeleton::OnInit():

        load_xrc_file_from_data_directory(xml_resources, "toolbar.xrc");
        load_xrc_file_from_data_directory(xml_resources, 
PolicyView::resource_file_name());
        load_xrc_file_from_data_directory(xml_resources, 
RoundingView::resource_file_name());

        InitDocManager();

so I wouldn't be surprised if the MDI diagnostic is traceable
to lmi's 'docmanager_ex.cpp' (though I don't find any /MDI\c
in that file).