bug#29889: 27.0.50; Slow visual selection

[Eli Zaretskii <eliz@gnu.org>]

On December 31, 2017 9:20:19 AM GMT+02:00, Eli Zaretskii <eliz@gnu.org> wrote:
> On December 31, 2017 7:25:32 AM GMT+02:00, Sujith <m.sujith@gmail.com>
> wrote:
> > Eli Zaretskii <eliz@gnu.org> writes:
> > > Run Emacs under 'perf' (or build with C-level profiling), and show
> > the
> > > C-level profile while moving the cursor with region highlighted? 
> > That
> > > should tell whether my hypothesis above holds any water, and if
> not,
> > > point out some other suspects.
> > 
> > I did 'perf record emacs' and then 'perf report --stdio'.
> > 
> > Profile report (just the top few lines):
> > 
> > # Overhead  Command      Shared Object               Symbol         
>  
> >                             
> > # ........  ...........  .......................... 
> > ................................
> > #
> >     41.09%  emacs        emacs-27.0.50               [.] mark_object
> > 10.90%  emacs        emacs-27.0.50               [.]
> > balance_an_interval
> >      4.23%  emacs        emacs-27.0.50               [.]
> mark_interval
> >      3.77%  emacs        emacs-27.0.50               [.] Flength
> >      3.45%  emacs        emacs-27.0.50               [.]
> sweep_strings
> >      3.11%  emacs        emacs-27.0.50               [.]
> sweep_conses
> > 2.94%  emacs        emacs-27.0.50               [.]
> > balance_intervals_internal
> >    2.85%  emacs        emacs-27.0.50               [.]
> sweep_intervals
> > 1.91%  emacs        emacs-27.0.50               [.]
> > traverse_intervals_noorder
> >    1.70%  emacs        emacs-27.0.50               [.]
> mark_char_table
> >      1.65%  emacs        emacs-27.0.50               [.]
> next_interval
> >     1.52%  emacs        emacs-27.0.50               [.]
> copy_intervals
> >      1.50%  emacs        emacs-27.0.50               [.] concat
> >      1.43%  emacs        emacs-27.0.50               [.]
> sweep_vectors
> > 1.28%  emacs        emacs-27.0.50               [.]
> scan_sexps_forward
> >      0.93%  emacs        emacs-27.0.50               [.] Fcons
> >     0.84%  emacs        emacs-27.0.50               [.]
> exec_byte_code
> >      0.81%  emacs        emacs-27.0.50               [.]
> sweep_symbols
> > 0.72%  emacs        emacs-27.0.50               [.]
> > re_match_2_internal
> > 
> > 
> > Using gprof with --enable-profiling, the report looks like:
> > 
> > Flat profile:
> > 
> > Each sample counts as 0.01 seconds.
> >   %   cumulative   self              self     total           
> >  time   seconds   seconds    calls  ms/call  ms/call  name    
> >  33.97      6.33     6.33 111195700     0.00     0.00  mark_object
> > 10.26      8.24     1.91 31639099     0.00     0.00 
> > balance_an_interval
> >   3.54      8.90     0.66 22239242     0.00     0.00  mark_interval
> > 2.95      9.45     0.55     7431     0.07     0.25 
> > balance_intervals_internal
> >   2.79      9.97     0.52      223     2.33    10.50  sweep_strings
> >   2.42     10.42     0.45  7826133     0.00     0.00  Flength
> >   2.42     10.87     0.45      223     2.02     2.26  sweep_conses
> >   2.09     11.26     0.39      223     1.75     1.89 
> sweep_intervals
> >   2.09     11.65     0.39   419665     0.00     0.00  assq_no_quit
> >   2.04     12.03     0.38 11148108     0.00     0.00  next_interval
> > 1.93     12.39     0.36    42738     0.01     0.02 
> scan_sexps_forward
> >   1.88     12.74     0.35  7482960     0.00     0.00  concat
> > 1.66     13.05     0.31 24810407     0.00     0.00 
> > FETCH_MULTIBYTE_CHAR
> >   1.40     13.31     0.26    34595     0.01     0.01 
> mark_char_table
> > 1.34     13.56     0.25     7431     0.03     0.12 
> > traverse_intervals_noorder
> >   1.29     13.80     0.24   422335     0.00     0.00  exec_byte_code
> >   1.18     14.02     0.22      223     0.99     1.14  sweep_vectors
> >   1.07     14.22     0.20      282     0.71     0.71  evxprintf
> 
> Thanks a lot!
> 
> Since mark_object appears high in the profile, could you please
> rerun the experiment after setting gc-cons-threshold and
> gc-cons-percentage so as to avoid GC for the time of the expdriment?

Also, please profile only when you move the cursor in the last step
of the recipe.  I suspect that you profiled also the time during
fontification of the buffer in step 1, otherwise I don't understand
why balance_an_interval is called so many times.