No issues found
1 /* -*- Mode: C; tab-width: 8; indent-tabs-mode: t; c-basic-offset: 8 -*-
2 *
3 * Copyright (C) 2002 Jorn Baayen
4 *
5 * This program is free software; you can redistribute it and/or modify
6 * it under the terms of the GNU General Public License as published by
7 * the Free Software Foundation; either version 2, or (at your option)
8 * any later version.
9 *
10 * The Rhythmbox authors hereby grant permission for non-GPL compatible
11 * GStreamer plugins to be used and distributed together with GStreamer
12 * and Rhythmbox. This permission is above and beyond the permissions granted
13 * by the GPL license by which Rhythmbox is covered. If you modify this code
14 * you may extend this exception to your version of the code, but you are not
15 * obligated to do so. If you do not wish to do so, delete this exception
16 * statement from your version.
17 *
18 * This program is distributed in the hope that it will be useful,
19 * but WITHOUT ANY WARRANTY; without even the implied warranty of
20 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
21 * GNU General Public License for more details.
22 *
23 * You should have received a copy of the GNU General Public License
24 * along with this program; if not, write to the Free Software
25 * Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
26 *
27 * NOTES: log domain hack stolen from nautilus
28 *
29 */
30
31 #include "config.h"
32
33 #include <unistd.h>
34 #include <stdio.h>
35 #include <string.h>
36 #include <stdarg.h>
37 #include <signal.h>
38 #include <time.h>
39
40 #include <glib.h>
41
42 #include "rb-debug.h"
43
44 /**
45 * SECTION:rb-debug
46 * @short_description: debugging support functions
47 *
48 * In addition to a simple debug output system, we have two distinct
49 * profiling mechanisms for timing sections of code.
50 */
51
52 static void log_handler (const char *domain,
53 GLogLevelFlags level,
54 const char *message,
55 gpointer data);
56
57 static const char *debug_everything = "everything";
58 static const char *debug_match = NULL;
59
60 /**
61 * rb_debug_matches:
62 * @func: function to check
63 * @file: filename to check
64 *
65 * Checks if @file or @func matches the current debug output settings.
66 *
67 * Return value: %TRUE if matched
68 */
69 gboolean
70 rb_debug_matches (const char *func,
71 const char *file)
72 {
73 if (debug_match == NULL ||
74 (debug_match != debug_everything &&
75 (strstr (file, debug_match) == NULL) &&
76 (strstr (func, debug_match) == NULL)))
77 return FALSE;
78
79 return TRUE;
80 }
81
82 /**
83 * rb_debug:
84 * @Varargs: printf-style format string followed by any substitution values
85 *
86 * If the call site function or file name matches the current debug output
87 * settings, the message will be formatted and printed to standard error,
88 * including a timestamp, the thread ID, the file and function names, and
89 * the line number. A newline will be appended, so the format string shouldn't
90 * include one.
91 */
92
93 static void
94 _rb_debug_print (const char *func, const char *file, const int line, gboolean newline, const char *buffer)
95 {
96 char str_time[255];
97 time_t the_time;
98
99 time (&the_time);
100 strftime (str_time, 254, "%H:%M:%S", localtime (&the_time));
101
102 g_printerr (newline ? "(%s) [%p] [%s] %s:%d: %s\n" : "(%s) [%p] [%s] %s:%d: %s",
103 str_time, g_thread_self (), func, file, line, buffer);
104 }
105
106 /**
107 * rb_debug_real:
108 * @func: function name
109 * @file: file name
110 * @line: line number
111 * @newline: if TRUE, add a newline to the output
112 * @message: the debug message
113 *
114 * If the debug output settings match the function or file names,
115 * the debug message will be formatted and written to standard error.
116 */
117 void
118 rb_debug_real (const char *func, const char *file, const int line, gboolean newline, const char *message)
119 {
120 if (rb_debug_matches (func, file)) {
121 _rb_debug_print (func, file, line, newline, message);
122 }
123 }
124
125 /**
126 * rb_debug_realf:
127 * @func: function name
128 * @file: file name
129 * @line: line number
130 * @newline: if TRUE, add a newline to the output
131 * @format: printf style format specifier
132 * @Varargs: substitution values for @format
133 *
134 * If the debug output settings match the function or file names,
135 * the debug message will be formatted and written to standard error.
136 */
137 void
138 rb_debug_realf (const char *func,
139 const char *file,
140 const int line,
141 gboolean newline,
142 const char *format, ...)
143 {
144 va_list args;
145 char buffer[1025];
146
147 if (!rb_debug_matches (func, file))
148 return;
149
150 va_start (args, format);
151
152 g_vsnprintf (buffer, 1024, format, args);
153
154 va_end (args);
155
156 _rb_debug_print (func, file, line, newline, buffer);
157 }
158
159 /**
160 * rb_debug_init:
161 * @debug: if TRUE, enable all debug output
162 *
163 * Sets up debug output, with either all debug enabled
164 * or none.
165 */
166 void
167 rb_debug_init (gboolean debug)
168 {
169 rb_debug_init_match (debug ? debug_everything : NULL);
170 }
171
172 /**
173 * rb_debug_init_match:
174 * @match: string to match functions and filenames against
175 *
176 * Sets up debug output, enabling debug output from file and function
177 * names that contain the specified match string.
178 *
179 * Also sets up a GLib log handler that will trigger a debugger
180 * break for critical or warning level output if any debug output
181 * at all is enabled.
182 */
183 void
184 rb_debug_init_match (const char *match)
185 {
186 guint i;
187
188 /* This is a workaround for the fact that there is no way to
189 * make this useful debugging feature happen for ALL domains.
190 *
191 * What we did here is list all the ones we could think of that
192 * were interesting to us. It's OK to add more to the list.
193 */
194 static const char * const standard_log_domains[] = {
195 "",
196 "Bonobo",
197 "BonoboUI",
198 "Echo",
199 "Eel",
200 "GConf",
201 "GConf-Backends",
202 "GConf-Tests",
203 "GConfEd",
204 "GLib",
205 "GLib-GObject",
206 "GModule",
207 "GThread",
208 "GStreamer",
209 "Gdk",
210 "Gdk-Pixbuf",
211 "GdkPixbuf",
212 "Glib",
213 "Gnome",
214 "GnomeCanvas",
215 "GnomePrint",
216 "GnomeUI",
217 "GnomeVFS",
218 "GnomeVFS-CORBA",
219 "GnomeVFS-pthread",
220 "GnomeVFSMonikers",
221 "Gtk",
222 "Rhythmbox",
223 "RhythmDB",
224 "ORBit",
225 "ZVT",
226 "libIDL",
227 "libgconf-scm",
228 "libgnomevfs",
229 "librsvg",
230 "libnotify",
231 "GLib-GIO",
232 };
233
234 debug_match = match;
235
236 if (debug_match != NULL)
237 for (i = 0; i < G_N_ELEMENTS (standard_log_domains); i++)
238 g_log_set_handler (standard_log_domains[i], G_LOG_LEVEL_MASK, log_handler, NULL);
239
240 rb_debug ("Debugging enabled");
241 }
242
243 /**
244 * rb_debug_get_args:
245 *
246 * Constructs arguments to pass to another process using
247 * this debug output code that will produce the same debug output
248 * settings.
249 *
250 * Return value: (transfer full): debug output arguments, must be freed with #g_strfreev()
251 */
252 char **
253 rb_debug_get_args (void)
254 {
255 char **args;
256 if (debug_match == NULL) {
257 args = (char **)g_new0 (char *, 1);
258 } else if (debug_match == debug_everything) {
259 args = (char **)g_new0 (char *, 2);
260 args[0] = g_strdup ("--debug");
261 } else {
262 args = (char **)g_new0 (char *, 3);
263 args[0] = g_strdup ("--debug-match");
264 args[1] = g_strdup (debug_match);
265 }
266 return args;
267 }
268
269 /**
270 * rb_debug_stop_in_debugger:
271 *
272 * Raises a SIGINT signal to get the attention of the debugger.
273 * When not running under the debugger, we don't want to stop,
274 * so we ignore the signal for just the moment that we raise it.
275 */
276 void
277 rb_debug_stop_in_debugger (void)
278 {
279 void (* saved_handler) (int);
280
281 saved_handler = signal (SIGINT, SIG_IGN);
282 raise (SIGINT);
283 signal (SIGINT, saved_handler);
284 }
285
286 /* Stop in the debugger after running the default log handler.
287 * This makes certain kinds of messages stop in the debugger
288 * without making them fatal (you can continue).
289 */
290 static void
291 log_handler (const char *domain,
292 GLogLevelFlags level,
293 const char *message,
294 gpointer data)
295 {
296 g_log_default_handler (domain, level, message, data);
297 if ((level & (G_LOG_LEVEL_CRITICAL | G_LOG_LEVEL_WARNING)) != 0)
298 {
299 rb_debug_stop_in_debugger ();
300 }
301 }
302
303 struct RBProfiler
304 {
305 GTimer *timer;
306 char *name;
307 };
308
309 /**
310 * rb_profiler_new: (skip):
311 * @name: profiler name
312 *
313 * Creates a new profiler instance. This can be used to
314 * time certain sections of code.
315 *
316 * Return value: profiler instance
317 */
318 RBProfiler *
319 rb_profiler_new (const char *name)
320 {
321 RBProfiler *profiler;
322
323 if (debug_match == NULL)
324 return NULL;
325
326 profiler = g_new0 (RBProfiler, 1);
327 profiler->timer = g_timer_new ();
328 profiler->name = g_strdup (name);
329
330 g_timer_start (profiler->timer);
331
332 return profiler;
333 }
334
335 /**
336 * rb_profiler_dump: (skip):
337 * @profiler: profiler instance
338 *
339 * Produces debug output for the profiler instance,
340 * showing the elapsed time.
341 */
342 void
343 rb_profiler_dump (RBProfiler *profiler)
344 {
345 gulong elapsed;
346 double seconds;
347
348 if (debug_match == NULL)
349 return;
350 if (profiler == NULL)
351 return;
352
353 seconds = g_timer_elapsed (profiler->timer, &elapsed);
354
355 rb_debug ("PROFILER %s %ld ms (%f s) elapsed", profiler->name,
356 elapsed / (G_USEC_PER_SEC / 1000), seconds);
357 }
358
359 /**
360 * rb_profiler_reset: (skip):
361 * @profiler: profiler instance
362 *
363 * Resets the elapsed time for the profiler
364 */
365 void
366 rb_profiler_reset (RBProfiler *profiler)
367 {
368 if (debug_match == NULL)
369 return;
370 if (profiler == NULL)
371 return;
372
373 g_timer_start (profiler->timer);
374 }
375
376 /**
377 * rb_profiler_free: (skip):
378 * @profiler: profiler instance to destroy
379 *
380 * Frees the memory associated with a profiler instance.
381 */
382 void
383 rb_profiler_free (RBProfiler *profiler)
384 {
385 if (debug_match == NULL)
386 return;
387 if (profiler == NULL)
388 return;
389
390 g_timer_destroy (profiler->timer);
391 g_free (profiler->name);
392 g_free (profiler);
393 }
394
395 /* Profiling */
396
397 static int profile_indent;
398
399 static void
400 profile_add_indent (int indent)
401 {
402 profile_indent += indent;
403 if (profile_indent < 0) {
404 g_error ("You screwed up your indentation");
405 }
406 }
407
408 /**
409 * rb_profile_start:
410 * @msg: profile point message
411 *
412 * Records a start point for profiling.
413 * This profile mechanism operates by issuing file access
414 * requests with filenames indicating the profile points.
415 * Use 'strace -e access' to gather this information.
416 */
417
418 /**
419 * rb_profile_end:
420 * @msg: profile point message
421 *
422 * Records an end point for profiling. See @rb_profile_start.
423 */
424
425 /**
426 * _rb_profile_log:
427 * @func: call site function name
428 * @file: call site file name
429 * @line: call site line number
430 * @indent: indent level for output
431 * @msg1: message part 1
432 * @msg2: message part 2
433 *
434 * Issues a file access request with a constructed filename.
435 * Run rhythmbox under 'strace -ttt -e access' to show these profile
436 * points.
437 */
438 void
439 _rb_profile_log (const char *func,
440 const char *file,
441 int line,
442 int indent,
443 const char *msg1,
444 const char *msg2)
445 {
446 char *str;
447
448 if (indent < 0) {
449 profile_add_indent (indent);
450 }
451
452 if (profile_indent == 0) {
453 str = g_strdup_printf ("MARK: [%s %s %d] %s %s", file, func, line, msg1 ? msg1 : "", msg2 ? msg2 : "");
454 } else {
455 str = g_strdup_printf ("MARK: %*c [%s %s %d] %s %s", profile_indent - 1, ' ', file, func, line, msg1 ? msg1 : "", msg2 ? msg2 : "");
456 }
457
458 access (str, F_OK);
459
460 g_free (str);
461
462 if (indent > 0) {
463 profile_add_indent (indent);
464 }
465 }