Re: Slowdown around 5.0.5-dev-0

[Sebastian Gniazdowski <sgniazdowski@xxxxxxxxx>]

On 12 October 2015 at 10:21, Sebastian Gniazdowski
<sgniazdowski@xxxxxxxxx> wrote:
> With both patches zprof running time is around 1806. RES is 152M and
> goes down nicely to 37564 when I quit the script. Didn't observe
> after-while slow down. The tool is almost fully usable for 89k
> elements (there's still a bit lag), however searching is slow, I
> attached zprof results for searching. It is done via two following
> invocations:
>
>                 list=( "${(@M)list:#(#i)*$~search_pattern*}" )
>                 col_list=(
> "${(@)list//(#mi)($~colsearch_pattern)/$red${MATCH}$reset}" )
>
> Maybe they trigger some specific behavior on heap?

Did one more memory and performance test for version with both patches
and without them. Earlier I just started the script and moved 9 lines,
then checked memory. Now I ran search with $search_pattern and
$colsearch_pattern set to "s", single leter, then checked memory. RES
is 433M and 432M, so it's fine. The patched (HEAD) version is 14 times
faster. I also checked 5.0.2 – RES is 400M, and it's ~8 times slower
than the patched version.

Best regards,
Sebastian Gniazdowski

both patches (HEAD):
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)    1       10112,65 10112,65   99,85%   5124,47  5124,47   50,60%  n-list
 2)   92        4597,96    49,98   45,40%   4597,96    49,98   45,40%  _nlist_print_with_ansi
 3)    4        4910,97  1227,74   48,49%    313,01    78,25    3,09%  n-list-draw
 4)    4          69,24    17,31    0,68%     53,26    13,31    0,53%  n-list-input
 5)    4          28,51     7,13    0,28%     28,51     7,13    0,28%  _nlist_cursor_visibility
 6)    1          14,79    14,79    0,15%      7,11     7,11    0,07%  _nlist_exit
 7)    4           2,78     0,70    0,03%      2,72     0,68    0,03%  _nlist_setup_user_vars
 8)    4           0,18     0,05    0,00%      0,18     0,05    0,00%  _nlist_status_msg
( n-panelize < ~/lsoflsof; )  10,88s user 0,52s system 93% cpu 12,153 total

RES: 433M

no patches:
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)   92       77542,89   842,86   54,42%  77542,89   842,86   54,42%  _nlist_print_with_ansi
 2)    1       142460,54 142460,54   99,98%  61816,42 61816,42   43,38%  n-list
 3)    4       80130,34 20032,59   56,24%   2587,46   646,86    1,82%  n-list-draw
 4)    4         456,02   114,01    0,32%    362,14    90,54    0,25%  n-list-input
 5)    4         117,37    29,34    0,08%    117,37    29,34    0,08%  _nlist_cursor_visibility
 6)    4          28,08     7,02    0,02%     28,08     7,02    0,02%  _nlist_status_msg
 7)    4          19,50     4,88    0,01%     18,71     4,68    0,01%  _nlist_setup_user_vars
 8)    1          26,80    26,80    0,02%     11,03    11,03    0,01%  _nlist_exit
( n-panelize < ~/lsoflsof; )  143,73s user 0,54s system 99% cpu 2:25,15 total

RES: 432M

5.0.2 - the test is biased because I browsed list for ~10 seconds before the
script catched "second breath" and started to work fast. But the user time here
is quite accurate.
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)  828       43962,09    53,09   48,09%  43962,09    53,09   48,09%  _nlist_print_with_ansi
 2)    1       91406,33 91406,33   99,99%  40327,39 40327,39   44,12%  n-list
 3)   36       50295,77  1397,10   55,02%   6333,68   175,94    6,93%  n-list-draw
 4)   36         602,80    16,74    0,66%    538,63    14,96    0,59%  n-list-input
 5)   36         108,53     3,01    0,12%     84,31     2,34    0,09%  _nlist_setup_user_vars
 6)   36          63,53     1,76    0,07%     63,53     1,76    0,07%  _nlist_status_msg
 7)    4          62,24    15,56    0,07%     62,24    15,56    0,07%  _nlist_cursor_visibility
 8)   34          24,22     0,71    0,03%     24,22     0,71    0,03%  _nlist_compute_user_vars_difference
( n-panelize < ~/lsoflsof; )  84,60s user 0,42s system 90% cpu 1:33,78 total

RES: 400M