Re: [lmi] Can linux-perf illuminate this problem?

[Vadim Zeitlin]

On Fri, 5 Mar 2021 20:30:53 +0000 Greg Chicares <gchicares@sbcglobal.net> wrote:

GC> Vadim--I seem to have done something awful in a commit that I've
GC> pushed only to this branch, but not to origin/master:
GC> 
GC> https://git.savannah.nongnu.org/cgit/lmi.git/commit/?h=odd/eraseme
GC> | commit    d1ae1eaeef2ed1a1ddd15b47f19703d6a26b1e5d
GC> | Use currency type for max non-MEC payment
GC> | This commit has a disastrous effect on performance as measured by
GC> | 'make cli_timing': for the first ('naic, no solve') scenario, the
GC> | penalty is 14% for i686 and 30% for x86_64. How can that be?

 I can't answer this question neither. I didn't have time to rebuild
everything and run perf myself yet, but I've just quickly compiled the 2
version and compared the assembly generated for them and don't see anything
unexpected, I.e. there is indeed a bunch of new instructions in DoMonthDR()
but there are fewer instructions in the new version of TxLimitPayment()
that should compensate for this.

GC> I pushed that branch to origin so that I could easily switch to it
GC> in a chroot that's configured to use linux-perf. I can get 'perf'
GC> to tell me what I already know--that AccountValue::DoMonthDR() is
GC> where the problem is--but can it tell me which statements are
GC> responsible?

 It should be able to show you the instructions responsible.

GC> I used this command:
GC> 
GC> 
$LD_LIBRARY_PATH=.:/opt/lmi/bin:/opt/lmi/local/gcc_x86_64-pc-linux-gnu/lib/:/srv/cache_for_lmi/perf_ln
 /srv/cache_for_lmi/perf_ln/perf_4.19 record --freq=max --call-graph=lbr 
/opt/lmi/bin/lmi_cli_shared --accept --data_path=/opt/lmi/data --selftest
GC> 
GC> to collect data: first, with the offending commit; then, again,
GC> without the offending commit.
GC> 
GC> This command:
GC>   $LD_LIBRARY_PATH=.:/srv/cache_for_lmi/perf_ln 
/srv/cache_for_lmi/perf_ln/perf_4.19 diff
GC> tells me:
GC> 
GC> # Baseline  Delta Abs  Shared Object         Symbol                         
                      >
GC> # ........  .........  ....................  
.....................................................>
GC> #
GC>     14.90%    -10.35%  liblmi.so             [.] AccountValue::DoMonthDR
GC> 
GC> but doesn't let me drill down.

 Yes, I don't think perf-diff allows to do this.

GC> This command:
[...]
GC> ...but that only seems to tell me how much time is spent in each
GC> function called by AccountValue::DoMonthDR(). However, I suspect
GC> that I've done something atrocious inside DoMonthDR() itself.
GC> Can 'perf' help me find that?

 If you select the function and press "Enter", you should see the menu with
several choices, the first of which is "Annotate <function>". Selecting it
shows the instructions actually being executed, annotated with the source
lines, and percentage of the execution time for the hot instructions.

 Again, I didn't have the time to actually do it myself yet, so I don't
know if it shows anything useful, but this is where I'd start looking.
Please let me know if you find anything useful and/or if you'd like me to
try it myself (but tomorrow).

 Good luck!
VZ

pgpfcpbk6UL_Y.pgp
Description: PGP signature