Subject: Re: bug#29889: 27.0.50; Slow visual selection

From: Sujith <[email-masked]>
Date: Sun, 31 Dec 2017 10:55:32 +0530

Eli Zaretskii <[email-masked]> 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