|
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 {
|
|
70
|
69 Lisp_Object fun;
|
|
44
|
70
|
|
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;
|
|
0
|
78
|
|
70
|
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;
|
|
0
|
85
|
|
70
|
86 {
|
|
|
87 long count;
|
|
|
88 CONST void *vval;
|
|
44
|
89
|
|
70
|
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 }
|
|
0
|
98 }
|
|
|
99
|
|
20
|
100 DEFUN ("start-profiling", Fstart_profiling, 0, 1, 0, /*
|
|
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
|
|
20
|
109 will be properly accumulated.
|
|
|
110 */
|
|
|
111 (microsecs))
|
|
0
|
112 {
|
|
|
113 int msecs;
|
|
|
114 struct itimerval foo;
|
|
|
115
|
|
|
116 /* #### The hash code can safely be called from a signal handler
|
|
|
117 except when it has to grow the hashtable. In this case, it calls
|
|
|
118 realloc(), which is not (in general) re-entrant. We just be
|
|
|
119 sleazy and make the table large enough that it (hopefully) won't
|
|
|
120 need to be realloc()ed. */
|
|
|
121 if (!big_profile_table)
|
|
|
122 big_profile_table = make_hashtable (10000);
|
|
|
123 if (NILP (microsecs))
|
|
|
124 msecs = default_profiling_interval;
|
|
|
125 else
|
|
|
126 {
|
|
|
127 CHECK_NATNUM (microsecs);
|
|
|
128 msecs = XINT (microsecs);
|
|
|
129 }
|
|
|
130 if (msecs <= 0)
|
|
|
131 msecs = 1000;
|
|
|
132
|
|
|
133 signal (SIGPROF, sigprof_handler);
|
|
|
134 foo.it_value.tv_sec = 0;
|
|
|
135 foo.it_value.tv_usec = msecs;
|
|
|
136 EMACS_NORMALIZE_TIME (foo.it_value);
|
|
|
137 foo.it_interval = foo.it_value;
|
|
|
138 profiling_active = 1;
|
|
|
139 setitimer (ITIMER_PROF, &foo, 0);
|
|
|
140 return Qnil;
|
|
|
141 }
|
|
|
142
|
|
20
|
143 DEFUN ("stop-profiling", Fstop_profiling, 0, 0, 0, /*
|
|
0
|
144 Stop profiling.
|
|
20
|
145 */
|
|
|
146 ())
|
|
0
|
147 {
|
|
|
148 struct itimerval foo;
|
|
|
149
|
|
|
150 foo.it_value.tv_sec = 0;
|
|
|
151 foo.it_value.tv_usec = 0;
|
|
|
152 foo.it_interval = foo.it_value;
|
|
|
153 setitimer (ITIMER_PROF, &foo, 0);
|
|
|
154 profiling_active = 0;
|
|
|
155 signal (SIGPROF, fatal_error_signal);
|
|
|
156 return Qnil;
|
|
|
157 }
|
|
|
158
|
|
|
159 struct get_profiling_info_closure
|
|
|
160 {
|
|
|
161 Lisp_Object accum;
|
|
|
162 };
|
|
|
163
|
|
|
164 static void
|
|
|
165 get_profiling_info_maphash (CONST void *void_key,
|
|
|
166 void *void_val,
|
|
|
167 void *void_closure)
|
|
|
168 {
|
|
70
|
169 /* This function can GC */
|
|
0
|
170 Lisp_Object key;
|
|
|
171 struct get_profiling_info_closure *closure = void_closure;
|
|
|
172 EMACS_INT val;
|
|
|
173
|
|
|
174 CVOID_TO_LISP (key, void_key);
|
|
|
175 val = (EMACS_INT) void_val;
|
|
|
176
|
|
|
177 closure->accum = Fcons (Fcons (key, make_int (val)),
|
|
|
178 closure->accum);
|
|
|
179 }
|
|
|
180
|
|
20
|
181 DEFUN ("get-profiling-info", Fget_profiling_info, 0, 0, 0, /*
|
|
0
|
182 Return the profiling info as an alist.
|
|
20
|
183 */
|
|
|
184 ())
|
|
0
|
185 {
|
|
|
186 struct get_profiling_info_closure closure;
|
|
|
187
|
|
|
188 closure.accum = Qnil;
|
|
|
189 if (big_profile_table)
|
|
70
|
190 maphash (get_profiling_info_maphash, big_profile_table, &closure);
|
|
0
|
191 return closure.accum;
|
|
|
192 }
|
|
|
193
|
|
|
194 struct mark_profiling_info_closure
|
|
|
195 {
|
|
|
196 void (*markfun) (Lisp_Object);
|
|
|
197 };
|
|
|
198
|
|
|
199 static void
|
|
|
200 mark_profiling_info_maphash (CONST void *void_key,
|
|
|
201 void *void_val,
|
|
|
202 void *void_closure)
|
|
|
203 {
|
|
70
|
204 /* This function can GC */
|
|
0
|
205 Lisp_Object key;
|
|
|
206 struct mark_profiling_info_closure *closure = void_closure;
|
|
|
207
|
|
|
208 CVOID_TO_LISP (key, void_key);
|
|
|
209 (closure->markfun) (key);
|
|
|
210 }
|
|
|
211
|
|
|
212 void
|
|
|
213 mark_profiling_info (void (*markfun) (Lisp_Object))
|
|
|
214 {
|
|
|
215 struct mark_profiling_info_closure closure;
|
|
|
216
|
|
|
217 closure.markfun = markfun;
|
|
|
218 if (big_profile_table)
|
|
70
|
219 maphash (mark_profiling_info_maphash, big_profile_table, &closure);
|
|
0
|
220 }
|
|
|
221
|
|
20
|
222 DEFUN ("clear-profiling-info", Fclear_profiling_info, 0, 0, 0, /*
|
|
0
|
223 Clear out the recorded profiling info.
|
|
20
|
224 */
|
|
|
225 ())
|
|
0
|
226 {
|
|
|
227 if (big_profile_table)
|
|
70
|
228 clrhash (big_profile_table);
|
|
0
|
229 return Qnil;
|
|
|
230 }
|
|
|
231
|
|
20
|
232 DEFUN ("profiling-active-p", Fprofiling_active_p, 0, 0, 0, /*
|
|
0
|
233 Return non-nil if profiling information is currently being recorded.
|
|
20
|
234 */
|
|
|
235 ())
|
|
0
|
236 {
|
|
|
237 return profiling_active ? Qt : Qnil;
|
|
|
238 }
|
|
|
239
|
|
|
240 void
|
|
|
241 syms_of_profile (void)
|
|
|
242 {
|
|
20
|
243 DEFSUBR (Fstart_profiling);
|
|
|
244 DEFSUBR (Fstop_profiling);
|
|
|
245 DEFSUBR (Fget_profiling_info);
|
|
|
246 DEFSUBR (Fclear_profiling_info);
|
|
|
247 DEFSUBR (Fprofiling_active_p);
|
|
0
|
248 }
|
|
|
249
|
|
|
250 void
|
|
|
251 vars_of_profile (void)
|
|
|
252 {
|
|
|
253 DEFVAR_INT ("default-profiling-interval", &default_profiling_interval /*
|
|
|
254 Default time in microseconds between profiling queries.
|
|
|
255 Used when the argument to `start-profiling' is nil or omitted.
|
|
|
256 Note that the time in question is CPU time (when the program is executing
|
|
|
257 or the kernel is executing on behalf of the program) and not real time.
|
|
|
258 */ );
|
|
|
259 default_profiling_interval = 1000;
|
|
|
260
|
|
|
261 QSin_redisplay = build_string ("(in redisplay)");
|
|
|
262 staticpro (&QSin_redisplay);
|
|
|
263 QSin_garbage_collection = build_string ("(in garbage collection)");
|
|
|
264 staticpro (&QSin_garbage_collection);
|
|
|
265 QSunknown = build_string ("(unknown)");
|
|
|
266 staticpro (&QSunknown);
|
|
|
267 QSprocessing_events_at_top_level =
|
|
|
268 build_string ("(processing events at top level)");
|
|
|
269 staticpro (&QSprocessing_events_at_top_level);
|
|
|
270 }
|
