[Top][All Lists]
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: slow output in *compilation* buffer
|
From: |
Dan Nicolaescu |
|
Subject: |
Re: slow output in *compilation* buffer |
|
Date: |
Mon, 24 Aug 2009 13:24:57 -0700 (PDT) |
Dan Nicolaescu <address@hidden> writes:
> Stefan Monnier <address@hidden> writes:
>
> > > % cumulative self self total
> > > time seconds seconds calls s/call s/call name
> > > 31.19 2.72 2.72 52618323 0.00 0.00
lookup_char_property
> > > 20.30 4.49 1.77 51726150 0.00 0.00
previous_interval
> > > 12.16 5.55 1.06 208889310 0.00 0.00 Fcdr
> > > 5.85 6.06 0.51 52444384 0.00 0.00 Fassq
> > > 5.39 6.53 0.47 4573 0.00 0.00
Fprevious_single_property_change
> > > 2.64 6.76 0.23 8860105 0.00 0.00 mark_object
> > > 2.52 6.98 0.22 10621 0.00 0.00 Fsetcar
> > > 2.29 7.18 0.20 52618300 0.00 0.00 textget
> > > 1.83 7.34 0.16 59828 0.00 0.00 re_search_2
> > > 1.72 7.49 0.15 305181 0.00 0.00
re_match_2_internal
> > > 1.03 7.58 0.09 82087 0.00 0.00 Fbyte_code
> > > 0.80 7.65 0.07 9094 0.00 0.00
adjust_for_invis_intang
> > > 0.80 7.72 0.07 581767 0.00 0.00 find_interval
> > > 0.69 7.78 0.06 295253 0.00 0.00 next_interval
> > > 0.69 7.84 0.06 21 0.00 0.02 Fgarbage_collect
> > > 0.57 7.89 0.05 23886 0.00 0.00 mark_vectorlike
> >
> > compile.el does its work via font-lock, so I do expect most/all of the
> > time to be spent there.
>
> Another data point, take the process output out of the equation:
> grep -nH -e emacs *.el */*.el > /tmp/t.grep
>
> emacs -Q /tmp/t.grep
> M-x compilation-mode RET
> M-x font-lock-fontify-buffer RET [this might not be necessary]
>
>
> % cumulative self self total
> time seconds seconds calls s/call s/call name
> 35.13 5.54 5.54 102003560 0.00 0.00 lookup_char_property
> 22.45 9.08 3.54 101705026 0.00 0.00 previous_interval
> 13.57 11.22 2.14 408455379 0.00 0.00 Fcdr
> 6.59 12.26 1.04 9018 0.00 0.00
Fprevious_single_property_change
> 5.83 13.18 0.92 101946549 0.00 0.00 Fassq
> 2.98 13.65 0.47 18460 0.00 0.00 Fsetcar
> 1.71 13.92 0.27 9370435 0.00 0.00 mark_object
> 1.59 14.17 0.25 102003522 0.00 0.00 textget
> 1.46 14.40 0.23 54635 0.00 0.00 re_search_2
> 1.14 14.58 0.18 134737 0.00 0.00 Fbyte_code
> 0.95 14.73 0.15
adjust_for_invis_intang
> 0.95 14.88 0.15 525629 0.00 0.00 re_match_2_internal
> 0.82 15.01 0.13 262725 0.00 0.00 next_interval
> 0.63 15.11 0.10 2698 0.00 0.00 Frassq
> 0.44 15.18 0.07 22 0.00 0.02 Fgarbage_collect
> 0.32 15.23 0.05 541671 0.00 0.00 Ffuncall
> 0.32 15.28 0.05 22906 0.00 0.00 mark_vectorlike
> 0.19 15.31 0.03 584428 0.00 0.00 balance_an_interval
> 0.13 15.33 0.02 2333591 0.00 0.00
multibyte_char_to_unibyte_safe
> 0.13 15.35 0.02 315105 0.00 0.00 find_interval
> 0.13 15.37 0.02 133764 0.00 0.00 funcall_lambda
> 0.13 15.39 0.02 91236 0.00 0.00 add_properties
> 0.13 15.41 0.02 18261 0.00 0.00 set_point_both
> 0.13 15.43 0.02 9448 0.00 0.00
balance_intervals_internal
> 0.13 15.45 0.02 5316 0.00 0.00 set_buffer_internal_1
> 0.13 15.47 0.02 92 0.00 0.00 mark_glyph_matrix
> 0.13 15.49 0.02 Fmemory_limit
> 0.06 15.50 0.01 1006998 0.00 0.00 specbind
> 0.06 15.51 0.01 718455 0.00 0.00 Fcons
> 0.06 15.52 0.01 621053 0.00 0.00 Faref
And another data point and some explanation.
Using -Q -nw instead of just -Q:
% cumulative self self total
time seconds seconds calls s/call s/call name
34.58 5.19 5.19 101981134 0.00 0.00 lookup_char_property
21.19 8.37 3.18 101705010 0.00 0.00 previous_interval
13.06 10.33 1.96 408395117 0.00 0.00 Fcdr
6.73 11.34 1.01 9018 0.00 0.00
Fprevious_single_property_change
6.73 12.35 1.01 101923589 0.00 0.00 Fassq
3.06 12.81 0.46 18459 0.00 0.00 Fsetcar
1.93 13.10 0.29 514797 0.00 0.00 re_match_2_internal
1.73 13.36 0.26 5072134 0.00 0.00 mark_object
1.60 13.60 0.24 31816 0.00 0.00 re_search_2
1.27 13.79 0.19 133095 0.00 0.00 Fbyte_code
1.20 13.97 0.18 256789 0.00 0.00 next_interval
1.07 14.13 0.16 2555 0.00 0.00 Frassq
1.07 14.29 0.16 adjust_for_invis_intang
1.00 14.44 0.15 101981134 0.00 0.00 textget
0.40 14.50 0.06 300850 0.00 0.00 find_interval
0.40 14.56 0.06 19 0.00 0.02 Fgarbage_collect
0.27 14.60 0.04 132114 0.00 0.00 funcall_lambda
so roughly 40% less mark_object calls.
Why?
Although I use LANG=C, when using the X11 version (with this font:
-b&h-lucidatypewriter-medium-r-normal-sans-12-120-75-75-m-70-iso8859-1)
these charsets are read during startup:
emacs/etc/charsets/MULE-tibetan.map
emacs/etc/charsets/MULE-ethiopic.map
emacs/etc/charsets/MULE-ipa.map
emacs/etc/charsets/symbol.map
emacs/etc/charsets/JISX0208.map
emacs/etc/charsets/GB2312.map
emacs/etc/charsets/BIG5.map
emacs/etc/charsets/CNS-1.map
emacs/etc/charsets/KSC5601.map
and it seems that creates a lot of lisp objects.
Is it necessary to read all these charsets?
Creating that many lisp objects has second order effects on GC speed,
and cache performance.