if we log our init, should also log finalize
[platform/upstream/gstreamer.git] / gst / gstinfo.c
1 /* GStreamer
2  * Copyright (C) 1999,2000 Erik Walthinsen <omega@cse.ogi.edu>
3  *                    2000 Wim Taymans <wtay@chello.be>
4  *                    2003 Benjamin Otte <in7y118@public.uni-hamburg.de>
5  *
6  * gstinfo.c: debugging functions
7  *
8  * This library is free software; you can redistribute it and/or
9  * modify it under the terms of the GNU Library General Public
10  * License as published by the Free Software Foundation; either
11  * version 2 of the License, or (at your option) any later version.
12  *
13  * This library is distributed in the hope that it will be useful,
14  * but WITHOUT ANY WARRANTY; without even the implied warranty of
15  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
16  * Library General Public License for more details.
17  *
18  * You should have received a copy of the GNU Library General Public
19  * License along with this library; if not, write to the
20  * Free Software Foundation, Inc., 59 Temple Place - Suite 330,
21  * Boston, MA 02111-1307, USA.
22  */
23 /**
24  * SECTION:gstinfo
25  * @short_description: Debugging and logging facillities
26  * @see_also: #GstConfig, #Gst for command line parameters
27  * and environment variables that affect the debugging output.
28  *
29  * GStreamer's debugging subsystem is an easy way to get information about what
30  * the application is doing.
31  * It is not meant for programming errors. Use GLib methods (g_warning and 
32  * friends) for that.
33  *
34  * The debugging subsystem works only after GStreamer has been initialized
35  * - for example by calling gst_init().
36  *
37  * The debugging subsystem is used to log informational messages while the
38  * application runs. 
39  * Each messages has some properties attached to it. Among these properties
40  * are the debugging category, the severity (called "level" here) and an
41  * optional
42  * #GObject it belongs to. Each of these messages is sent to all registered
43  * debugging handlers, which then handle the messages. GStreamer attaches a
44  * default handler on startup, which outputs requested messages to stderr.
45  *
46  * Messages are output by using shortcut macros like #GST_DEBUG, 
47  * #GST_CAT_ERROR_OBJECT or similar. These all expand to calling gst_debug_log()
48  * with the right parameters.
49  * The only thing a developer will probably want to do is define his own 
50  * categories. This is easily done with 3 lines. At the top of your code,
51  * declare
52  * the variables and set the default category.
53  * <informalexample>
54  * <programlisting>
55  * GST_DEBUG_CATEGORY (my_category);            // define category
56  * &hash;define GST_CAT_DEFAULT my_category     // set as default
57  * </programlisting>
58  * </informalexample>
59  * After that you only need to initialize the category.
60  * <informalexample>
61  * <programlisting>
62  * GST_DEBUG_CATEGORY_INIT (my_category, "my category",
63  *                          0, "This is my very own");
64  * </programlisting>
65  * </informalexample>
66  * Initialization must be done before the category is used first.
67  * Plugins do this 
68  * in their plugin_init function, libraries and applications should do that
69  * during their initialization.
70  *
71  * The whole debugging subsystem can be disabled at build time with passing the
72  * --disable-gst-debug switch to configure. If this is done, every function,
73  * macro
74  * and even structs described in this file evaluate to default values or
75  * nothing
76  * at all. So don't take addresses of these functions or use other tricks.
77  * If you must do that for some reason, there is still an option.
78  * If the debugging
79  * subsystem was compiled out, #GST_DISABLE_GST_DEBUG is defined in
80  * &lt;gst/gst.h&gt;,
81  * so you can check that before doing your trick.
82  * Disabling the debugging subsystem will give you a slight (read: unnoticable) 
83  * speed increase and will reduce the size of your compiled code. The GStreamer 
84  * library itself becomes around 10% smaller.
85  *
86  * Please note that there are naming conventions for the names of debugging 
87  * categories. These are explained at GST_DEBUG_CATEGORY_INIT().
88  */
89
90 #include "gst_private.h"
91 #include "gstinfo.h"
92
93 #ifndef GST_DISABLE_GST_DEBUG
94
95 #ifdef HAVE_DLFCN_H
96 #include <dlfcn.h>
97 #endif
98 #ifdef HAVE_PRINTF_EXTENSION
99 #include <printf.h>
100 #endif
101 #include <stdio.h>              /* fprintf */
102 #ifdef HAVE_UNISTD_H
103 #include <unistd.h>
104 #endif
105 #include <string.h>             /* G_VA_COPY */
106 #include "gst_private.h"
107 #include "gstutils.h"
108 #ifdef HAVE_VALGRIND
109 #include <valgrind/valgrind.h>
110 #endif
111 #include <glib/gprintf.h>       /* g_sprintf */
112
113 /* underscore is to prevent conflict with GST_CAT_DEBUG define */
114 GST_DEBUG_CATEGORY_STATIC (_GST_CAT_DEBUG);
115 /* time of initialization, so we get useful debugging output times */
116 GstClockTime start_time;
117
118 #if 0
119 #if defined __sgi__
120 #include <rld_interface.h>
121 typedef struct DL_INFO
122 {
123   const char *dli_fname;
124   void *dli_fbase;
125   const char *dli_sname;
126   void *dli_saddr;
127   int dli_version;
128   int dli_reserved1;
129   long dli_reserved[4];
130 }
131 Dl_info;
132
133 #define _RLD_DLADDR             14
134 int dladdr (void *address, Dl_info * dl);
135
136 int
137 dladdr (void *address, Dl_info * dl)
138 {
139   void *v;
140
141   v = _rld_new_interface (_RLD_DLADDR, address, dl);
142   return (int) v;
143 }
144 #endif /* __sgi__ */
145 #endif
146
147 static void gst_debug_reset_threshold (gpointer category, gpointer unused);
148 static void gst_debug_reset_all_thresholds (void);
149
150 #ifdef HAVE_PRINTF_EXTENSION
151 static int _gst_info_printf_extension (FILE * stream,
152     const struct printf_info *info, const void *const *args);
153 static int _gst_info_printf_extension_arginfo (const struct printf_info *info,
154     size_t n, int *argtypes);
155 #endif
156
157 struct _GstDebugMessage
158 {
159   gchar *message;
160   const gchar *format;
161   va_list arguments;
162 };
163
164 /* list of all name/level pairs from --gst-debug and GST_DEBUG */
165 static GStaticMutex __level_name_mutex = G_STATIC_MUTEX_INIT;
166 static GSList *__level_name = NULL;
167 typedef struct
168 {
169   GPatternSpec *pat;
170   GstDebugLevel level;
171 }
172 LevelNameEntry;
173
174 /* list of all categories */
175 static GStaticMutex __cat_mutex = G_STATIC_MUTEX_INIT;
176 static GSList *__categories = NULL;
177
178 /* all registered debug handlers */
179 typedef struct
180 {
181   GstLogFunction func;
182   gpointer user_data;
183 }
184 LogFuncEntry;
185 static GStaticMutex __log_func_mutex = G_STATIC_MUTEX_INIT;
186 static GSList *__log_functions = NULL;
187
188 static gint __default_level;
189 static gint __use_color;
190 gboolean __gst_debug_enabled = TRUE;
191
192
193 GstDebugCategory *GST_CAT_DEFAULT = NULL;
194
195 GstDebugCategory *GST_CAT_GST_INIT = NULL;
196 GstDebugCategory *GST_CAT_AUTOPLUG = NULL;
197 GstDebugCategory *GST_CAT_AUTOPLUG_ATTEMPT = NULL;
198 GstDebugCategory *GST_CAT_PARENTAGE = NULL;
199 GstDebugCategory *GST_CAT_STATES = NULL;
200 GstDebugCategory *GST_CAT_SCHEDULING = NULL;
201
202 GstDebugCategory *GST_CAT_BUFFER = NULL;
203 GstDebugCategory *GST_CAT_BUS = NULL;
204 GstDebugCategory *GST_CAT_CAPS = NULL;
205 GstDebugCategory *GST_CAT_CLOCK = NULL;
206 GstDebugCategory *GST_CAT_ELEMENT_PADS = NULL;
207 GstDebugCategory *GST_CAT_PADS = NULL;
208 GstDebugCategory *GST_CAT_PIPELINE = NULL;
209 GstDebugCategory *GST_CAT_PLUGIN_LOADING = NULL;
210 GstDebugCategory *GST_CAT_PLUGIN_INFO = NULL;
211 GstDebugCategory *GST_CAT_PROPERTIES = NULL;
212 GstDebugCategory *GST_CAT_THREAD = NULL;
213 GstDebugCategory *GST_CAT_TYPES = NULL;
214 GstDebugCategory *GST_CAT_XML = NULL;
215 GstDebugCategory *GST_CAT_NEGOTIATION = NULL;
216 GstDebugCategory *GST_CAT_REFCOUNTING = NULL;
217 GstDebugCategory *GST_CAT_ERROR_SYSTEM = NULL;
218 GstDebugCategory *GST_CAT_EVENT = NULL;
219 GstDebugCategory *GST_CAT_MESSAGE = NULL;
220 GstDebugCategory *GST_CAT_PARAMS = NULL;
221 GstDebugCategory *GST_CAT_CALL_TRACE = NULL;
222 GstDebugCategory *GST_CAT_SIGNAL = NULL;
223 GstDebugCategory *GST_CAT_PROBE = NULL;
224 GstDebugCategory *GST_CAT_REGISTRY = NULL;
225
226 /* FIXME: export this? */
227 gboolean
228 __gst_in_valgrind (void)
229 {
230   static enum
231   {
232     GST_VG_UNCHECKED,
233     GST_VG_NO_VALGRIND,
234     GST_VG_INSIDE
235   }
236   in_valgrind = GST_VG_UNCHECKED;
237
238   if (in_valgrind == GST_VG_UNCHECKED) {
239 #ifdef HAVE_VALGRIND
240     if (RUNNING_ON_VALGRIND) {
241       GST_CAT_INFO (GST_CAT_GST_INIT, "we're running inside valgrind");
242       VALGRIND_PRINTF
243           ("GStreamer has detected that it is running inside valgrind.");
244       VALGRIND_PRINTF
245           ("It might now take different code paths to ease debugging.");
246       VALGRIND_PRINTF ("Of course, this may also lead to different bugs.");
247       in_valgrind = GST_VG_INSIDE;
248     } else {
249       GST_CAT_LOG (GST_CAT_GST_INIT, "not doing extra valgrind stuff");
250       in_valgrind = GST_VG_NO_VALGRIND;
251     }
252 #else
253     in_valgrind = GST_VG_NO_VALGRIND;
254 #endif
255     g_assert (in_valgrind == GST_VG_NO_VALGRIND ||
256         in_valgrind == GST_VG_INSIDE);
257   }
258   return (in_valgrind == GST_VG_INSIDE) ? TRUE : FALSE;
259 }
260
261 /**
262  * _gst_debug_init:
263  * 
264  * Initializes the debugging system.
265  * Normally you don't want to call this, because gst_init does it for you.
266  */
267 void
268 _gst_debug_init (void)
269 {
270   GTimeVal current;
271
272   gst_atomic_int_set (&__default_level, GST_LEVEL_DEFAULT);
273   gst_atomic_int_set (&__use_color, 1);
274
275   /* get time we started for debugging messages */
276   g_get_current_time (&current);
277   start_time = GST_TIMEVAL_TO_TIME (current);
278
279 #ifdef HAVE_PRINTF_EXTENSION
280   register_printf_function (GST_PTR_FORMAT[0], _gst_info_printf_extension,
281       _gst_info_printf_extension_arginfo);
282 #endif
283
284   /* do NOT use a single debug function before this line has been run */
285   GST_CAT_DEFAULT = _gst_debug_category_new ("default",
286       GST_DEBUG_UNDERLINE, NULL);
287   _GST_CAT_DEBUG = _gst_debug_category_new ("GST_DEBUG",
288       GST_DEBUG_BOLD | GST_DEBUG_FG_YELLOW, "debugging subsystem");
289
290   gst_debug_add_log_function (gst_debug_log_default, NULL);
291
292   /* FIXME: add descriptions here */
293   GST_CAT_GST_INIT = _gst_debug_category_new ("GST_INIT",
294       GST_DEBUG_BOLD | GST_DEBUG_FG_RED, NULL);
295   GST_CAT_AUTOPLUG = _gst_debug_category_new ("GST_AUTOPLUG",
296       GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
297   GST_CAT_AUTOPLUG_ATTEMPT = _gst_debug_category_new ("GST_AUTOPLUG_ATTEMPT",
298       GST_DEBUG_BOLD | GST_DEBUG_FG_CYAN | GST_DEBUG_BG_BLUE, NULL);
299   GST_CAT_PARENTAGE = _gst_debug_category_new ("GST_PARENTAGE",
300       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
301   GST_CAT_STATES = _gst_debug_category_new ("GST_STATES",
302       GST_DEBUG_BOLD | GST_DEBUG_FG_RED, NULL);
303   GST_CAT_SCHEDULING = _gst_debug_category_new ("GST_SCHEDULING",
304       GST_DEBUG_BOLD | GST_DEBUG_FG_MAGENTA, NULL);
305   GST_CAT_BUFFER = _gst_debug_category_new ("GST_BUFFER",
306       GST_DEBUG_BOLD | GST_DEBUG_BG_GREEN, NULL);
307   GST_CAT_BUS = _gst_debug_category_new ("GST_BUS", GST_DEBUG_BG_YELLOW, NULL);
308   GST_CAT_CAPS = _gst_debug_category_new ("GST_CAPS",
309       GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
310   GST_CAT_CLOCK = _gst_debug_category_new ("GST_CLOCK",
311       GST_DEBUG_BOLD | GST_DEBUG_FG_YELLOW, NULL);
312   GST_CAT_ELEMENT_PADS = _gst_debug_category_new ("GST_ELEMENT_PADS",
313       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
314   GST_CAT_PADS = _gst_debug_category_new ("GST_PADS",
315       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
316   GST_CAT_PIPELINE = _gst_debug_category_new ("GST_PIPELINE",
317       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
318   GST_CAT_PLUGIN_LOADING = _gst_debug_category_new ("GST_PLUGIN_LOADING",
319       GST_DEBUG_BOLD | GST_DEBUG_FG_CYAN, NULL);
320   GST_CAT_PLUGIN_INFO = _gst_debug_category_new ("GST_PLUGIN_INFO",
321       GST_DEBUG_BOLD | GST_DEBUG_FG_CYAN, NULL);
322   GST_CAT_PROPERTIES = _gst_debug_category_new ("GST_PROPERTIES",
323       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_BLUE, NULL);
324   GST_CAT_THREAD = _gst_debug_category_new ("GST_THREAD",
325       GST_DEBUG_BOLD | GST_DEBUG_FG_RED, NULL);
326   GST_CAT_TYPES = _gst_debug_category_new ("GST_TYPES",
327       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
328   GST_CAT_XML = _gst_debug_category_new ("GST_XML",
329       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
330   GST_CAT_NEGOTIATION = _gst_debug_category_new ("GST_NEGOTIATION",
331       GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
332   GST_CAT_REFCOUNTING = _gst_debug_category_new ("GST_REFCOUNTING",
333       GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_BLUE, NULL);
334   GST_CAT_ERROR_SYSTEM = _gst_debug_category_new ("GST_ERROR_SYSTEM",
335       GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_WHITE, NULL);
336
337   GST_CAT_EVENT = _gst_debug_category_new ("GST_EVENT",
338       GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
339   GST_CAT_MESSAGE = _gst_debug_category_new ("GST_MESSAGE",
340       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
341   GST_CAT_PARAMS = _gst_debug_category_new ("GST_PARAMS",
342       GST_DEBUG_BOLD | GST_DEBUG_FG_BLACK | GST_DEBUG_BG_YELLOW, NULL);
343   GST_CAT_CALL_TRACE = _gst_debug_category_new ("GST_CALL_TRACE",
344       GST_DEBUG_BOLD, NULL);
345   GST_CAT_SIGNAL = _gst_debug_category_new ("GST_SIGNAL",
346       GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
347   GST_CAT_PROBE = _gst_debug_category_new ("GST_PROBE",
348       GST_DEBUG_BOLD | GST_DEBUG_FG_GREEN, "pad probes");
349   GST_CAT_REGISTRY = _gst_debug_category_new ("GST_REGISTRY", 0, "registry");
350
351
352   /* print out the valgrind message if we're in valgrind */
353   __gst_in_valgrind ();
354 }
355
356 /* we can't do this further above, because we initialize the GST_CAT_DEFAULT struct */
357 #define GST_CAT_DEFAULT _GST_CAT_DEBUG
358
359 /**
360  * gst_debug_log:
361  * @category: category to log
362  * @level: level of the message is in
363  * @file: the file that emitted the message, usually the __FILE__ identifier
364  * @function: the function that emitted the message
365  * @line: the line from that the message was emitted, usually __LINE__
366  * @object: the object this message relates to or NULL if none
367  * @format: a printf style format string
368  * @...: optional arguments for the format
369  * 
370  * Logs the given message using the currently registered debugging handlers.
371  */
372 void
373 gst_debug_log (GstDebugCategory * category, GstDebugLevel level,
374     const gchar * file, const gchar * function, gint line,
375     GObject * object, const gchar * format, ...)
376 {
377   va_list var_args;
378
379   va_start (var_args, format);
380   gst_debug_log_valist (category, level, file, function, line, object, format,
381       var_args);
382   va_end (var_args);
383 }
384
385 /**
386  * gst_debug_log_valist:
387  * @category: category to log
388  * @level: level of the message is in
389  * @file: the file that emitted the message, usually the __FILE__ identifier
390  * @function: the function that emitted the message
391  * @line: the line from that the message was emitted, usually __LINE__
392  * @object: the object this message relates to or NULL if none
393  * @format: a printf style format string
394  * @args: optional arguments for the format
395  * 
396  * Logs the given message using the currently registered debugging handlers.
397  */
398 void
399 gst_debug_log_valist (GstDebugCategory * category, GstDebugLevel level,
400     const gchar * file, const gchar * function, gint line,
401     GObject * object, const gchar * format, va_list args)
402 {
403   GstDebugMessage message;
404   LogFuncEntry *entry;
405   GSList *handler;
406
407   g_return_if_fail (category != NULL);
408   g_return_if_fail (file != NULL);
409   g_return_if_fail (function != NULL);
410   g_return_if_fail (format != NULL);
411
412   message.message = NULL;
413   message.format = format;
414   G_VA_COPY (message.arguments, args);
415
416   handler = __log_functions;
417   while (handler) {
418     entry = handler->data;
419     handler = g_slist_next (handler);
420     entry->func (category, level, file, function, line, object, &message,
421         entry->user_data);
422   }
423   g_free (message.message);
424   va_end (message.arguments);
425 }
426
427 /**
428  * gst_debug_message_get:
429  * @message: a debug message
430  *
431  * Gets the string representation of a #GstDebugMessage. This function is used
432  * in debug handlers to extract the message.
433  *
434  * Returns: the string representation of a #GstDebugMessage.
435  */
436 const gchar *
437 gst_debug_message_get (GstDebugMessage * message)
438 {
439   if (message->message == NULL) {
440     message->message = g_strdup_vprintf (message->format, message->arguments);
441   }
442   return message->message;
443 }
444
445
446 static gchar *
447 gst_debug_print_object (gpointer ptr)
448 {
449   GObject *object = (GObject *) ptr;
450
451 #ifdef unused
452   /* This is a cute trick to detect unmapped memory, but is unportable,
453    * slow, screws around with madvise, and not actually that useful. */
454   {
455     int ret;
456
457     ret = madvise ((void *) ((unsigned long) ptr & (~0xfff)), 4096, 0);
458     if (ret == -1 && errno == ENOMEM) {
459       buffer = g_strdup_printf ("%p (unmapped memory)", ptr);
460     }
461   }
462 #endif
463
464   /* nicely printed object */
465   if (object == NULL) {
466     return g_strdup ("(NULL)");
467   }
468   if (*(GType *) ptr == GST_TYPE_CAPS) {
469     return gst_caps_to_string ((GstCaps *) ptr);
470   }
471   if (*(GType *) ptr == GST_TYPE_STRUCTURE) {
472     return gst_structure_to_string ((GstStructure *) ptr);
473   }
474 #ifdef USE_POISONING
475   if (*(guint32 *) ptr == 0xffffffff) {
476     return g_strdup_printf ("<poisoned@%p>", ptr);
477   }
478 #endif
479   if (GST_IS_PAD (object) && GST_OBJECT_NAME (object)) {
480     return g_strdup_printf ("<%s:%s>", GST_DEBUG_PAD_NAME (object));
481   }
482   if (GST_IS_OBJECT (object) && GST_OBJECT_NAME (object)) {
483     return g_strdup_printf ("<%s>", GST_OBJECT_NAME (object));
484   }
485   if (G_IS_OBJECT (object)) {
486     return g_strdup_printf ("<%s@%p>", G_OBJECT_TYPE_NAME (object), object);
487   }
488
489   return g_strdup_printf ("%p", ptr);
490 }
491
492 /**
493  * gst_debug_construct_term_color:
494  * @colorinfo: the color info
495  * 
496  * Constructs a string that can be used for getting the desired color in color
497  * terminals.
498  * You need to free the string after use.
499  * 
500  * Returns: a string containing the color definition
501  */
502 gchar *
503 gst_debug_construct_term_color (guint colorinfo)
504 {
505   GString *color;
506   gchar *ret;
507
508   color = g_string_new ("\033[00");
509
510   if (colorinfo & GST_DEBUG_BOLD) {
511     g_string_append (color, ";01");
512   }
513   if (colorinfo & GST_DEBUG_UNDERLINE) {
514     g_string_append (color, ";04");
515   }
516   if (colorinfo & GST_DEBUG_FG_MASK) {
517     g_string_append_printf (color, ";3%1d", colorinfo & GST_DEBUG_FG_MASK);
518   }
519   if (colorinfo & GST_DEBUG_BG_MASK) {
520     g_string_append_printf (color, ";4%1d",
521         (colorinfo & GST_DEBUG_BG_MASK) >> 4);
522   }
523   g_string_append (color, "m");
524
525   ret = color->str;
526   g_string_free (color, FALSE);
527   return ret;
528 }
529
530 /**
531  * gst_debug_log_default:
532  * @category: category to log
533  * @level: level of the message
534  * @file: the file that emitted the message, usually the __FILE__ identifier
535  * @function: the function that emitted the message
536  * @line: the line from that the message was emitted, usually __LINE__
537  * @message: the actual message
538  * @object: the object this message relates to or NULL if none
539  * @unused: an unused variable, reserved for some user_data.
540  * 
541  * The default logging handler used by GStreamer. Logging functions get called
542  * whenever a macro like GST_DEBUG or similar is used. This function outputs the
543  * message and additional info using the glib error handler.
544  * You can add other handlers by using #gst_debug_add_log_function. 
545  * And you can remove this handler by calling
546  * gst_debug_remove_log_function (gst_debug_log_default);
547  */
548 void
549 gst_debug_log_default (GstDebugCategory * category, GstDebugLevel level,
550     const gchar * file, const gchar * function, gint line,
551     GObject * object, GstDebugMessage * message, gpointer unused)
552 {
553   gchar *color = NULL;
554   gchar *clear;
555   gchar *obj = NULL;
556   gchar pidcolor[10];
557   gint pid;
558   GTimeVal now;
559   GstClockTime elapsed;
560   gboolean free_color = TRUE;
561   gboolean free_obj = TRUE;
562
563   if (level > gst_debug_category_get_threshold (category))
564     return;
565
566   pid = getpid ();
567
568   /* color info */
569   if (gst_debug_is_colored ()) {
570     color = gst_debug_construct_term_color (gst_debug_category_get_color
571         (category));
572     clear = "\033[00m";
573     g_sprintf (pidcolor, "\033[3%1dm", pid % 6 + 31);
574   } else {
575     color = "\0";
576     free_color = FALSE;
577     clear = "";
578     pidcolor[0] = '\0';
579   }
580
581   if (object) {
582     obj = gst_debug_print_object (object);
583   } else {
584     obj = "\0";
585     free_obj = FALSE;
586   }
587
588   g_get_current_time (&now);
589   elapsed = GST_TIMEVAL_TO_TIME (now) - start_time;
590   g_printerr ("%s (%p - %" GST_TIME_FORMAT
591       ") %s%20s%s(%s%5d%s) %s%s(%d):%s:%s%s %s\n",
592       gst_debug_level_get_name (level), g_thread_self (),
593       GST_TIME_ARGS (elapsed), color,
594       gst_debug_category_get_name (category), clear, pidcolor, pid, clear,
595       color, file, line, function, obj, clear, gst_debug_message_get (message));
596
597   if (free_color)
598     g_free (color);
599   if (free_obj)
600     g_free (obj);
601 }
602
603 /**
604  * gst_debug_level_get_name:
605  * @level: the level to get the name for
606  * 
607  * Get the string trepresentation of a debugging level
608  * 
609  * Returns: the name
610  */
611 const gchar *
612 gst_debug_level_get_name (GstDebugLevel level)
613 {
614   switch (level) {
615     case GST_LEVEL_NONE:
616       return "";
617     case GST_LEVEL_ERROR:
618       return "ERROR";
619     case GST_LEVEL_WARNING:
620       return "WARN ";
621     case GST_LEVEL_INFO:
622       return "INFO ";
623     case GST_LEVEL_DEBUG:
624       return "DEBUG";
625     case GST_LEVEL_LOG:
626       return "LOG  ";
627     default:
628       g_warning ("invalid level specified for gst_debug_level_get_name");
629       return "";
630   }
631 }
632
633 /**
634  * gst_debug_add_log_function:
635  * @func: the function to use
636  * @data: user data
637  * 
638  * Adds the logging function to the list of logging functions.
639  * Be sure to use G_GNUC_NO_INSTRUMENT on that function, it is needed.
640  */
641 void
642 gst_debug_add_log_function (GstLogFunction func, gpointer data)
643 {
644   LogFuncEntry *entry;
645   GSList *list;
646
647   g_return_if_fail (func != NULL);
648
649   entry = g_new (LogFuncEntry, 1);
650   entry->func = func;
651   entry->user_data = data;
652   /* FIXME: we leak the old list here - other threads might access it right now
653    * in gst_debug_logv. Another solution is to lock the mutex in gst_debug_logv,
654    * but that is waaay costly.
655    * It'd probably be clever to use some kind of RCU here, but I don't know 
656    * anything about that.
657    */
658   g_static_mutex_lock (&__log_func_mutex);
659   list = g_slist_copy (__log_functions);
660   __log_functions = g_slist_prepend (list, entry);
661   g_static_mutex_unlock (&__log_func_mutex);
662
663   GST_DEBUG ("prepended log function %p (user data %p) to log functions",
664       func, data);
665 }
666
667 static gint
668 gst_debug_compare_log_function_by_func (gconstpointer entry, gconstpointer func)
669 {
670   gpointer entryfunc = ((LogFuncEntry *) entry)->func;
671
672   return (entryfunc < func) ? -1 : (entryfunc > func) ? 1 : 0;
673 }
674
675 static gint
676 gst_debug_compare_log_function_by_data (gconstpointer entry, gconstpointer data)
677 {
678   gpointer entrydata = ((LogFuncEntry *) entry)->user_data;
679
680   return (entrydata < data) ? -1 : (entrydata > data) ? 1 : 0;
681 }
682
683 static guint
684 gst_debug_remove_with_compare_func (GCompareFunc func, gpointer data)
685 {
686   GSList *found;
687   GSList *new;
688   guint removals = 0;
689
690   g_static_mutex_lock (&__log_func_mutex);
691   new = __log_functions;
692   while ((found = g_slist_find_custom (new, data, func))) {
693     if (new == __log_functions) {
694       new = g_slist_copy (new);
695       continue;
696     }
697     g_free (found->data);
698     new = g_slist_delete_link (new, found);
699     removals++;
700   }
701   /* FIXME: We leak the old list here. See _add_log_function for why. */
702   __log_functions = new;
703   g_static_mutex_unlock (&__log_func_mutex);
704
705   return removals;
706 }
707
708 /**
709  * gst_debug_remove_log_function:
710  * @func: the log function to remove
711  * 
712  * Removes all registrered instances of the given logging functions.
713  * 
714  * Returns: How many instances of the function were removed
715  */
716 guint
717 gst_debug_remove_log_function (GstLogFunction func)
718 {
719   guint removals;
720
721   g_return_val_if_fail (func != NULL, 0);
722
723   removals =
724       gst_debug_remove_with_compare_func
725       (gst_debug_compare_log_function_by_func, func);
726   GST_DEBUG ("removed log function %p %d times from log function list", func,
727       removals);
728
729   return removals;
730 }
731
732 /**
733  * gst_debug_remove_log_function_by_data:
734  * @data: user data of the log function to remove
735  * 
736  * Removes all registrered instances of log functions with the given user data.
737  * 
738  * Returns: How many instances of the function were removed
739  */
740 guint
741 gst_debug_remove_log_function_by_data (gpointer data)
742 {
743   guint removals;
744
745   removals =
746       gst_debug_remove_with_compare_func
747       (gst_debug_compare_log_function_by_data, data);
748   GST_DEBUG
749       ("removed %d log functions with user data %p from log function list",
750       removals, data);
751
752   return removals;
753 }
754
755 /**
756  * gst_debug_set_colored:
757  * @colored: Whether to use colored output or not
758  * 
759  * Sets or unsets the use of coloured debugging output.
760  */
761 void
762 gst_debug_set_colored (gboolean colored)
763 {
764   gst_atomic_int_set (&__use_color, colored ? 1 : 0);
765 }
766
767 /**
768  * gst_debug_is_colored:
769  * 
770  * Checks if the debugging output should be colored.
771  * 
772  * Returns: TRUE, if the debug output should be colored.
773  */
774 gboolean
775 gst_debug_is_colored (void)
776 {
777   return g_atomic_int_get (&__use_color) == 0 ? FALSE : TRUE;
778 }
779
780 /**
781  * gst_debug_set_active:
782  * @active: Whether to use debugging output or not
783  * 
784  * If activated, debugging messages are sent to the debugging
785  * handlers.
786  * It makes sense to deactivate it for speed issues.
787  * <note><para>This function is not threadsafe. It makes sense to only call it
788  * during initialization.</para></note>
789  */
790 void
791 gst_debug_set_active (gboolean active)
792 {
793   __gst_debug_enabled = active;
794 }
795
796 /**
797  * gst_debug_is_active:
798  * 
799  * Checks if debugging output is activated.
800  * 
801  * Returns: TRUE, if debugging is activated
802  */
803 gboolean
804 gst_debug_is_active (void)
805 {
806   return __gst_debug_enabled;
807 }
808
809 /**
810  * gst_debug_set_default_threshold:
811  * @level: level to set
812  * 
813  * Sets the default threshold to the given level and updates all categories to
814  * use this threshold.
815  */
816 void
817 gst_debug_set_default_threshold (GstDebugLevel level)
818 {
819   gst_atomic_int_set (&__default_level, level);
820   gst_debug_reset_all_thresholds ();
821 }
822
823 /**
824  * gst_debug_get_default_threshold:
825  * 
826  * Returns the default threshold that is used for new categories.
827  * 
828  * Returns: the default threshold level
829  */
830 GstDebugLevel
831 gst_debug_get_default_threshold (void)
832 {
833   return (GstDebugLevel) g_atomic_int_get (&__default_level);
834 }
835 static void
836 gst_debug_reset_threshold (gpointer category, gpointer unused)
837 {
838   GstDebugCategory *cat = (GstDebugCategory *) category;
839   GSList *walk;
840
841   g_static_mutex_lock (&__level_name_mutex);
842   walk = __level_name;
843   while (walk) {
844     LevelNameEntry *entry = walk->data;
845
846     walk = g_slist_next (walk);
847     if (g_pattern_match_string (entry->pat, cat->name)) {
848       GST_LOG ("category %s matches pattern %p - gets set to level %d",
849           cat->name, entry->pat, entry->level);
850       gst_debug_category_set_threshold (cat, entry->level);
851       goto exit;
852     }
853   }
854   gst_debug_category_set_threshold (cat, gst_debug_get_default_threshold ());
855
856 exit:
857   g_static_mutex_unlock (&__level_name_mutex);
858 }
859 static void
860 gst_debug_reset_all_thresholds (void)
861 {
862   g_static_mutex_lock (&__cat_mutex);
863   g_slist_foreach (__categories, gst_debug_reset_threshold, NULL);
864   g_static_mutex_unlock (&__cat_mutex);
865 }
866 static void
867 for_each_threshold_by_entry (gpointer data, gpointer user_data)
868 {
869   GstDebugCategory *cat = (GstDebugCategory *) data;
870   LevelNameEntry *entry = (LevelNameEntry *) user_data;
871
872   if (g_pattern_match_string (entry->pat, cat->name)) {
873     GST_LOG ("category %s matches pattern %p - gets set to level %d",
874         cat->name, entry->pat, entry->level);
875     gst_debug_category_set_threshold (cat, entry->level);
876   }
877 }
878
879 /**
880  * gst_debug_set_threshold_for_name:
881  * @name: name of the categories to set
882  * @level: level to set them to
883  *
884  * Sets all categories which match the given glob style pattern to the given
885  * level.
886  */
887 void
888 gst_debug_set_threshold_for_name (const gchar * name, GstDebugLevel level)
889 {
890   GPatternSpec *pat;
891   LevelNameEntry *entry;
892
893   g_return_if_fail (name != NULL);
894
895   pat = g_pattern_spec_new (name);
896   entry = g_new (LevelNameEntry, 1);
897   entry->pat = pat;
898   entry->level = level;
899   g_static_mutex_lock (&__level_name_mutex);
900   __level_name = g_slist_prepend (__level_name, entry);
901   g_static_mutex_unlock (&__level_name_mutex);
902   g_static_mutex_lock (&__cat_mutex);
903   g_slist_foreach (__categories, for_each_threshold_by_entry, entry);
904   g_static_mutex_unlock (&__cat_mutex);
905 }
906
907 /**
908  * gst_debug_unset_threshold_for_name:
909  * @name: name of the categories to set
910  *
911  * Resets all categories with the given name back to the default level.
912  */
913 void
914 gst_debug_unset_threshold_for_name (const gchar * name)
915 {
916   GSList *walk;
917   GPatternSpec *pat;
918
919   g_return_if_fail (name != NULL);
920
921   pat = g_pattern_spec_new (name);
922   g_static_mutex_lock (&__level_name_mutex);
923   walk = __level_name;
924   /* improve this if you want, it's mighty slow */
925   while (walk) {
926     LevelNameEntry *entry = walk->data;
927
928     if (g_pattern_spec_equal (entry->pat, pat)) {
929       __level_name = g_slist_remove_link (__level_name, walk);
930       g_pattern_spec_free (entry->pat);
931       g_free (entry);
932       g_slist_free_1 (walk);
933       walk = __level_name;
934     }
935   }
936   g_static_mutex_unlock (&__level_name_mutex);
937   g_pattern_spec_free (pat);
938   gst_debug_reset_all_thresholds ();
939 }
940
941 GstDebugCategory *
942 _gst_debug_category_new (gchar * name, guint color, gchar * description)
943 {
944   GstDebugCategory *cat;
945
946   g_return_val_if_fail (name != NULL, NULL);
947
948   cat = g_new (GstDebugCategory, 1);
949   cat->name = g_strdup (name);
950   cat->color = color;
951   if (description != NULL) {
952     cat->description = g_strdup (description);
953   } else {
954     cat->description = g_strdup ("no description");
955   }
956   gst_atomic_int_set (&cat->threshold, 0);
957   gst_debug_reset_threshold (cat, NULL);
958
959   /* add to category list */
960   g_static_mutex_lock (&__cat_mutex);
961   __categories = g_slist_prepend (__categories, cat);
962   g_static_mutex_unlock (&__cat_mutex);
963
964   return cat;
965 }
966
967 /**
968  * gst_debug_category_free:
969  * @category: #GstDebugCategory to free.
970  *
971  * Removes and frees the category and all associated resources.
972  */
973 void
974 gst_debug_category_free (GstDebugCategory * category)
975 {
976   if (category == NULL)
977     return;
978
979   /* remove from category list */
980   g_static_mutex_lock (&__cat_mutex);
981   __categories = g_slist_remove (__categories, category);
982   g_static_mutex_unlock (&__cat_mutex);
983
984   g_free ((gpointer) category->name);
985   g_free ((gpointer) category->description);
986   g_free (category);
987 }
988
989 /**
990  * gst_debug_category_set_threshold:
991  * @category: a #GstDebugCategory to set threshold of.
992  * @level: the #GstDebugLevel threshold to set.
993  *
994  * Sets the threshold of the category to the given level. Debug information will
995  * only be output if the threshold is lower or equal to the level of the
996  * debugging message.
997  * <note><para>
998  * Do not use this function in production code, because other functions may
999  * change the threshold of categories as side effect. It is however a nice
1000  * function to use when debugging (even from gdb).
1001  * </para></note>
1002  */
1003 void
1004 gst_debug_category_set_threshold (GstDebugCategory * category,
1005     GstDebugLevel level)
1006 {
1007   g_return_if_fail (category != NULL);
1008
1009   gst_atomic_int_set (&category->threshold, level);
1010 }
1011
1012 /**
1013  * gst_debug_category_reset_threshold:
1014  * @category: a #GstDebugCategory to reset threshold of.
1015  *
1016  * Resets the threshold of the category to the default level. Debug information
1017  * will only be output if the threshold is lower or equal to the level of the
1018  * debugging message.
1019  * Use this function to set the threshold back to where it was after using
1020  * gst_debug_category_set_threshold().
1021  */
1022 void
1023 gst_debug_category_reset_threshold (GstDebugCategory * category)
1024 {
1025   gst_debug_reset_threshold (category, NULL);
1026 }
1027
1028 /**
1029  * gst_debug_category_get_threshold:
1030  * @category: a #GstDebugCategory to get threshold of.
1031  *
1032  * Returns the threshold of a #GstCategory.
1033  *
1034  * Returns: the #GstDebugLevel that is used as threshold.
1035  */
1036 GstDebugLevel
1037 gst_debug_category_get_threshold (GstDebugCategory * category)
1038 {
1039   return g_atomic_int_get (&category->threshold);
1040 }
1041
1042 /**
1043  * gst_debug_category_get_name:
1044  * @category: a #GstDebugCategory to get name of.
1045  *
1046  * Returns the name of a debug category.
1047  *
1048  * Returns: the name of the category.
1049  */
1050 const gchar *
1051 gst_debug_category_get_name (GstDebugCategory * category)
1052 {
1053   return category->name;
1054 }
1055
1056 /**
1057  * gst_debug_category_get_color:
1058  * @category: a #GstDebugCategory to get the color of.
1059  *
1060  * Returns the color of a debug category used when printing output in this
1061  * category.
1062  *
1063  * Returns: the color of the category.
1064  */
1065 guint
1066 gst_debug_category_get_color (GstDebugCategory * category)
1067 {
1068   return category->color;
1069 }
1070
1071 /**
1072  * gst_debug_category_get_description:
1073  * @category: a #GstDebugCategory to get the description of.
1074  *
1075  * Returns the description of a debug category.
1076  *
1077  * Returns: the description of the category.
1078  */
1079 const gchar *
1080 gst_debug_category_get_description (GstDebugCategory * category)
1081 {
1082   return category->description;
1083 }
1084
1085 /**
1086  * gst_debug_get_all_categories:
1087  *
1088  * Returns a snapshot of a all categories that are currently in use . This list
1089  * may change anytime.
1090  * The caller has to free the list after use.
1091  * <emphasis>This function is not threadsafe, so only use it while only the
1092  * main thread is running.</emphasis>
1093  *
1094  * Returns: the list of categories
1095  */
1096 GSList *
1097 gst_debug_get_all_categories (void)
1098 {
1099   GSList *ret;
1100
1101   g_static_mutex_lock (&__cat_mutex);
1102   ret = g_slist_copy (__categories);
1103   g_static_mutex_unlock (&__cat_mutex);
1104
1105   return ret;
1106 }
1107
1108 /*** FUNCTION POINTERS ********************************************************/
1109
1110 static GHashTable *__gst_function_pointers;     /* NULL */
1111 static GStaticMutex __dbg_functions_mutex = G_STATIC_MUTEX_INIT;
1112
1113 const gchar *
1114 _gst_debug_nameof_funcptr (GstDebugFuncPtr ptr)
1115     G_GNUC_NO_INSTRUMENT;
1116
1117 /* This function MUST NOT return NULL */
1118      const gchar *_gst_debug_nameof_funcptr (GstDebugFuncPtr func)
1119 {
1120   gpointer ptr = (gpointer) func;
1121   gchar *ptrname;
1122
1123 #ifdef HAVE_DLADDR
1124   Dl_info dlinfo;
1125 #endif
1126
1127   if (__gst_function_pointers) {
1128     g_static_mutex_lock (&__dbg_functions_mutex);
1129     ptrname = g_hash_table_lookup (__gst_function_pointers, ptr);
1130     g_static_mutex_unlock (&__dbg_functions_mutex);
1131     if (ptrname)
1132       return ptrname;
1133   }
1134   /* we need to create an entry in the hash table for this one so we don't leak
1135    * the name */
1136 #ifdef HAVE_DLADDR
1137   if (dladdr (ptr, &dlinfo) && dlinfo.dli_sname) {
1138     gchar *name = g_strdup (dlinfo.dli_sname);
1139
1140     _gst_debug_register_funcptr (ptr, name);
1141     return name;
1142   } else
1143 #endif
1144   {
1145     gchar *name = g_strdup_printf ("%p", ptr);
1146
1147     _gst_debug_register_funcptr (ptr, name);
1148     return name;
1149   }
1150 }
1151
1152 void
1153 _gst_debug_register_funcptr (GstDebugFuncPtr func, gchar * ptrname)
1154 {
1155   gpointer ptr = (gpointer) func;
1156
1157   g_static_mutex_lock (&__dbg_functions_mutex);
1158
1159   if (!__gst_function_pointers)
1160     __gst_function_pointers = g_hash_table_new (g_direct_hash, g_direct_equal);
1161   if (!g_hash_table_lookup (__gst_function_pointers, ptr))
1162     g_hash_table_insert (__gst_function_pointers, ptr, ptrname);
1163
1164   g_static_mutex_unlock (&__dbg_functions_mutex);
1165 }
1166
1167 #ifdef HAVE_PRINTF_EXTENSION
1168 static int
1169 _gst_info_printf_extension (FILE * stream, const struct printf_info *info,
1170     const void *const *args)
1171 {
1172   char *buffer;
1173   int len;
1174   void *ptr;
1175
1176   buffer = NULL;
1177   ptr = *(void **) args[0];
1178
1179   buffer = gst_debug_print_object (ptr);
1180   len = fprintf (stream, "%*s", (info->left ? -info->width : info->width),
1181       buffer);
1182
1183   free (buffer);
1184   return len;
1185 }
1186
1187 static int
1188 _gst_info_printf_extension_arginfo (const struct printf_info *info, size_t n,
1189     int *argtypes)
1190 {
1191   if (n > 0)
1192     argtypes[0] = PA_POINTER;
1193   return 1;
1194 }
1195 #endif /* HAVE_PRINTF_EXTENSION */
1196
1197 #else /* !GST_DISABLE_GST_DEBUG */
1198 guint
1199 gst_debug_remove_log_function (GstLogFunction func)
1200 {
1201   return 0;
1202 }
1203
1204 guint
1205 gst_debug_remove_log_function_by_data (gpointer data)
1206 {
1207   return 0;
1208 }
1209
1210 gboolean
1211 __gst_in_valgrind (void)
1212 {
1213   return FALSE;
1214 }
1215
1216 #endif /* GST_DISABLE_GST_DEBUG */
1217
1218
1219 #ifdef GST_ENABLE_FUNC_INSTRUMENTATION
1220 /* FIXME make this thread specific */
1221 static GSList *stack_trace = NULL;
1222
1223 void
1224 __cyg_profile_func_enter (void *this_fn, void *call_site)
1225     G_GNUC_NO_INSTRUMENT;
1226      void __cyg_profile_func_enter (void *this_fn, void *call_site)
1227 {
1228   gchar *name = _gst_debug_nameof_funcptr (this_fn);
1229   gchar *site = _gst_debug_nameof_funcptr (call_site);
1230
1231   GST_CAT_DEBUG (GST_CAT_CALL_TRACE, "entering function %s from %s", name,
1232       site);
1233   stack_trace =
1234       g_slist_prepend (stack_trace, g_strdup_printf ("%8p in %s from %p (%s)",
1235           this_fn, name, call_site, site));
1236
1237   g_free (name);
1238   g_free (site);
1239 }
1240
1241 void
1242 __cyg_profile_func_exit (void *this_fn, void *call_site)
1243     G_GNUC_NO_INSTRUMENT;
1244      void __cyg_profile_func_exit (void *this_fn, void *call_site)
1245 {
1246   gchar *name = _gst_debug_nameof_funcptr (this_fn);
1247
1248   GST_CAT_DEBUG (GST_CAT_CALL_TRACE, "leaving function %s", name);
1249   g_free (stack_trace->data);
1250   stack_trace = g_slist_delete_link (stack_trace, stack_trace);
1251
1252   g_free (name);
1253 }
1254
1255 /**
1256  * gst_debug_print_stack_trace:
1257  *
1258  * If GST_ENABLE_FUNC_INSTRUMENTATION is defined a stacktracke is available for
1259  * gstreamer code, which can be printed with this function. 
1260  */
1261 void
1262 gst_debug_print_stack_trace (void)
1263 {
1264   GSList *walk = stack_trace;
1265   gint count = 0;
1266
1267   if (walk)
1268     walk = g_slist_next (walk);
1269
1270   while (walk) {
1271     gchar *name = (gchar *) walk->data;
1272
1273     g_print ("#%-2d %s\n", count++, name);
1274
1275     walk = g_slist_next (walk);
1276   }
1277 }
1278 #else
1279 void
1280 gst_debug_print_stack_trace (void)
1281 {
1282   /* nothing because it's compiled out */
1283 }
1284
1285 #endif /* GST_ENABLE_FUNC_INTSTRUMENTATION */