Re: profiling emacs-23.1 vs emacs-22.3

[Dan Nicolaescu <dann@ics.uci.edu>]

Here's another data point.  This time from running a process (a
recursive grep for setq in the lisp subdirectory):

emacs --batch --eval '(progn (call-process "grep" nil (get-buffer-create "tmp") t "--color=never" "-r" "setq" "/tmp/Emacs-CVS/emacs/lisp/") (set-buffer "tmp") (write-file "/tmp/23"))'

emacs-22.3:
Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 20.59      0.07     0.07      111     0.63     0.63  decode_eol
 14.71      0.12     0.05     5018     0.01     0.01  re_search_2
 14.71      0.17     0.05      138     0.36     1.12  decode_coding
 11.76      0.21     0.04        1    40.00    40.00  find_safe_codings
  8.82      0.24     0.03      224     0.13     0.13  detect_coding_mask
  5.88      0.26     0.02        1    20.00    20.00  unencodable_char_position
  2.94      0.27     0.01  1401155     0.00     0.00  Faref
  2.94      0.28     0.01  1396772     0.00     0.00  translate_char
  2.94      0.29     0.01     6955     0.00     0.00  Fstring_equal
  2.94      0.30     0.01     3180     0.00     0.00  allocate_vector
  2.94      0.31     0.01     2062     0.00     0.00  mark_object
  2.94      0.32     0.01      509     0.02     0.02  analyze_first
  2.94      0.33     0.01      392     0.03     0.03  buf_charpos_to_bytepos
  2.94      0.34     0.01        5     2.00     2.51  Faccessible_keymaps
  0.00      0.34     0.00    84102     0.00     0.00  readchar
  0.00      0.34     0.00    22523     0.00     0.00  re_match_2_internal
[snip]



CVS HEAD:

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 18.18      0.06     0.06  2097964     0.00     0.00  mark_object
 15.15      0.11     0.05      966     0.05     0.05  consume_chars
  9.09      0.14     0.03      388     0.08     0.08  encode_coding_raw_text
  9.09      0.17     0.03      219     0.14     0.15  produce_chars
  6.06      0.19     0.02      140     0.14     0.21  detect_coding
  6.06      0.21     0.02       98     0.20     0.20  decode_coding_iso_2022
  6.06      0.23     0.02        1    20.00    20.00  Funencodable_char_position
  3.03      0.24     0.01   377383     0.00     0.00  read_hex
  3.03      0.25     0.01   219810     0.00     0.00  char_table_ref
  3.03      0.26     0.01     8391     0.00     0.00  mem_insert
  3.03      0.27     0.01     7036     0.00     0.00  Fcar
  3.03      0.28     0.01     1472     0.01     0.01  emacs_read
  3.03      0.29     0.01      467     0.02     0.02  Ftext_properties_at
  3.03      0.30     0.01      201     0.05     0.05  gap_left
  3.03      0.31     0.01       64     0.16     0.43  load_charset_map
  3.03      0.32     0.01        4     2.50     2.50  Fkill_buffer
  3.03      0.33     0.01        4     2.50     2.50  detect_coding_iso_2022
  0.00      0.33     0.00   221420     0.00     0.00  char_table_set
  0.00      0.33     0.00   106914     0.00     0.00  readchar
  0.00      0.33     0.00    82427     0.00     0.00  Faref
[snip]

so we have a lot more calls to mark_object.  They do not matter much
from the performance point of view in this particular case, but it
should be interesting to find out why we get them now.