|
0
|
1 /* Why the hell is XEmacs so fucking slow?
|
|
|
2 Copyright (C) 1996 Ben Wing.
|
|
|
3
|
|
|
4 This file is part of XEmacs.
|
|
|
5
|
|
|
6 XEmacs is free software; you can redistribute it and/or modify it
|
|
|
7 under the terms of the GNU General Public License as published by the
|
|
|
8 Free Software Foundation; either version 2, or (at your option) any
|
|
|
9 later version.
|
|
|
10
|
|
|
11 XEmacs is distributed in the hope that it will be useful, but WITHOUT
|
|
|
12 ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
|
|
|
13 FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
|
|
|
14 for more details.
|
|
|
15
|
|
|
16 You should have received a copy of the GNU General Public License
|
|
|
17 along with XEmacs; see the file COPYING. If not, write to
|
|
|
18 the Free Software Foundation, Inc., 59 Temple Place - Suite 330,
|
|
|
19 Boston, MA 02111-1307, USA. */
|
|
|
20
|
|
|
21 #include <config.h>
|
|
|
22 #include "lisp.h"
|
|
|
23
|
|
|
24 #include "backtrace.h"
|
|
|
25 #include "bytecode.h"
|
|
|
26 #include "hash.h"
|
|
|
27
|
|
|
28 #include "syssignal.h"
|
|
|
29 #include "systime.h"
|
|
|
30
|
|
|
31 /*
|
|
|
32
|
|
|
33 We implement our own profiling scheme so that we can determine things
|
|
|
34 like which Lisp functions are occupying the most time. Any standard
|
|
|
35 OS-provided profiling works on C functions, which is somewhat useless.
|
|
|
36
|
|
|
37 The basic idea is simple. We set a profiling timer using
|
|
|
38 setitimer (ITIMER_PROF), which generates a SIGPROF every so often.
|
|
|
39 \(This runs not in real time but rather when the process is executing
|
|
|
40 or the system is running on behalf of the process.) When the signal
|
|
|
41 goes off, we see what we're in, and add by 1 the count associated with
|
|
|
42 that function.
|
|
|
43
|
|
|
44 It would be nice to use the Lisp allocation mechanism etc. to keep
|
|
|
45 track of the profiling information, but we can't because that's not
|
|
|
46 safe, and trying to make it safe would be much more work than is
|
|
|
47 worth.
|
|
|
48
|
|
|
49 */
|
|
|
50
|
|
|
51 c_hashtable big_profile_table;
|
|
|
52
|
|
|
53 int default_profiling_interval;
|
|
|
54
|
|
|
55 int profiling_active;
|
|
|
56
|
|
|
57 /* The normal flag in_display is used as a critical-section flag
|
|
|
58 and is not set the whole time we're in redisplay. */
|
|
|
59 int profiling_redisplay_flag;
|
|
|
60
|
|
|
61 Lisp_Object QSin_redisplay;
|
|
|
62 Lisp_Object QSin_garbage_collection;
|
|
|
63 Lisp_Object QSprocessing_events_at_top_level;
|
|
|
64 Lisp_Object QSunknown;
|
|
|
65
|
|
|
66 static SIGTYPE
|
|
|
67 sigprof_handler (int signo)
|
|
|
68 {
|
|
|
69 Lisp_Object fun;
|
|
|
70
|
|
|
71 if (profiling_redisplay_flag)
|
|
|
72 fun = QSin_redisplay;
|
|
|
73 else if (gc_in_progress)
|
|
|
74 fun = QSin_garbage_collection;
|
|
|
75 else if (backtrace_list)
|
|
|
76 {
|
|
|
77 fun = *backtrace_list->function;
|
|
|
78
|
|
|
79 XUNMARK (fun);
|
|
|
80 if (!GC_SYMBOLP (fun) && !GC_COMPILED_FUNCTIONP (fun))
|
|
|
81 fun = QSunknown;
|
|
|
82 }
|
|
|
83 else
|
|
|
84 fun = QSprocessing_events_at_top_level;
|
|
|
85
|
|
|
86 {
|
|
|
87 long count;
|
|
|
88 CONST void *vval;
|
|
|
89
|
|
|
90 if (gethash (LISP_TO_VOID (fun), big_profile_table, &vval))
|
|
|
91 count = (long) vval;
|
|
|
92 else
|
|
|
93 count = 0;
|
|
|
94 count++;
|
|
|
95 vval = (CONST void *) count;
|
|
|
96 puthash (LISP_TO_VOID (fun), (void *) vval, big_profile_table);
|
|
|
97 }
|
|
|
98 }
|
|
|
99
|
|
|
100 DEFUN ("start-profiling", Fstart_profiling, Sstart_profiling, 0, 1, 0 /*
|
|
|
101 Start profiling, with profile queries every MICROSECS.
|
|
|
102 If MICROSECS is nil or omitted, the value of `default-profiling-interval'
|
|
|
103 is used.
|
|
|
104
|
|
|
105 You can retrieve the recorded profiling info using `get-profiling-info'.
|
|
|
106
|
|
|
107 Starting and stopping profiling does not clear the currently recorded
|
|
|
108 info. Thus you can start and stop as many times as you want and everything
|
|
|
109 will be properly accumulated.
|
|
|
110 */ )
|
|
|
111 (microsecs)
|
|
|
112 Lisp_Object microsecs;
|
|
|
113 {
|
|
|
114 int msecs;
|
|
|
115 struct itimerval foo;
|
|
|
116
|
|
|
117 /* #### The hash code can safely be called from a signal handler
|
|
|
118 except when it has to grow the hashtable. In this case, it calls
|
|
|
119 realloc(), which is not (in general) re-entrant. We just be
|
|
|
120 sleazy and make the table large enough that it (hopefully) won't
|
|
|
121 need to be realloc()ed. */
|
|
|
122 if (!big_profile_table)
|
|
|
123 big_profile_table = make_hashtable (10000);
|
|
|
124 if (NILP (microsecs))
|
|
|
125 msecs = default_profiling_interval;
|
|
|
126 else
|
|
|
127 {
|
|
|
128 CHECK_NATNUM (microsecs);
|
|
|
129 msecs = XINT (microsecs);
|
|
|
130 }
|
|
|
131 if (msecs <= 0)
|
|
|
132 msecs = 1000;
|
|
|
133
|
|
|
134 signal (SIGPROF, sigprof_handler);
|
|
|
135 foo.it_value.tv_sec = 0;
|
|
|
136 foo.it_value.tv_usec = msecs;
|
|
|
137 EMACS_NORMALIZE_TIME (foo.it_value);
|
|
|
138 foo.it_interval = foo.it_value;
|
|
|
139 profiling_active = 1;
|
|
|
140 setitimer (ITIMER_PROF, &foo, 0);
|
|
|
141 return Qnil;
|
|
|
142 }
|
|
|
143
|
|
|
144 DEFUN ("stop-profiling", Fstop_profiling, Sstop_profiling, 0, 0, 0 /*
|
|
|
145 Stop profiling.
|
|
|
146 */ )
|
|
|
147 ()
|
|
|
148 {
|
|
|
149 struct itimerval foo;
|
|
|
150
|
|
|
151 foo.it_value.tv_sec = 0;
|
|
|
152 foo.it_value.tv_usec = 0;
|
|
|
153 foo.it_interval = foo.it_value;
|
|
|
154 setitimer (ITIMER_PROF, &foo, 0);
|
|
|
155 profiling_active = 0;
|
|
|
156 signal (SIGPROF, fatal_error_signal);
|
|
|
157 return Qnil;
|
|
|
158 }
|
|
|
159
|
|
|
160 struct get_profiling_info_closure
|
|
|
161 {
|
|
|
162 Lisp_Object accum;
|
|
|
163 };
|
|
|
164
|
|
|
165 static void
|
|
|
166 get_profiling_info_maphash (CONST void *void_key,
|
|
|
167 void *void_val,
|
|
|
168 void *void_closure)
|
|
|
169 {
|
|
|
170 /* This function can GC */
|
|
|
171 Lisp_Object key;
|
|
|
172 struct get_profiling_info_closure *closure = void_closure;
|
|
|
173 EMACS_INT val;
|
|
|
174
|
|
|
175 CVOID_TO_LISP (key, void_key);
|
|
|
176 val = (EMACS_INT) void_val;
|
|
|
177
|
|
|
178 closure->accum = Fcons (Fcons (key, make_int (val)),
|
|
|
179 closure->accum);
|
|
|
180 }
|
|
|
181
|
|
|
182 DEFUN ("get-profiling-info", Fget_profiling_info, Sget_profiling_info,
|
|
|
183 0, 0, 0 /*
|
|
|
184 Return the profiling info as an alist.
|
|
|
185 */ )
|
|
|
186 ()
|
|
|
187 {
|
|
|
188 struct get_profiling_info_closure closure;
|
|
|
189
|
|
|
190 closure.accum = Qnil;
|
|
|
191 if (big_profile_table)
|
|
|
192 maphash (get_profiling_info_maphash, big_profile_table, &closure);
|
|
|
193 return closure.accum;
|
|
|
194 }
|
|
|
195
|
|
|
196 struct mark_profiling_info_closure
|
|
|
197 {
|
|
|
198 void (*markfun) (Lisp_Object);
|
|
|
199 };
|
|
|
200
|
|
|
201 static void
|
|
|
202 mark_profiling_info_maphash (CONST void *void_key,
|
|
|
203 void *void_val,
|
|
|
204 void *void_closure)
|
|
|
205 {
|
|
|
206 /* This function can GC */
|
|
|
207 Lisp_Object key;
|
|
|
208 struct mark_profiling_info_closure *closure = void_closure;
|
|
|
209
|
|
|
210 CVOID_TO_LISP (key, void_key);
|
|
|
211 (closure->markfun) (key);
|
|
|
212 }
|
|
|
213
|
|
|
214 void
|
|
|
215 mark_profiling_info (void (*markfun) (Lisp_Object))
|
|
|
216 {
|
|
|
217 struct mark_profiling_info_closure closure;
|
|
|
218
|
|
|
219 closure.markfun = markfun;
|
|
|
220 if (big_profile_table)
|
|
|
221 maphash (mark_profiling_info_maphash, big_profile_table, &closure);
|
|
|
222 }
|
|
|
223
|
|
|
224 DEFUN ("clear-profiling-info", Fclear_profiling_info, Sclear_profiling_info,
|
|
|
225 0, 0, 0 /*
|
|
|
226 Clear out the recorded profiling info.
|
|
|
227 */ )
|
|
|
228 ()
|
|
|
229 {
|
|
|
230 if (big_profile_table)
|
|
|
231 clrhash (big_profile_table);
|
|
|
232 return Qnil;
|
|
|
233 }
|
|
|
234
|
|
|
235 DEFUN ("profiling-active-p", Fprofiling_active_p, Sprofiling_active_p,
|
|
|
236 0, 0, 0 /*
|
|
|
237 Return non-nil if profiling information is currently being recorded.
|
|
|
238 */ )
|
|
|
239 ()
|
|
|
240 {
|
|
|
241 return profiling_active ? Qt : Qnil;
|
|
|
242 }
|
|
|
243
|
|
|
244 void
|
|
|
245 syms_of_profile (void)
|
|
|
246 {
|
|
|
247 defsubr (&Sstart_profiling);
|
|
|
248 defsubr (&Sstop_profiling);
|
|
|
249 defsubr (&Sget_profiling_info);
|
|
|
250 defsubr (&Sclear_profiling_info);
|
|
|
251 defsubr (&Sprofiling_active_p);
|
|
|
252 }
|
|
|
253
|
|
|
254 void
|
|
|
255 vars_of_profile (void)
|
|
|
256 {
|
|
|
257 DEFVAR_INT ("default-profiling-interval", &default_profiling_interval /*
|
|
|
258 Default time in microseconds between profiling queries.
|
|
|
259 Used when the argument to `start-profiling' is nil or omitted.
|
|
|
260 Note that the time in question is CPU time (when the program is executing
|
|
|
261 or the kernel is executing on behalf of the program) and not real time.
|
|
|
262 */ );
|
|
|
263 default_profiling_interval = 1000;
|
|
|
264
|
|
|
265 QSin_redisplay = build_string ("(in redisplay)");
|
|
|
266 staticpro (&QSin_redisplay);
|
|
|
267 QSin_garbage_collection = build_string ("(in garbage collection)");
|
|
|
268 staticpro (&QSin_garbage_collection);
|
|
|
269 QSunknown = build_string ("(unknown)");
|
|
|
270 staticpro (&QSunknown);
|
|
|
271 QSprocessing_events_at_top_level =
|
|
|
272 build_string ("(processing events at top level)");
|
|
|
273 staticpro (&QSprocessing_events_at_top_level);
|
|
|
274 }
|
