Mercurial > hg > xemacs-beta
annotate src/profile.c @ 5307:c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
src/ChangeLog addition:
2010-11-20 Aidan Kehoe <kehoea@parhasard.net>
* abbrev.c (Fexpand_abbrev):
* alloc.c:
* alloc.c (Fmake_list):
* alloc.c (Fmake_vector):
* alloc.c (Fmake_bit_vector):
* alloc.c (Fmake_byte_code):
* alloc.c (Fmake_string):
* alloc.c (vars_of_alloc):
* bytecode.c (UNUSED):
* bytecode.c (Fbyte_code):
* chartab.c (decode_char_table_range):
* cmds.c (Fself_insert_command):
* data.c (check_integer_range):
* data.c (Fnatnump):
* data.c (Fnonnegativep):
* data.c (Fstring_to_number):
* elhash.c (hash_table_size_validate):
* elhash.c (decode_hash_table_size):
* eval.c (Fbacktrace_frame):
* event-stream.c (lisp_number_to_milliseconds):
* event-stream.c (Faccept_process_output):
* event-stream.c (Frecent_keys):
* event-stream.c (Fdispatch_event):
* events.c (Fmake_event):
* events.c (Fevent_timestamp):
* events.c (Fevent_timestamp_lessp):
* events.h:
* events.h (struct command_builder):
* file-coding.c (gzip_putprop):
* fns.c:
* fns.c (check_sequence_range):
* fns.c (Frandom):
* fns.c (Fnthcdr):
* fns.c (Flast):
* fns.c (Fnbutlast):
* fns.c (Fbutlast):
* fns.c (Fmember):
* fns.c (Ffill):
* fns.c (Freduce):
* fns.c (replace_string_range_1):
* fns.c (Freplace):
* font-mgr.c (Ffc_pattern_get):
* frame-msw.c (msprinter_set_frame_properties):
* glyphs.c (check_valid_xbm_inline):
* indent.c (Fmove_to_column):
* intl-win32.c (mswindows_multibyte_to_unicode_putprop):
* lisp.h:
* lisp.h (ARRAY_DIMENSION_LIMIT):
* lread.c (decode_mode_1):
* mule-ccl.c (ccl_get_compiled_code):
* number.h:
* process-unix.c (unix_open_multicast_group):
* process.c (Fset_process_window_size):
* profile.c (Fstart_profiling):
* unicode.c (Funicode_to_char):
Change NATNUMP to return 1 for positive bignums; changes uses of
it and of CHECK_NATNUM appropriately, usually by checking for an
integer in an appropriate range.
Add array-dimension-limit and use it in #'make-vector,
#'make-string. Add array-total-size-limit, array-rank-limit while
we're at it, for the sake of any Common Lisp-oriented code that
uses these limits.
Rename check_int_range to check_integer_range, have it take
Lisp_Objects (and thus bignums) instead.
Remove bignum_butlast(), just set int_n to an appropriately large
integer if N is a bignum.
Accept bignums in check_sequence_range(), change the functions
that use check_sequence_range() appropriately.
Move the definition of NATNUMP() to number.h; document why it's a
reasonable name, contradicting an old comment.
tests/ChangeLog addition:
2010-11-20 Aidan Kehoe <kehoea@parhasard.net>
* automated/lisp-tests.el:
* automated/lisp-tests.el (featurep):
* automated/lisp-tests.el (wrong-type-argument):
* automated/mule-tests.el (featurep):
Check for args-out-of-range errors instead of wrong-type-argument
errors in various places when code is handed a large bignum
instead of a fixnum.
Also check for the wrong-type-argument errors when giving the same
code a non-integer value.
| author | Aidan Kehoe <kehoea@parhasard.net> |
|---|---|
| date | Sat, 20 Nov 2010 16:49:11 +0000 |
| parents | 71ee43b8a74d |
| children | db326b8fe982 8d29f1c4bb98 |
| rev | line source |
|---|---|
| 428 | 1 /* Why the hell is XEmacs so fucking slow? |
|
5169
6c6d78781d59
cleanup of code related to xfree(), better KKCC backtrace capabilities, document XD_INLINE_LISP_OBJECT_BLOCK_PTR, fix some memory leaks, other code cleanup
Ben Wing <ben@xemacs.org>
parents:
5038
diff
changeset
|
2 Copyright (C) 1996, 2002, 2003, 2004, 2010 Ben Wing. |
| 428 | 3 Copyright (C) 1998 Free Software Foundation, Inc. |
| 4 | |
| 5 This file is part of XEmacs. | |
| 6 | |
| 7 XEmacs is free software; you can redistribute it and/or modify it | |
| 8 under the terms of the GNU General Public License as published by the | |
| 9 Free Software Foundation; either version 2, or (at your option) any | |
| 10 later version. | |
| 11 | |
| 12 XEmacs is distributed in the hope that it will be useful, but WITHOUT | |
| 13 ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or | |
| 14 FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License | |
| 15 for more details. | |
| 16 | |
| 17 You should have received a copy of the GNU General Public License | |
| 18 along with XEmacs; see the file COPYING. If not, write to | |
| 19 the Free Software Foundation, Inc., 59 Temple Place - Suite 330, | |
| 20 Boston, MA 02111-1307, USA. */ | |
| 21 | |
| 22 #include <config.h> | |
| 23 #include "lisp.h" | |
| 24 | |
| 25 #include "backtrace.h" | |
| 26 #include "bytecode.h" | |
| 27 #include "elhash.h" | |
|
5169
6c6d78781d59
cleanup of code related to xfree(), better KKCC backtrace capabilities, document XD_INLINE_LISP_OBJECT_BLOCK_PTR, fix some memory leaks, other code cleanup
Ben Wing <ben@xemacs.org>
parents:
5038
diff
changeset
|
28 #include "gc.h" |
| 428 | 29 #include "hash.h" |
| 1315 | 30 #include "profile.h" |
| 428 | 31 |
| 32 #include "syssignal.h" | |
| 33 #include "systime.h" | |
| 34 | |
| 611 | 35 #ifndef HAVE_SETITIMER |
| 36 #error Sorry charlie. We need a scalpel and all we have is a lawnmower. | |
| 37 #endif | |
| 38 | |
| 1292 | 39 #ifdef WIN32_ANY |
| 40 int mswindows_is_blocking; | |
| 41 #endif | |
| 42 | |
| 2367 | 43 /* Written by Ben Wing. */ |
| 428 | 44 |
| 2367 | 45 /* |
| 428 | 46 |
| 2367 | 47 Documented in |
| 428 | 48 |
| 2367 | 49 (Info-goto-node "(internals)Profiling") |
| 1292 | 50 */ |
| 51 | |
| 52 /* We use a plain table here because we're recording inside of a signal | |
| 53 handler. */ | |
| 428 | 54 static struct hash_table *big_profile_table; |
| 1292 | 55 Lisp_Object Vtotal_timing_profile_table; |
| 428 | 56 Lisp_Object Vcall_count_profile_table; |
| 1292 | 57 Lisp_Object Vtotal_gc_usage_profile_table; |
| 58 Lisp_Object Vgc_usage_profile_table; | |
| 59 | |
| 60 extern int lisp_eval_depth; | |
| 61 | |
| 62 extern EMACS_UINT total_consing; | |
| 63 static volatile EMACS_UINT total_ticks; | |
| 428 | 64 |
| 458 | 65 Fixnum default_profiling_interval; |
| 428 | 66 |
| 67 int profiling_active; | |
| 68 | |
| 1292 | 69 static Lisp_Object QSprocessing_events_at_top_level; |
| 70 static Lisp_Object QSunknown, QSprofile_overhead; | |
| 71 | |
| 2514 | 72 #ifdef DEBUG_XEMACS |
| 73 /* For temporary profiling */ | |
| 74 Lisp_Object QSin_temp_spot_1; | |
| 75 Lisp_Object QSin_temp_spot_2; | |
| 76 Lisp_Object QSin_temp_spot_3; | |
| 77 Lisp_Object QSin_temp_spot_4; | |
| 78 Lisp_Object QSin_temp_spot_5; | |
| 79 #endif /* DEBUG_XEMACS */ | |
| 80 | |
| 1292 | 81 static Lisp_Object Qtiming, Qtotal_timing, Qcall_count; |
| 82 static Lisp_Object Qgc_usage, Qtotal_gc_usage; | |
| 83 | |
| 84 /* This needs to be >= the total number of defined internal sections, | |
| 85 plus 1 or 2?? Set it extra big just to be ultra-paranoid. */ | |
| 86 #define EXTRA_BREATHING_ROOM 100 | |
| 428 | 87 |
| 1292 | 88 /* We use profiling_lock to prevent the signal handler from writing to |
| 89 the table while another routine is operating on it. We also set | |
| 90 profiling_lock in case the timeout between signal calls is short | |
| 91 enough to catch us while we're already in there. */ | |
| 92 static volatile int profiling_lock; | |
| 428 | 93 |
| 1292 | 94 /* Whether we're in the process of doing *any* profiling-related stuff. |
| 95 Used to indicate amount of time spent profiling. */ | |
| 96 static int in_profiling; | |
| 97 | |
| 98 #if 0 /* #### for KKCC, eventually */ | |
| 1123 | 99 |
| 1292 | 100 static const struct memory_description hentry_description_1[] = { |
| 101 { XD_LISP_OBJECT, offsetof (hentry, key) }, | |
| 102 { XD_END } | |
| 103 }; | |
| 104 | |
| 105 static const struct sized_memory_description hentry_description = { | |
| 106 sizeof (hentry), | |
| 107 hentry_description_1 | |
| 108 }; | |
| 428 | 109 |
| 1292 | 110 static const struct memory_description plain_hash_table_description_1[] = { |
| 111 { XD_ELEMCOUNT, offsetof (struct hash_table, size) }, | |
| 2367 | 112 { XD_BLOCK_PTR, offsetof (struct hash_table, harray), XD_INDIRECT (0, 0), |
| 2551 | 113 { &hentry_description } }, |
| 1292 | 114 { XD_END } |
| 115 }; | |
| 116 | |
| 117 static const struct sized_memory_description plain_hash_table_description = { | |
| 118 sizeof (struct hash_table), | |
| 119 plain_hash_table_description_1 | |
| 120 }; | |
| 121 | |
| 122 #endif /* 0 */ | |
| 1123 | 123 |
| 124 static void | |
| 125 create_timing_profile_table (void) | |
| 126 { | |
| 1292 | 127 /* The hash code can safely be called from a signal handler except when |
| 128 it has to grow the hash table. In this case, it calls realloc(), | |
| 5038 | 129 which is not (in general) reentrant. The way we deal with this is |
| 1292 | 130 documented at the top of this file. */ |
| 1123 | 131 if (!big_profile_table) |
| 1292 | 132 big_profile_table = make_hash_table (2000); |
| 133 } | |
| 134 | |
| 135 static void | |
| 136 create_profile_tables (void) | |
| 137 { | |
| 138 create_timing_profile_table (); | |
| 139 if (NILP (Vtotal_timing_profile_table)) | |
| 140 Vtotal_timing_profile_table = | |
|
5191
71ee43b8a74d
Add #'equalp as a hash test by default; add #'define-hash-table-test, GNU API
Aidan Kehoe <kehoea@parhasard.net>
parents:
5169
diff
changeset
|
141 make_lisp_hash_table (1000, HASH_TABLE_NON_WEAK, Qeq); |
| 1292 | 142 if (NILP (Vcall_count_profile_table)) |
| 143 Vcall_count_profile_table = | |
|
5191
71ee43b8a74d
Add #'equalp as a hash test by default; add #'define-hash-table-test, GNU API
Aidan Kehoe <kehoea@parhasard.net>
parents:
5169
diff
changeset
|
144 make_lisp_hash_table (1000, HASH_TABLE_NON_WEAK, Qeq); |
| 1292 | 145 if (NILP (Vgc_usage_profile_table)) |
| 146 Vgc_usage_profile_table = | |
|
5191
71ee43b8a74d
Add #'equalp as a hash test by default; add #'define-hash-table-test, GNU API
Aidan Kehoe <kehoea@parhasard.net>
parents:
5169
diff
changeset
|
147 make_lisp_hash_table (1000, HASH_TABLE_NON_WEAK, Qeq); |
| 1292 | 148 if (NILP (Vtotal_gc_usage_profile_table)) |
| 149 Vtotal_gc_usage_profile_table = | |
|
5191
71ee43b8a74d
Add #'equalp as a hash test by default; add #'define-hash-table-test, GNU API
Aidan Kehoe <kehoea@parhasard.net>
parents:
5169
diff
changeset
|
150 make_lisp_hash_table (1000, HASH_TABLE_NON_WEAK, Qeq); |
| 1292 | 151 } |
| 152 | |
| 153 static Lisp_Object | |
| 154 current_profile_function (void) | |
| 155 { | |
| 156 Lisp_Object fun; | |
| 157 struct backtrace *bt = backtrace_list; | |
| 158 | |
| 159 /* 2 because we set in_profiling when we entered the current routine. */ | |
| 160 if (in_profiling >= 2) | |
| 161 return QSprofile_overhead; | |
| 162 | |
| 163 /* Find a function actually being called. Potentially (?) there could be | |
| 164 a number of non-calling funs -- calling foo autoloads, which tries to | |
| 165 call bar, but requires evalling its args first, which calls baz, ... | |
| 166 If profiling was not enabled when the function was called, just treat | |
| 167 the function as actually called, because the info about whether we've | |
| 168 finished the preamble will not have been recorded. */ | |
| 169 for (; bt && !bt->function_being_called; bt = bt->next) | |
| 170 ; | |
| 171 | |
| 172 if (bt) | |
| 173 { | |
| 174 fun = *bt->function; | |
| 175 | |
| 176 if (!SYMBOLP (fun) | |
| 177 && !COMPILED_FUNCTIONP (fun) | |
| 178 && !SUBRP (fun) | |
| 179 && !CONSP (fun) | |
| 180 && !STRINGP (fun)) | |
| 181 fun = QSunknown; | |
| 182 } | |
| 183 else | |
| 184 fun = QSprocessing_events_at_top_level; | |
| 185 return fun; | |
| 186 } | |
| 187 | |
| 188 void | |
| 189 profile_record_consing (EMACS_INT size) | |
| 190 { | |
| 191 in_profiling++; | |
| 2421 | 192 inchash_eq (current_profile_function (), Vgc_usage_profile_table, size); |
| 1292 | 193 in_profiling--; |
| 194 } | |
| 195 | |
| 196 void | |
| 197 profile_record_unconsing (EMACS_INT size) | |
| 198 { | |
| 199 /* If we don't want to record values less than 0, change this; but then | |
| 200 the totals won't be accurate. */ | |
| 201 profile_record_consing (-size); | |
| 1123 | 202 } |
| 203 | |
| 1292 | 204 inline static void |
| 205 profile_sow_backtrace (struct backtrace *bt) | |
| 428 | 206 { |
| 1292 | 207 bt->current_total_timing_val = |
| 208 XINT (Fgethash (*bt->function, Vtotal_timing_profile_table, Qzero)); | |
| 209 bt->current_total_gc_usage_val = | |
| 210 XINT (Fgethash (*bt->function, Vtotal_gc_usage_profile_table, Qzero)); | |
| 211 bt->function_being_called = 1; | |
| 212 /* Need to think carefully about the exact order of operations here | |
| 213 so that we don't end up with totals being less than function-only | |
| 214 values; */ | |
| 215 bt->total_consing_at_start = total_consing; | |
| 216 /* Order of operation is tricky here because we want the total function | |
| 217 time to be as close as possible to (and absolutely not less than) the | |
| 218 function-only time. From the sigprof-handler's perspective, the | |
| 219 function is "entered" the moment we finish executing the | |
| 220 in_profiling-- statement below, and ends the moment we finish | |
| 221 executing the in_profiling++ statement in | |
| 222 profile_record_just_called(). By recording the tick value as close as | |
| 223 possible to the "in-function" window but not in it, we satisfy the | |
| 224 conditions just mentioned. */ | |
| 225 bt->total_ticks_at_start = total_ticks; | |
| 226 } | |
| 428 | 227 |
| 1292 | 228 void |
| 229 profile_record_about_to_call (struct backtrace *bt) | |
| 230 { | |
| 231 in_profiling++; | |
| 232 profiling_lock = 1; | |
| 233 /* See comments in create_timing_profile_table(). */ | |
| 234 pregrow_hash_table_if_necessary (big_profile_table, EXTRA_BREATHING_ROOM); | |
| 235 profiling_lock = 0; | |
| 2421 | 236 inchash_eq (*bt->function, Vcall_count_profile_table, 1); |
| 1292 | 237 /* This may be set if the function was in its preamble at the time that |
| 238 `start-profiling' was called. If so, we shouldn't reset the values | |
| 239 because we may get inconsistent results, since we have already started | |
| 240 recording ticks and consing for the function. */ | |
| 241 if (!bt->function_being_called) | |
| 242 profile_sow_backtrace (bt); | |
| 243 in_profiling--; | |
| 244 } | |
| 428 | 245 |
| 1292 | 246 inline static void |
| 247 profile_reap_backtrace (struct backtrace *bt) | |
| 248 { | |
| 249 EMACS_UINT ticks; | |
| 250 /* The following statement *MUST* come directly after the preceding one! | |
| 251 See the comment above. */ | |
| 252 ticks = total_ticks; | |
| 253 /* We need to reset the "in-function" flag here. Otherwise the sigprof | |
| 254 handler will record more ticks for the function while the post-amble | |
| 255 is executing, and its value will be > our total value. */ | |
| 256 bt->function_being_called = 0; | |
| 257 Fputhash (*bt->function, | |
| 258 /* This works even when the total_ticks value has overwrapped. | |
| 259 Same for total_consing below. */ | |
| 260 make_int ((EMACS_INT) (ticks - bt->total_ticks_at_start) | |
| 261 + bt->current_total_timing_val), | |
| 262 Vtotal_timing_profile_table); | |
| 263 Fputhash (*bt->function, | |
| 264 make_int ((EMACS_INT) | |
| 265 (total_consing - bt->total_consing_at_start) | |
| 266 + bt->current_total_gc_usage_val), | |
| 267 Vtotal_gc_usage_profile_table); | |
| 268 } | |
| 269 | |
| 270 void | |
| 271 profile_record_just_called (struct backtrace *bt) | |
| 272 { | |
| 273 in_profiling++; | |
| 274 profile_reap_backtrace (bt); | |
| 275 in_profiling--; | |
| 276 } | |
| 277 | |
| 278 /* Called when unwinding the catch stack after a throw or signal, to | |
| 279 note that we are exiting the function. */ | |
| 280 void | |
| 281 profile_record_unwind (struct backtrace *bt) | |
| 282 { | |
| 283 /* We may have thrown while still in a function's preamble. */ | |
| 284 if (bt->function_being_called) | |
| 285 profile_record_just_called (bt); | |
| 428 | 286 } |
| 287 | |
| 288 static SIGTYPE | |
| 2286 | 289 sigprof_handler (int UNUSED (signo)) |
| 428 | 290 { |
| 1292 | 291 #ifdef WIN32_ANY |
| 292 /* Windows unfortunately does not have any such thing as setitimer | |
| 293 (ITIMER_PROF, ...), which runs in process time. Everything is real | |
| 294 time. So to get slightly more reasonable results, ignore completely | |
| 295 the times when we're blocking. Same applies, of course, to Cygwin. */ | |
| 296 if (mswindows_is_blocking) | |
| 297 return; | |
| 298 #endif | |
| 299 | |
| 300 in_profiling++; | |
| 301 total_ticks++; | |
| 302 | |
| 428 | 303 /* Don't do anything if we are shutting down, or are doing a maphash |
| 304 or clrhash on the table. */ | |
| 1292 | 305 if (!profiling_lock && !preparing_for_armageddon) |
| 428 | 306 { |
| 1292 | 307 Lisp_Object fun = current_profile_function (); |
| 428 | 308 |
| 309 /* If something below causes an error to be signaled, we'll | |
| 310 not correctly reset this flag. But we'll be in worse shape | |
| 311 than that anyways, since we'll longjmp back to the last | |
| 312 condition case. */ | |
| 1292 | 313 profiling_lock = 1; |
| 428 | 314 |
| 315 { | |
| 316 long count; | |
| 442 | 317 const void *vval; |
| 428 | 318 |
| 5013 | 319 if (gethash (STORE_LISP_IN_VOID (fun), big_profile_table, &vval)) |
| 428 | 320 count = (long) vval; |
| 321 else | |
| 322 count = 0; | |
| 323 count++; | |
| 442 | 324 vval = (const void *) count; |
| 5013 | 325 puthash (STORE_LISP_IN_VOID (fun), (void *) vval, big_profile_table); |
| 428 | 326 } |
| 327 | |
| 1292 | 328 profiling_lock = 0; |
| 428 | 329 } |
| 1292 | 330 in_profiling--; |
| 428 | 331 } |
| 332 | |
| 1292 | 333 DEFUN ("start-profiling", Fstart_profiling, 0, 1, "", /* |
| 428 | 334 Start profiling, with profile queries every MICROSECS. |
| 335 If MICROSECS is nil or omitted, the value of `default-profiling-interval' | |
| 336 is used. | |
| 337 | |
| 1123 | 338 Information on function timings and call counts is currently recorded. |
| 1292 | 339 You can retrieve the recorded profiling info using `get-profiling-info', |
| 340 or the higher-level function `profile-results'. | |
| 428 | 341 |
| 342 Starting and stopping profiling does not clear the currently recorded | |
| 343 info. Thus you can start and stop as many times as you want and everything | |
| 1292 | 344 will be properly accumulated. (To clear, use `clear-profiling-info'.) |
| 428 | 345 */ |
| 346 (microsecs)) | |
| 347 { | |
| 348 /* This function can GC */ | |
| 349 int msecs; | |
| 350 struct itimerval foo; | |
| 1292 | 351 int depth; |
| 428 | 352 |
| 1292 | 353 if (profiling_active) |
| 354 return Qnil; | |
| 355 depth = internal_bind_int (&in_profiling, 1 + in_profiling); | |
| 356 | |
| 357 create_profile_tables (); | |
| 358 /* See comments at top of file and in create_timing_profile_table(). | |
| 359 We ensure enough breathing room for all entries currently on the | |
| 360 stack. */ | |
| 361 pregrow_hash_table_if_necessary (big_profile_table, | |
| 362 EXTRA_BREATHING_ROOM + lisp_eval_depth); | |
| 428 | 363 |
| 364 if (NILP (microsecs)) | |
| 365 msecs = default_profiling_interval; | |
| 366 else | |
| 367 { | |
|
5307
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
368 #ifdef HAVE_BIGNUM |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
369 check_integer_range (microsecs, make_int (1000), make_integer (INT_MAX)); |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
370 msecs = |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
371 BIGNUMP (microsecs) ? bignum_to_int (XBIGNUM_DATA (microsecs)) : |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
372 XINT (microsecs); |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
373 #else |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
374 check_integer_range (microsecs, make_int (1000), |
|
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
375 make_integer (EMACS_INT_MAX)); |
| 428 | 376 msecs = XINT (microsecs); |
|
5307
c096d8051f89
Have NATNUMP give t for positive bignums; check limits appropriately.
Aidan Kehoe <kehoea@parhasard.net>
parents:
5191
diff
changeset
|
377 #endif |
| 428 | 378 } |
| 379 if (msecs <= 0) | |
| 380 msecs = 1000; | |
| 381 | |
| 613 | 382 set_timeout_signal (SIGPROF, sigprof_handler); |
| 1292 | 383 { |
| 384 struct backtrace *bt = backtrace_list; | |
| 385 | |
| 386 /* When we begin profiling, pretend like we just entered all the | |
| 387 functions currently on the stack. When we stop profiling, do the | |
| 388 opposite. This ensures consistent values being recorded for both | |
| 389 function-only and total in such cases. */ | |
| 390 for (; bt; bt = bt->next) | |
| 391 profile_sow_backtrace (bt); | |
| 392 } | |
| 393 profiling_active = 1; | |
| 394 profiling_lock = 0; | |
| 428 | 395 foo.it_value.tv_sec = 0; |
| 396 foo.it_value.tv_usec = msecs; | |
| 397 EMACS_NORMALIZE_TIME (foo.it_value); | |
| 398 foo.it_interval = foo.it_value; | |
| 611 | 399 qxe_setitimer (ITIMER_PROF, &foo, 0); |
| 1292 | 400 unbind_to (depth); |
| 428 | 401 return Qnil; |
| 402 } | |
| 403 | |
| 1292 | 404 DEFUN ("stop-profiling", Fstop_profiling, 0, 0, "", /* |
| 428 | 405 Stop profiling. |
| 406 */ | |
| 407 ()) | |
| 408 { | |
| 409 /* This function does not GC */ | |
| 410 struct itimerval foo; | |
| 411 | |
| 1292 | 412 if (!profiling_active) |
| 413 return Qnil; | |
| 414 in_profiling++; | |
| 428 | 415 foo.it_value.tv_sec = 0; |
| 416 foo.it_value.tv_usec = 0; | |
| 417 foo.it_interval = foo.it_value; | |
| 611 | 418 qxe_setitimer (ITIMER_PROF, &foo, 0); |
| 428 | 419 profiling_active = 0; |
| 1292 | 420 { |
| 421 struct backtrace *bt = backtrace_list; | |
| 422 | |
| 423 for (; bt; bt = bt->next) | |
| 424 profile_reap_backtrace (bt); | |
| 425 } | |
| 613 | 426 set_timeout_signal (SIGPROF, fatal_error_signal); |
| 1292 | 427 in_profiling--; |
| 428 | 428 return Qnil; |
| 429 } | |
| 430 | |
| 1123 | 431 DEFUN ("clear-profiling-info", Fclear_profiling_info, 0, 0, "", /* |
| 432 Clear out the recorded profiling info. | |
| 433 This clears both the internal timing information and the call counts in | |
| 434 `call-count-profile-table'. | |
| 435 */ | |
| 436 ()) | |
| 437 { | |
| 1292 | 438 in_profiling++; |
| 1123 | 439 /* This function does not GC */ |
| 440 if (big_profile_table) | |
| 441 { | |
| 1292 | 442 profiling_lock = 1; |
| 1123 | 443 clrhash (big_profile_table); |
| 1292 | 444 profiling_lock = 0; |
| 1123 | 445 } |
| 1292 | 446 if (!NILP (Vtotal_timing_profile_table)) |
| 447 Fclrhash (Vtotal_timing_profile_table); | |
| 1123 | 448 if (!NILP (Vcall_count_profile_table)) |
| 449 Fclrhash (Vcall_count_profile_table); | |
| 1292 | 450 if (!NILP (Vgc_usage_profile_table)) |
| 451 Fclrhash (Vgc_usage_profile_table); | |
| 452 if (!NILP (Vtotal_gc_usage_profile_table)) | |
| 453 Fclrhash (Vtotal_gc_usage_profile_table); | |
| 454 in_profiling--; | |
| 455 | |
| 1123 | 456 return Qnil; |
| 457 } | |
| 458 | |
| 428 | 459 struct get_profiling_info_closure |
| 460 { | |
| 1123 | 461 Lisp_Object timing; |
| 428 | 462 }; |
| 463 | |
| 464 static int | |
| 1123 | 465 get_profiling_info_timing_maphash (const void *void_key, |
| 466 void *void_val, | |
| 467 void *void_closure) | |
| 428 | 468 { |
| 469 /* This function does not GC */ | |
| 470 Lisp_Object key; | |
| 471 struct get_profiling_info_closure *closure | |
| 472 = (struct get_profiling_info_closure *) void_closure; | |
| 473 EMACS_INT val; | |
| 474 | |
| 5013 | 475 key = GET_LISP_FROM_VOID (void_key); |
| 428 | 476 val = (EMACS_INT) void_val; |
| 477 | |
| 1123 | 478 Fputhash (key, make_int (val), closure->timing); |
| 428 | 479 return 0; |
| 480 } | |
| 481 | |
| 1292 | 482 static Lisp_Object |
| 483 copy_hash_table_or_blank (Lisp_Object table) | |
| 484 { | |
| 485 return !NILP (table) ? Fcopy_hash_table (table) : | |
| 486 make_lisp_hash_table (100, HASH_TABLE_NON_WEAK, | |
|
5191
71ee43b8a74d
Add #'equalp as a hash test by default; add #'define-hash-table-test, GNU API
Aidan Kehoe <kehoea@parhasard.net>
parents:
5169
diff
changeset
|
487 Qeq); |
| 1292 | 488 } |
| 489 | |
| 428 | 490 DEFUN ("get-profiling-info", Fget_profiling_info, 0, 0, 0, /* |
| 1123 | 491 Return the currently recorded profiling info. |
| 492 The format is a plist of symbols describing type of info recorded and | |
| 493 an associated type-specific entry. Currently, the following info types | |
| 494 are recorded | |
| 495 | |
| 496 `timing' | |
| 1292 | 497 A hash table of function descriptions (funcallable objects or strings |
| 498 describing internal processing operations -- redisplay, garbage | |
| 499 collection, etc.), along with associated tick counts (the frequency of | |
| 500 ticks is controlled by `default-profiling-interval' or the argument to | |
| 501 `start-profiling'). | |
| 502 | |
| 503 `total-timing' | |
| 504 A hash table of function descriptions and associated timing count for | |
| 505 the function and all descendants. | |
| 1123 | 506 |
| 507 `call-count' | |
| 1292 | 508 A hash table of function descriptions and associated call counts. |
| 509 | |
| 510 `gc-usage' | |
| 511 A hash table of function descriptions and associated amount of consing. | |
| 512 | |
| 513 `total-gc-usage' | |
| 514 A hash table of function descriptions and associated amount of consing | |
| 515 in the function and all descendants. | |
| 428 | 516 */ |
| 517 ()) | |
| 518 { | |
| 519 /* This function does not GC */ | |
| 520 struct get_profiling_info_closure closure; | |
| 1292 | 521 Lisp_Object retv; |
| 522 int depth = internal_bind_int (&in_profiling, 1 + in_profiling); | |
| 523 const void *overhead; | |
| 428 | 524 |
| 1123 | 525 closure.timing = |
|
5191
71ee43b8a74d
Add #'equalp as a hash test by default; add #'define-hash-table-test, GNU API
Aidan Kehoe <kehoea@parhasard.net>
parents:
5169
diff
changeset
|
526 make_lisp_hash_table (100, HASH_TABLE_NON_WEAK, Qequal); |
| 1123 | 527 |
| 428 | 528 if (big_profile_table) |
| 529 { | |
| 1292 | 530 int count = internal_bind_int ((int *) &profiling_lock, 1); |
| 1123 | 531 maphash (get_profiling_info_timing_maphash, big_profile_table, &closure); |
| 1292 | 532 |
| 533 /* OK, OK ... the total-timing table is not going to have an entry | |
| 534 for profile overhead, and it looks strange for it to come out 0, | |
| 535 so make sure it looks reasonable. */ | |
| 5013 | 536 if (!gethash (STORE_LISP_IN_VOID (QSprofile_overhead), big_profile_table, |
| 1292 | 537 &overhead)) |
| 538 overhead = 0; | |
| 539 Fputhash (QSprofile_overhead, make_int ((EMACS_INT) overhead), | |
| 540 Vtotal_timing_profile_table); | |
| 541 | |
| 771 | 542 unbind_to (count); |
| 428 | 543 } |
| 1123 | 544 |
| 1292 | 545 retv = nconc2 (list6 (Qtiming, closure.timing, Qtotal_timing, |
| 546 copy_hash_table_or_blank (Vtotal_timing_profile_table), | |
| 547 Qcall_count, | |
| 548 copy_hash_table_or_blank (Vcall_count_profile_table)), | |
| 549 list4 (Qgc_usage, | |
| 550 copy_hash_table_or_blank (Vgc_usage_profile_table), | |
| 551 Qtotal_gc_usage, | |
| 552 copy_hash_table_or_blank (Vtotal_gc_usage_profile_table | |
| 553 ))); | |
| 554 unbind_to (depth); | |
| 555 return retv; | |
| 1123 | 556 } |
| 557 | |
| 558 static int | |
| 559 set_profiling_info_timing_maphash (Lisp_Object key, | |
| 560 Lisp_Object val, | |
| 2286 | 561 void *UNUSED (void_closure)) |
| 1123 | 562 { |
| 563 /* This function does not GC */ | |
| 564 if (!INTP (val)) | |
| 565 invalid_argument_2 | |
| 566 ("Function timing count is not an integer in given entry", | |
| 567 key, val); | |
| 568 | |
| 5013 | 569 puthash (STORE_LISP_IN_VOID (key), (void *) XINT (val), big_profile_table); |
| 1123 | 570 |
| 571 return 0; | |
| 572 } | |
| 573 | |
| 574 DEFUN ("set-profiling-info", Fset_profiling_info, 1, 1, 0, /* | |
| 575 Set the currently recorded profiling info. | |
| 576 INFO should be in the same format returned by `get-profiling-info', | |
| 577 as described there. | |
| 578 */ | |
| 579 (info)) | |
| 580 { | |
| 1292 | 581 int depth; |
| 1123 | 582 /* This function does not GC */ |
| 583 Fclear_profiling_info (); | |
| 584 | |
| 1292 | 585 depth = internal_bind_int (&in_profiling, 1 + in_profiling); |
| 1123 | 586 { |
| 587 EXTERNAL_PROPERTY_LIST_LOOP_3 (key, value, info) | |
| 588 { | |
| 589 if (EQ (key, Qtiming)) | |
| 590 { | |
| 591 CHECK_HASH_TABLE (value); | |
| 592 create_timing_profile_table (); | |
| 1292 | 593 profiling_lock = 1; |
| 1123 | 594 elisp_maphash_unsafe (set_profiling_info_timing_maphash, value, |
| 595 NULL); | |
| 1292 | 596 profiling_lock = 0; |
| 1123 | 597 } |
| 598 else if (EQ (key, Qcall_count)) | |
| 1292 | 599 Vcall_count_profile_table = Fcopy_hash_table (value); |
| 600 else if (EQ (key, Qtotal_timing)) | |
| 601 Vtotal_timing_profile_table = Fcopy_hash_table (value); | |
| 602 else if (EQ (key, Qgc_usage)) | |
| 603 Vgc_usage_profile_table = Fcopy_hash_table (value); | |
| 604 else if (EQ (key, Qtotal_gc_usage)) | |
| 605 Vtotal_gc_usage_profile_table = Fcopy_hash_table (value); | |
| 1123 | 606 else |
| 607 invalid_constant ("Unrecognized profiling-info keyword", key); | |
| 608 } | |
| 609 } | |
| 610 | |
| 1292 | 611 unbind_to (depth); |
| 1123 | 612 return Qnil; |
| 428 | 613 } |
| 614 | |
| 615 static int | |
| 442 | 616 mark_profiling_info_maphash (const void *void_key, |
| 2286 | 617 void *UNUSED (void_val), |
| 618 void *UNUSED (void_closure)) | |
| 428 | 619 { |
| 1598 | 620 #ifdef USE_KKCC |
|
5169
6c6d78781d59
cleanup of code related to xfree(), better KKCC backtrace capabilities, document XD_INLINE_LISP_OBJECT_BLOCK_PTR, fix some memory leaks, other code cleanup
Ben Wing <ben@xemacs.org>
parents:
5038
diff
changeset
|
621 kkcc_gc_stack_push_lisp_object_0 (GET_LISP_FROM_VOID (void_key)); |
| 1598 | 622 #else /* NOT USE_KKCC */ |
| 5013 | 623 mark_object (GET_LISP_FROM_VOID (void_key)); |
| 1598 | 624 #endif /* NOT USE_KKCC */ |
| 428 | 625 return 0; |
| 626 } | |
| 627 | |
| 628 void | |
| 629 mark_profiling_info (void) | |
| 630 { | |
| 631 /* This function does not GC */ | |
| 632 if (big_profile_table) | |
| 633 { | |
| 1292 | 634 profiling_lock = 1; |
| 428 | 635 maphash (mark_profiling_info_maphash, big_profile_table, 0); |
| 1292 | 636 profiling_lock = 0; |
| 428 | 637 } |
| 638 } | |
| 639 | |
| 640 DEFUN ("profiling-active-p", Fprofiling_active_p, 0, 0, 0, /* | |
| 641 Return non-nil if profiling information is currently being recorded. | |
| 642 */ | |
| 643 ()) | |
| 644 { | |
| 645 return profiling_active ? Qt : Qnil; | |
| 646 } | |
| 647 | |
| 648 void | |
| 649 syms_of_profile (void) | |
| 650 { | |
| 651 DEFSUBR (Fstart_profiling); | |
| 652 DEFSUBR (Fstop_profiling); | |
| 653 DEFSUBR (Fget_profiling_info); | |
| 1123 | 654 DEFSUBR (Fset_profiling_info); |
| 428 | 655 DEFSUBR (Fclear_profiling_info); |
| 656 DEFSUBR (Fprofiling_active_p); | |
| 657 } | |
| 658 | |
| 659 void | |
| 660 vars_of_profile (void) | |
| 661 { | |
| 662 DEFVAR_INT ("default-profiling-interval", &default_profiling_interval /* | |
| 663 Default CPU time in microseconds between profiling sampling. | |
| 664 Used when the argument to `start-profiling' is nil or omitted. | |
| 1346 | 665 Under Unix, the time in question is CPU time (when the program is executing |
| 666 or the kernel is executing on behalf of the program) and not real time. | |
| 667 Under MS Windows and Cygwin, the time is real time, but time spent blocking | |
| 668 while waiting for an event is ignored, to get more accurate results. | |
| 669 Note that there is usually a machine-dependent limit on how small this | |
| 670 value can be. | |
| 428 | 671 */ ); |
| 672 default_profiling_interval = 1000; | |
| 673 | |
| 1123 | 674 staticpro (&Vcall_count_profile_table); |
| 428 | 675 Vcall_count_profile_table = Qnil; |
| 676 | |
| 1292 | 677 staticpro (&Vgc_usage_profile_table); |
| 678 Vgc_usage_profile_table = Qnil; | |
| 679 | |
| 680 staticpro (&Vtotal_gc_usage_profile_table); | |
| 681 Vtotal_gc_usage_profile_table = Qnil; | |
| 682 | |
| 683 staticpro (&Vtotal_timing_profile_table); | |
| 684 Vtotal_timing_profile_table = Qnil; | |
| 428 | 685 |
| 1292 | 686 #if 0 |
| 687 /* #### This is supposed to be for KKCC but KKCC doesn't use this stuff | |
| 688 currently. */ | |
| 2367 | 689 dump_add_root_block_ptr (&big_profile_table, &plain_hash_table_description); |
| 1292 | 690 #endif /* 0 */ |
| 691 | |
| 692 profiling_lock = 0; | |
| 693 | |
| 2514 | 694 #ifdef DEBUG_XEMACS |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
695 QSin_temp_spot_1 = build_defer_string ("(in temp spot 1)"); |
| 2514 | 696 staticpro (&QSin_temp_spot_1); |
| 697 | |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
698 QSin_temp_spot_2 = build_defer_string ("(in temp spot 2)"); |
| 2514 | 699 staticpro (&QSin_temp_spot_2); |
| 700 | |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
701 QSin_temp_spot_3 = build_defer_string ("(in temp spot 3)"); |
| 2514 | 702 staticpro (&QSin_temp_spot_3); |
| 703 | |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
704 QSin_temp_spot_4 = build_defer_string ("(in temp spot 4)"); |
| 2514 | 705 staticpro (&QSin_temp_spot_4); |
| 706 | |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
707 QSin_temp_spot_5 = build_defer_string ("(in temp spot 5)"); |
| 2514 | 708 staticpro (&QSin_temp_spot_5); |
| 709 #endif /* DEBUG_XEMACS */ | |
| 710 | |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
711 QSunknown = build_defer_string ("(unknown)"); |
| 428 | 712 staticpro (&QSunknown); |
| 713 QSprocessing_events_at_top_level = | |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
714 build_defer_string ("(processing events at top level)"); |
| 428 | 715 staticpro (&QSprocessing_events_at_top_level); |
|
4952
19a72041c5ed
Mule-izing, various fixes related to char * arguments
Ben Wing <ben@xemacs.org>
parents:
2645
diff
changeset
|
716 QSprofile_overhead = build_defer_string ("(profile overhead)"); |
| 1292 | 717 staticpro (&QSprofile_overhead); |
| 1123 | 718 |
| 719 DEFSYMBOL (Qtiming); | |
| 1292 | 720 DEFSYMBOL (Qtotal_timing); |
| 1123 | 721 DEFSYMBOL (Qcall_count); |
| 1292 | 722 DEFSYMBOL (Qgc_usage); |
| 723 DEFSYMBOL (Qtotal_gc_usage); | |
| 428 | 724 } |