So far, it seems that everyone's profiling on the Lisp level.
But C
level profiling could give much better results. Has anyone successfully
used Gprof or the VC++ tools for doing C-level profiling? When i tried
in the past, i got stuck; things crashed and i couldn't get them to
work. Any success stories and instructions telling what exactly to do?
Under Linux you could use oprofile
(
http://oprofile.sourceforge.net/download/). It isn't difficult to use
and does not require profiler instrumentation when compiling (debugging
information is useful, though). It also profiles the entire system, so
it can show you how much time you spend running X11 functions.
It's simple to use. After compiling and loading the module, one does:
opcontrol -s
run xemacs, do things, possibly for hours,
then:
opcontrol --dump
opreport -algx /local/bin/xemacs-21.5-b20
it produces something of this kind (sample from a several-minute gnus session):
Profiling through timer interrupt
samples cum. samples % cum. % linenr info symbol name
1072 1072 36.3267 36.3267 alloc.c:4194 mark_object
631 1703 21.3826 57.7093 alloc.c:5317 garbage_collect_1
255 1958 8.6411 66.3504 alloc.c:1164 mark_cons
74 2032 2.5076 68.8580 regex.c:4769
re_match_2_internal
70 2102 2.3721 71.2301 bytecode.c:640
execute_optimized_program
70 2172 2.3721 73.6022 regex.c:4251 sys_re_search_2
31 2203 1.0505 74.6527 eval.c:3766 Ffuncall
30 2233 1.0166 75.6693 fns.c:1400 Fmemq
30 2263 1.0166 76.6859 insdel.c:1068
buffer_insert_string_1
25 2288 0.8472 77.5330 symbols.c:91 mark_symbol
25 2313 0.8472 78.3802 dumper.c:243
pdump_objects_unmark
19 2332 0.6438 79.0241 alloc.c:2344 mark_string
18 2350 0.6100 79.6340 alloc.c:1526 mark_vector
15 2365 0.5083 80.1423 fns.c:620 concat
14 2379 0.4744 80.6167 extents.c:2129 map_extents
13 2392 0.4405 81.0573 fns.c:1441 Fassoc
13 2405 0.4405 81.4978 fns.c:290 Fstring_equal
13 2418 0.4405 81.9383 fns.c:2820 internal_equal
13 2431 0.4405 82.3789 bytecode.c:2135
mark_compiled_function
12 2443 0.4066 82.7855 symbols.c:1065
do_symval_forwarding
11 2454 0.3728 83.1583 file-coding.c:2719
no_conversion_convert
10 2464 0.3389 83.4971 fns.c:1511 assq_no_quit
10 2474 0.3389 83.8360 fns.c:3026 bytecode_nconc2
10 2484 0.3389 84.1749 symbols.c:1526
find_symbol_value_1
10 2494 0.3389 84.5137 elhash.c:243 mark_hash_table
10 2504 0.3389 84.8526 buffer.c:1492
set_buffer_internal
9 2513 0.3050 85.1576 bytecode.c:1731 optimize_byte_code
8 2521 0.2711 85.4287 eval.c:3475 Feval
8 2529 0.2711 85.6998 search.c:1549 boyer_moore
[...rest snipped...]
opcontrol --reset resets the counters, opcontrol -t stops the profiling.
--J.