On Friday, September 12, 2014 2:35:40 AM UTC+12, Charles Campbell wrote:
> Have you tried profiling?

Just did (about a decade since I last used a profiler at this, C, level).  
Compiled and linked with -pg, as advised in src/Makefile.

Execution time is dominated by ml_updatechunk in memline.c.  Here are the first 
few lines of gprof output:

  %   cumulative   self              self     total           
 time   seconds   seconds    calls   s/call   s/call  name    
 89.97     52.85    52.85 16264345     0.00     0.00  ml_updatechunk
  4.90     55.73     2.88        1     2.88    58.62  readfile
  1.16     56.41     0.68 108763323    0.00     0.00  utf_char2len
  1.07     57.04     0.63 108763323    0.00     0.00  utf_char2bytes
  0.73     57.47     0.43 10596718     0.00     0.00  ml_upd_block0
  0.51     57.77     0.30  5667628     0.00     0.00  ml_delete_int
  0.41     58.01     0.24 16371692     0.00     0.00  ml_find_line
  0.27     58.17     0.16 10596717     0.00     0.00  ml_append
  0.22     58.30     0.13  5667628     0.00     0.00  ml_delete
  0.15     58.39     0.09 16264348     0.00     0.00  netbeans_active
  0.15     58.48     0.09  5667630     0.00     0.00  ml_flush_line

compare with the quick run with the reverse sorted file:
  %   cumulative   self              self     total           
 time   seconds   seconds    calls   s/call   s/call  name    
 48.67      2.57     2.57        1     2.57     5.19  readfile
 19.51      3.60     1.03 108763323    0.00     0.00  utf_char2bytes
 17.42      4.52     0.92 108763323    0.00     0.00  utf_char2len
  4.55      4.76     0.24  4929091     0.00     0.00  ml_upd_block0
  2.27      4.88     0.12  4979284     0.00     0.00  ml_find_line
  1.89      4.98     0.10  4929091     0.00     0.00  ml_updatechunk
  1.52      5.06     0.08  4929090     0.00     0.00  ml_append
  1.33      5.13     0.07  4929094     0.00     0.00  netbeans_active
  1.33      5.20     0.07                             dbcs_off2cells
  0.38      5.22     0.02   226070     0.00     0.00  mf_get

In the slow run, ml_updatechunk has been called more than 3 times the number of 
lines in the file, instead of just once per line. That increased number of 
calls does not explain the ~500 fold increase in time spent in ml_updatechunk; 
something appears to be going badly wrong in there.

To go further on this I'll have to learn what ml_updatechunk does, and maybe 
break it up to find its hot spots.  Also, a profile-enabled glibc might be 
illuminating, or maybe just the allocator.  I seem to recall some comments in 
the vim source somewhere about that, I'll look for them.

Regards, John Little

-- 
-- 
You received this message from the "vim_use" maillist.
Do not top-post! Type your reply below the text you are replying to.
For more information, visit http://www.vim.org/maillist.php

--- 
You received this message because you are subscribed to the Google Groups 
"vim_use" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to [email protected].
For more options, visit https://groups.google.com/d/optout.

Reply via email to