X-Git-Url: http://review.tizen.org/git/?a=blobdiff_plain;f=gst%2Fgstinfo.c;h=2dcf04d5bc56ae30a9468a77b5c907631f4c9d71;hb=37edc474e3dc292d53e64f9415536da1741ecede;hp=8e8f00f6e6106dbfe3456f89db08f12bc6b28472;hpb=a837ff6581ba16180e89352a753296cd74a85a72;p=platform%2Fupstream%2Fgstreamer.git diff --git a/gst/gstinfo.c b/gst/gstinfo.c index 8e8f00f..2dcf04d 100644 --- a/gst/gstinfo.c +++ b/gst/gstinfo.c @@ -24,6 +24,7 @@ /** * SECTION:gstinfo + * @title: GstInfo * @short_description: Debugging and logging facilities * @see_also: #gst-running for command line parameters * and environment variables that affect the debugging output. @@ -317,13 +318,14 @@ _priv_gst_in_valgrind (void) } static gchar * -_replace_pattern_in_gst_debug_file_name (gchar * name, const char * token, guint val) +_replace_pattern_in_gst_debug_file_name (gchar * name, const char *token, + guint val) { - gchar * token_start; + gchar *token_start; if ((token_start = strstr (name, token))) { gsize token_len = strlen (token); - gchar * name_prefix = name; - gchar * name_suffix = token_start + token_len; + gchar *name_prefix = name; + gchar *name_suffix = token_start + token_len; token_start[0] = '\0'; name = g_strdup_printf ("%s%u%s", name_prefix, val, name_suffix); g_free (name_prefix); @@ -404,7 +406,7 @@ _priv_gst_debug_init (void) GST_CAT_ELEMENT_PADS = _gst_debug_category_new ("GST_ELEMENT_PADS", GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL); GST_CAT_PADS = _gst_debug_category_new ("GST_PADS", - GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_RED, NULL); + GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_BLUE, NULL); GST_CAT_PERFORMANCE = _gst_debug_category_new ("GST_PERFORMANCE", GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL); GST_CAT_PIPELINE = _gst_debug_category_new ("GST_PIPELINE", @@ -461,9 +463,8 @@ _priv_gst_debug_init (void) gst_debug_set_color_mode_from_string (env); env = g_getenv ("GST_DEBUG"); - if (env) { + if (env) gst_debug_set_threshold_from_string (env, FALSE); - } } /* we can't do this further above, because we initialize the GST_CAT_DEFAULT struct */ @@ -573,7 +574,7 @@ gst_debug_log_valist (GstDebugCategory * category, GstDebugLevel level, * Gets the string representation of a #GstDebugMessage. This function is used * in debug handlers to extract the message. * - * Returns: the string representation of a #GstDebugMessage. + * Returns: (nullable): the string representation of a #GstDebugMessage. */ const gchar * gst_debug_message_get (GstDebugMessage * message) @@ -1136,9 +1137,19 @@ gst_debug_log_default (GstDebugCategory * category, GstDebugLevel level, GstClockTime elapsed; gchar *obj = NULL; GstDebugColorMode color_mode; + const gchar *message_str; FILE *log_file = user_data ? user_data : stderr; gchar c; + /* Get message string first because printing it might call into our custom + * printf format extension mechanism which in turn might log something, e.g. + * from inside gst_structure_to_string() when something can't be serialised. + * This means we either need to do this outside of any critical section or + * use a recursive lock instead. As we always need the message string in all + * code paths, we might just as well get it here first thing and outside of + * the win_print_mutex critical section. */ + message_str = gst_debug_message_get (message); + /* __FILE__ might be a file name or an absolute path or a * relative path, irrespective of the exact compiler used, * in which case we want to shorten it to the filename for @@ -1185,7 +1196,7 @@ gst_debug_log_default (GstDebugCategory * category, GstDebugLevel level, pidcolor, pid, clear, g_thread_self (), levelcolor, gst_debug_level_get_name (level), clear, color, gst_debug_category_get_name (category), file, line, function, obj, - clear, gst_debug_message_get (message)); + clear, message_str); fflush (log_file); #undef PRINT_FMT g_free (color); @@ -1220,7 +1231,7 @@ gst_debug_log_default (GstDebugCategory * category, GstDebugLevel level, fflush (log_file); /* message */ SET_COLOR (clear); - fprintf (log_file, " %s\n", gst_debug_message_get (message)); + fprintf (log_file, " %s\n", message_str); fflush (log_file); } g_mutex_unlock (&win_print_mutex); @@ -1231,7 +1242,7 @@ gst_debug_log_default (GstDebugCategory * category, GstDebugLevel level, fprintf (log_file, "%" GST_TIME_FORMAT PRINT_FMT, GST_TIME_ARGS (elapsed), pid, g_thread_self (), gst_debug_level_get_name (level), gst_debug_category_get_name (category), file, line, function, obj, - gst_debug_message_get (message)); + message_str); fflush (log_file); #undef PRINT_FMT } @@ -1521,8 +1532,8 @@ gst_debug_get_color_mode (void) * If activated, debugging messages are sent to the debugging * handlers. * It makes sense to deactivate it for speed issues. - * This function is not threadsafe. It makes sense to only call it - * during initialization. + * > This function is not threadsafe. It makes sense to only call it + * during initialization. */ void gst_debug_set_active (gboolean active) @@ -1576,6 +1587,20 @@ gst_debug_get_default_threshold (void) return (GstDebugLevel) g_atomic_int_get (&__default_level); } +static gboolean +gst_debug_apply_entry (GstDebugCategory * cat, LevelNameEntry * entry) +{ + if (!g_pattern_match_string (entry->pat, cat->name)) + return FALSE; + + if (gst_is_initialized ()) + GST_LOG ("category %s matches pattern %p - gets set to level %d", + cat->name, entry->pat, entry->level); + + gst_debug_category_set_threshold (cat, entry->level); + return TRUE; +} + static void gst_debug_reset_threshold (gpointer category, gpointer unused) { @@ -1583,23 +1608,16 @@ gst_debug_reset_threshold (gpointer category, gpointer unused) GSList *walk; g_mutex_lock (&__level_name_mutex); - walk = __level_name; - while (walk) { - LevelNameEntry *entry = walk->data; - walk = g_slist_next (walk); - if (g_pattern_match_string (entry->pat, cat->name)) { - if (gst_is_initialized ()) - GST_LOG ("category %s matches pattern %p - gets set to level %d", - cat->name, entry->pat, entry->level); - gst_debug_category_set_threshold (cat, entry->level); - goto exit; - } + for (walk = __level_name; walk != NULL; walk = walk->next) { + if (gst_debug_apply_entry (cat, walk->data)) + break; } - gst_debug_category_set_threshold (cat, gst_debug_get_default_threshold ()); -exit: g_mutex_unlock (&__level_name_mutex); + + if (walk == NULL) + gst_debug_category_set_threshold (cat, gst_debug_get_default_threshold ()); } static void @@ -1616,12 +1634,7 @@ for_each_threshold_by_entry (gpointer data, gpointer user_data) GstDebugCategory *cat = (GstDebugCategory *) data; LevelNameEntry *entry = (LevelNameEntry *) user_data; - if (g_pattern_match_string (entry->pat, cat->name)) { - if (gst_is_initialized ()) - GST_LOG ("category %s matches pattern %p - gets set to level %d", - cat->name, entry->pat, entry->level); - gst_debug_category_set_threshold (cat, entry->level); - } + gst_debug_apply_entry (cat, entry); } /** @@ -1753,11 +1766,9 @@ gst_debug_category_free (GstDebugCategory * category) * Sets the threshold of the category to the given level. Debug information will * only be output if the threshold is lower or equal to the level of the * debugging message. - * - * Do not use this function in production code, because other functions may - * change the threshold of categories as side effect. It is however a nice - * function to use when debugging (even from gdb). - * + * > Do not use this function in production code, because other functions may + * > change the threshold of categories as side effect. It is however a nice + * > function to use when debugging (even from gdb). */ void gst_debug_category_set_threshold (GstDebugCategory * category, @@ -1976,7 +1987,7 @@ gst_debug_set_threshold_from_string (const gchar * list, gboolean reset) g_assert (list); if (reset) - gst_debug_set_default_threshold (0); + gst_debug_set_default_threshold (GST_LEVEL_DEFAULT); split = g_strsplit (list, ",", 0); @@ -1989,8 +2000,15 @@ gst_debug_set_threshold_from_string (const gchar * list, gboolean reset) const gchar *category; if (parse_debug_category (values[0], &category) - && parse_debug_level (values[1], &level)) + && parse_debug_level (values[1], &level)) { gst_debug_set_threshold_for_name (category, level); + + /* bump min-level anyway to allow the category to be registered in the + * future still */ + if (level > _gst_debug_min) { + _gst_debug_min = level; + } + } } g_strfreev (values); @@ -2418,7 +2436,7 @@ gst_info_vasprintf (gchar ** result, const gchar * format, va_list args) * * Free with g_free(). * - * Returns: a newly allocated null terminated string or %NULL on any error + * Returns: (nullable): a newly allocated null terminated string or %NULL on any error * * Since: 1.8 */ @@ -2445,7 +2463,7 @@ gst_info_strdup_vprintf (const gchar * format, va_list args) * * Free with g_free(). * - * Returns: a newly allocated null terminated string or %NULL on any error + * Returns: (nullable): a newly allocated null terminated string or %NULL on any error * * Since: 1.8 */ @@ -2605,23 +2623,12 @@ gst_printerrln (const gchar * format, ...) #ifdef HAVE_UNWIND #ifdef HAVE_DW static gboolean -append_debug_info (GString * trace, const void *ip) +append_debug_info (GString * trace, Dwfl * dwfl, const void *ip) { - Dwfl *dwfl; Dwfl_Line *line; Dwarf_Addr addr; Dwfl_Module *module; const gchar *function_name; - gchar *debuginfo_path = NULL; - Dwfl_Callbacks callbacks = { - .find_elf = dwfl_linux_proc_find_elf, - .find_debuginfo = dwfl_standard_find_debuginfo, - .debuginfo_path = &debuginfo_path, - }; - - dwfl = dwfl_begin (&callbacks); - if (!dwfl) - return FALSE; if (dwfl_linux_proc_report (dwfl, getpid ()) != 0) return FALSE; @@ -2656,24 +2663,54 @@ append_debug_info (GString * trace, const void *ip) #endif /* HAVE_DW */ static gchar * -generate_unwind_trace (void) +generate_unwind_trace (GstStackTraceFlags flags) { + gint unret; unw_context_t uc; unw_cursor_t cursor; gboolean use_libunwind = TRUE; GString *trace = g_string_new (NULL); - unw_getcontext (&uc); - unw_init_local (&cursor, &uc); +#ifdef HAVE_DW + Dwfl *dwfl = NULL; + Dwfl_Callbacks callbacks = { + .find_elf = dwfl_linux_proc_find_elf, + .find_debuginfo = dwfl_standard_find_debuginfo, + }; + + if ((flags & GST_STACK_TRACE_SHOW_FULL)) + dwfl = dwfl_begin (&callbacks); +#endif /* HAVE_DW */ + + unret = unw_getcontext (&uc); + if (unret) { + GST_DEBUG ("Could not get libunwind context (%d)", unret); + + goto done; + } + unret = unw_init_local (&cursor, &uc); + if (unret) { + GST_DEBUG ("Could not init libunwind context (%d)", unret); + + goto done; + } while (unw_step (&cursor) > 0) { #ifdef HAVE_DW - unw_word_t ip; + if (dwfl) { + unw_word_t ip; + + unret = unw_get_reg (&cursor, UNW_REG_IP, &ip); + if (unret) { + GST_DEBUG ("libunwind could read frame info (%d)", unret); + + goto done; + } - unw_get_reg (&cursor, UNW_REG_IP, &ip); - if (append_debug_info (trace, (void *) (ip - 4))) { - use_libunwind = FALSE; - g_string_append (trace, ")\n"); + if (append_debug_info (trace, dwfl, (void *) (ip - 4))) { + use_libunwind = FALSE; + g_string_append (trace, ")\n"); + } } #endif /* HAVE_DW */ @@ -2687,6 +2724,12 @@ generate_unwind_trace (void) } } +done: +#ifdef HAVE_DW + if (dwfl) + dwfl_end (dwfl); +#endif + return g_string_free (trace, FALSE); } @@ -2712,32 +2755,45 @@ generate_backtrace_trace (void) for (j = 0; j < nptrs; j++) g_string_append_printf (trace, "%s\n", strings[j]); + free (strings); + return g_string_free (trace, FALSE); } +#else +#define generate_backtrace_trace() NULL #endif /* HAVE_BACKTRACE */ /** * gst_debug_get_stack_trace: + * @flags: A set of #GstStackTraceFlags to determine how the stack + * trace should look like. Pass 0 to retrieve a minimal backtrace. + * + * Returns: (nullable): a stack trace, if libunwind or glibc backtrace are + * present, else %NULL. * - * If libunwind or glibc backtrace are present, a stack trace - * is returned. + * Since: 1.12 */ gchar * -gst_debug_get_stack_trace (void) +gst_debug_get_stack_trace (GstStackTraceFlags flags) { gchar *trace = NULL; +#ifdef HAVE_BACKTRACE + gboolean have_backtrace = TRUE; +#else + gboolean have_backtrace = FALSE; +#endif #ifdef HAVE_UNWIND - trace = generate_unwind_trace (); - if (trace) - return trace; + if ((flags & GST_STACK_TRACE_SHOW_FULL) || !have_backtrace) + trace = generate_unwind_trace (flags); #endif /* HAVE_UNWIND */ -#ifdef HAVE_BACKTRACE - trace = generate_backtrace_trace (); -#endif /* HAVE_BACKTRACE */ + if (trace) + return trace; + else if (have_backtrace) + return generate_backtrace_trace (); - return trace; + return NULL; } /** @@ -2749,10 +2805,299 @@ gst_debug_get_stack_trace (void) void gst_debug_print_stack_trace (void) { - gchar *trace = gst_debug_get_stack_trace (); + gchar *trace = gst_debug_get_stack_trace (GST_STACK_TRACE_SHOW_FULL); if (trace) g_print ("%s\n", trace); g_free (trace); } + +#ifndef GST_DISABLE_GST_DEBUG +typedef struct +{ + guint max_size_per_thread; + guint thread_timeout; + GQueue threads; + GHashTable *thread_index; +} GstRingBufferLogger; + +typedef struct +{ + GList *link; + gint64 last_use; + GThread *thread; + + GQueue log; + gsize log_size; +} GstRingBufferLog; + +G_LOCK_DEFINE_STATIC (ring_buffer_logger); +static GstRingBufferLogger *ring_buffer_logger = NULL; + +static void +gst_ring_buffer_logger_log (GstDebugCategory * category, + GstDebugLevel level, + const gchar * file, + const gchar * function, + gint line, GObject * object, GstDebugMessage * message, gpointer user_data) +{ + GstRingBufferLogger *logger = user_data; + gint pid; + GThread *thread; + GstClockTime elapsed; + gchar *obj = NULL; + gchar c; + gchar *output; + gsize output_len; + GstRingBufferLog *log; + gint64 now = g_get_monotonic_time (); + const gchar *message_str = gst_debug_message_get (message); + + G_LOCK (ring_buffer_logger); + + if (logger->thread_timeout > 0) { + /* Remove all threads that saw no output since thread_timeout seconds. + * By construction these are all at the tail of the queue, and the queue + * is ordered by last use, so we just need to look at the tail. + */ + while (logger->threads.tail) { + log = logger->threads.tail->data; + if (log->last_use + logger->thread_timeout * G_USEC_PER_SEC >= now) + break; + + g_hash_table_remove (logger->thread_index, log->thread); + while ((output = g_queue_pop_head (&log->log))) + g_free (output); + g_free (log); + g_queue_pop_tail (&logger->threads); + } + } + + /* Get logger for this thread, and put it back at the + * head of the threads queue */ + thread = g_thread_self (); + log = g_hash_table_lookup (logger->thread_index, thread); + if (!log) { + log = g_new0 (GstRingBufferLog, 1); + g_queue_init (&log->log); + log->log_size = 0; + g_queue_push_head (&logger->threads, log); + log->link = logger->threads.head; + log->thread = thread; + g_hash_table_insert (logger->thread_index, thread, log); + } else { + g_queue_unlink (&logger->threads, log->link); + g_queue_push_head_link (&logger->threads, log->link); + } + log->last_use = now; + + /* __FILE__ might be a file name or an absolute path or a + * relative path, irrespective of the exact compiler used, + * in which case we want to shorten it to the filename for + * readability. */ + c = file[0]; + if (c == '.' || c == '/' || c == '\\' || (c != '\0' && file[1] == ':')) { + file = gst_path_basename (file); + } + + pid = getpid (); + + if (object) { + obj = gst_debug_print_object (object); + } else { + obj = (gchar *) ""; + } + + elapsed = GST_CLOCK_DIFF (_priv_gst_start_time, gst_util_get_timestamp ()); + + /* no color, all platforms */ +#define PRINT_FMT " "PID_FMT" "PTR_FMT" %s "CAT_FMT" %s\n" + output = + g_strdup_printf ("%" GST_TIME_FORMAT PRINT_FMT, GST_TIME_ARGS (elapsed), + pid, thread, gst_debug_level_get_name (level), + gst_debug_category_get_name (category), file, line, function, obj, + message_str); +#undef PRINT_FMT + + output_len = strlen (output); + + if (output_len < logger->max_size_per_thread) { + gchar *buf; + + /* While using a GQueue here is not the most efficient thing to do, we + * have to allocate a string for every output anyway and could just store + * that instead of copying it to an actual ringbuffer. + * Better than GQueue would be GstQueueArray, but that one is in + * libgstbase and we can't use it here. That one allocation will not make + * much of a difference anymore, considering the number of allocations + * needed to get to this point... + */ + while (log->log_size + output_len > logger->max_size_per_thread) { + buf = g_queue_pop_head (&log->log); + log->log_size -= strlen (buf); + g_free (buf); + } + g_queue_push_tail (&log->log, output); + log->log_size += output_len; + } else { + gchar *buf; + + /* Can't really write anything as the line is bigger than the maximum + * allowed log size already, so just remove everything */ + + while ((buf = g_queue_pop_head (&log->log))) + g_free (buf); + g_free (output); + log->log_size = 0; + } + + if (object != NULL) + g_free (obj); + + G_UNLOCK (ring_buffer_logger); +} + +/** + * gst_debug_ring_buffer_logger_get_logs: + * + * Fetches the current logs per thread from the ring buffer logger. See + * gst_debug_add_ring_buffer_logger() for details. + * + * Returns: (transfer full) (array zero-terminated): NULL-terminated array of + * strings with the debug output per thread + * + * Since: 1.14 + */ +gchar ** +gst_debug_ring_buffer_logger_get_logs (void) +{ + gchar **logs, **tmp; + GList *l; + + g_return_val_if_fail (ring_buffer_logger != NULL, NULL); + + G_LOCK (ring_buffer_logger); + + tmp = logs = g_new0 (gchar *, ring_buffer_logger->threads.length + 1); + for (l = ring_buffer_logger->threads.head; l; l = l->next) { + GstRingBufferLog *log = l->data; + GList *l; + gchar *p; + gsize len; + + *tmp = p = g_new0 (gchar, log->log_size + 1); + + for (l = log->log.head; l; l = l->next) { + len = strlen (l->data); + memcpy (p, l->data, len); + p += len; + } + + tmp++; + } + + G_UNLOCK (ring_buffer_logger); + + return logs; +} + +static void +gst_ring_buffer_logger_free (GstRingBufferLogger * logger) +{ + G_LOCK (ring_buffer_logger); + if (ring_buffer_logger == logger) { + GstRingBufferLog *log; + + while ((log = g_queue_pop_head (&logger->threads))) { + gchar *buf; + while ((buf = g_queue_pop_head (&log->log))) + g_free (buf); + g_free (log); + } + + g_hash_table_unref (logger->thread_index); + + g_free (logger); + ring_buffer_logger = NULL; + } + G_UNLOCK (ring_buffer_logger); +} + +/** + * gst_debug_add_ring_buffer_logger: + * @max_size_per_thread: Maximum size of log per thread in bytes + * @thread_timeout: Timeout for threads in seconds + * + * Adds a memory ringbuffer based debug logger that stores up to + * @max_size_per_thread bytes of logs per thread and times out threads after + * @thread_timeout seconds of inactivity. + * + * Logs can be fetched with gst_debug_ring_buffer_logger_get_logs() and the + * logger can be removed again with gst_debug_remove_ring_buffer_logger(). + * Only one logger at a time is possible. + * + * Since: 1.14 + */ +void +gst_debug_add_ring_buffer_logger (guint max_size_per_thread, + guint thread_timeout) +{ + GstRingBufferLogger *logger; + + G_LOCK (ring_buffer_logger); + + if (ring_buffer_logger) { + g_warn_if_reached (); + G_UNLOCK (ring_buffer_logger); + return; + } + + logger = ring_buffer_logger = g_new0 (GstRingBufferLogger, 1); + + logger->max_size_per_thread = max_size_per_thread; + logger->thread_timeout = thread_timeout; + logger->thread_index = g_hash_table_new (g_direct_hash, g_direct_equal); + g_queue_init (&logger->threads); + + gst_debug_add_log_function (gst_ring_buffer_logger_log, logger, + (GDestroyNotify) gst_ring_buffer_logger_free); + G_UNLOCK (ring_buffer_logger); +} + +/** + * gst_debug_remove_ring_buffer_logger: + * + * Removes any previously added ring buffer logger with + * gst_debug_add_ring_buffer_logger(). + * + * Since: 1.14 + */ +void +gst_debug_remove_ring_buffer_logger (void) +{ + gst_debug_remove_log_function (gst_ring_buffer_logger_log); +} + +#else /* GST_DISABLE_GST_DEBUG */ +#ifndef GST_REMOVE_DISABLED + +gchar ** +gst_debug_ring_buffer_logger_get_logs (void) +{ + return NULL; +} + +void +gst_debug_add_ring_buffer_logger (guint max_size_per_thread, + guint thread_timeout) +{ +} + +void +gst_debug_remove_ring_buffer_logger (void) +{ +} + +#endif /* GST_REMOVE_DISABLED */ +#endif /* GST_DISABLE_GST_DEBUG */