gstinfo.c 76.2 KB
Newer Older
1 2 3
/* GStreamer
 * Copyright (C) 1999,2000 Erik Walthinsen <omega@cse.ogi.edu>
 *                    2000 Wim Taymans <wtay@chello.be>
4
 *                    2003 Benjamin Otte <in7y118@public.uni-hamburg.de>
5
 * Copyright (C) 2008-2009 Tim-Philipp Müller <tim centricular net>
6
 *
7
 * gstinfo.c: debugging functions
8 9 10 11 12 13 14 15 16 17 18 19 20
 *
 * This library is free software; you can redistribute it and/or
 * modify it under the terms of the GNU Library General Public
 * License as published by the Free Software Foundation; either
 * version 2 of the License, or (at your option) any later version.
 *
 * This library is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
 * Library General Public License for more details.
 *
 * You should have received a copy of the GNU Library General Public
 * License along with this library; if not, write to the
Tim-Philipp Müller's avatar
Tim-Philipp Müller committed
21 22
 * Free Software Foundation, Inc., 51 Franklin St, Fifth Floor,
 * Boston, MA 02110-1301, USA.
23
 */
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
24

25 26
/**
 * SECTION:gstinfo
27
 * @title: GstInfo
28
 * @short_description: Debugging and logging facilities
29
 * @see_also: #gst-running for command line parameters
30 31 32
 * and environment variables that affect the debugging output.
 *
 * GStreamer's debugging subsystem is an easy way to get information about what
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
33 34
 * the application is doing.  It is not meant for programming errors. Use GLib
 * methods (g_warning and friends) for that.
35
 *
36
 * The debugging subsystem works only after GStreamer has been initialized
37 38 39
 * - for example by calling gst_init().
 *
 * The debugging subsystem is used to log informational messages while the
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
40 41 42 43 44 45
 * application runs.  Each messages has some properties attached to it. Among
 * these properties are the debugging category, the severity (called "level"
 * here) and an optional #GObject it belongs to. Each of these messages is sent
 * to all registered debugging handlers, which then handle the messages.
 * GStreamer attaches a default handler on startup, which outputs requested
 * messages to stderr.
46
 *
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
47
 * Messages are output by using shortcut macros like #GST_DEBUG,
48 49
 * #GST_CAT_ERROR_OBJECT or similar. These all expand to calling gst_debug_log()
 * with the right parameters.
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
50
 * The only thing a developer will probably want to do is define his own
51 52
 * categories. This is easily done with 3 lines. At the top of your code,
 * declare
53
 * the variables and set the default category.
54
 * |[<!-- language="C" -->
55 56 57
 *   GST_DEBUG_CATEGORY_STATIC (my_category);  // define category (statically)
 *   #define GST_CAT_DEFAULT my_category       // set as default
 * ]|
58
 * After that you only need to initialize the category.
59
 * |[<!-- language="C" -->
60 61 62
 *   GST_DEBUG_CATEGORY_INIT (my_category, "my category",
 *                            0, "This is my very own");
 * ]|
63
 * Initialization must be done before the category is used first.
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
64
 * Plugins do this
65 66 67 68
 * in their plugin_init function, libraries and applications should do that
 * during their initialization.
 *
 * The whole debugging subsystem can be disabled at build time with passing the
69
 * --disable-gst-debug switch to configure. If this is done, every function,
Stefan Kost's avatar
Stefan Kost committed
70 71 72
 * macro and even structs described in this file evaluate to default values or
 * nothing at all.
 * So don't take addresses of these functions or use other tricks.
73 74 75 76
 * If you must do that for some reason, there is still an option.
 * If the debugging
 * subsystem was compiled out, #GST_DISABLE_GST_DEBUG is defined in
 * &lt;gst/gst.h&gt;,
77
 * so you can check that before doing your trick.
78
 * Disabling the debugging subsystem will give you a slight (read: unnoticeable)
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
79
 * speed increase and will reduce the size of your compiled code. The GStreamer
80 81
 * library itself becomes around 10% smaller.
 *
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
82
 * Please note that there are naming conventions for the names of debugging
83 84
 * categories. These are explained at GST_DEBUG_CATEGORY_INIT().
 */
85

86
#define GST_INFO_C
87 88 89
#include "gst_private.h"
#include "gstinfo.h"

90 91 92
#undef gst_debug_remove_log_function
#undef gst_debug_add_log_function

93
#ifndef GST_DISABLE_GST_DEBUG
94
#ifdef HAVE_DLFCN_H
95
#  include <dlfcn.h>
96
#endif
97
#include <stdio.h>              /* fprintf */
98 99
#include <glib/gstdio.h>
#include <errno.h>
100
#ifdef HAVE_UNISTD_H
101 102 103 104
#  include <unistd.h>           /* getpid on UNIX */
#endif
#ifdef HAVE_PROCESS_H
#  include <process.h>          /* getpid on win32 */
105
#endif
106
#include <string.h>             /* G_VA_COPY */
107 108 109 110
#ifdef G_OS_WIN32
#  define WIN32_LEAN_AND_MEAN   /* prevents from including too many things */
#  include <windows.h>          /* GetStdHandle, windows console */
#endif
111

112
#include "gst_private.h"
113
#include "gstutils.h"
114
#include "gstquark.h"
115
#include "gstsegment.h"
116
#include "gstvalue.h"
117
#include "gstcapsfeatures.h"
118

119
#ifdef HAVE_VALGRIND_VALGRIND_H
120
#  include <valgrind/valgrind.h>
121
#endif
122
#include <glib/gprintf.h>       /* g_sprintf */
123

124 125
/* our own printf implementation with custom extensions to %p for caps etc. */
#include "printf/printf.h"
126 127 128 129
#include "printf/printf-extension.h"

static char *gst_info_printf_pointer_extension_func (const char *format,
    void *ptr);
130
#else /* GST_DISABLE_GST_DEBUG */
131

132
#include <glib/gprintf.h>
133 134
#endif /* !GST_DISABLE_GST_DEBUG */

135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157
#ifdef HAVE_UNWIND
/* No need for remote debugging so turn on the 'local only' optimizations in
 * libunwind */
#define UNW_LOCAL_ONLY

#include <libunwind.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <stdarg.h>
#include <unistd.h>
#include <errno.h>

#ifdef HAVE_DW
#include <elfutils/libdwfl.h>
#endif /* HAVE_DW */
#endif /* HAVE_UNWIND */

#ifdef HAVE_BACKTRACE
#include <execinfo.h>
#define BT_BUF_SIZE 100
#endif /* HAVE_BACKTRACE */

158 159
extern gboolean gst_is_initialized (void);

160 161 162 163 164 165
/* we want these symbols exported even if debug is disabled, to maintain
 * ABI compatibility. Unless GST_REMOVE_DISABLED is defined. */
#if !defined(GST_DISABLE_GST_DEBUG) || !defined(GST_REMOVE_DISABLED)

/* disabled by default, as soon as some threshold is set > NONE,
 * it becomes enabled. */
166 167
gboolean _gst_debug_enabled = FALSE;
GstDebugLevel _gst_debug_min = GST_LEVEL_NONE;
168 169 170 171

GstDebugCategory *GST_CAT_DEFAULT = NULL;

GstDebugCategory *GST_CAT_GST_INIT = NULL;
Wim Taymans's avatar
Wim Taymans committed
172
GstDebugCategory *GST_CAT_MEMORY = NULL;
173 174 175 176 177 178 179 180 181 182 183
GstDebugCategory *GST_CAT_PARENTAGE = NULL;
GstDebugCategory *GST_CAT_STATES = NULL;
GstDebugCategory *GST_CAT_SCHEDULING = NULL;

GstDebugCategory *GST_CAT_BUFFER = NULL;
GstDebugCategory *GST_CAT_BUFFER_LIST = NULL;
GstDebugCategory *GST_CAT_BUS = NULL;
GstDebugCategory *GST_CAT_CAPS = NULL;
GstDebugCategory *GST_CAT_CLOCK = NULL;
GstDebugCategory *GST_CAT_ELEMENT_PADS = NULL;
GstDebugCategory *GST_CAT_PADS = NULL;
184
GstDebugCategory *GST_CAT_PERFORMANCE = NULL;
185 186 187 188 189 190 191 192 193 194 195 196 197 198 199
GstDebugCategory *GST_CAT_PIPELINE = NULL;
GstDebugCategory *GST_CAT_PLUGIN_LOADING = NULL;
GstDebugCategory *GST_CAT_PLUGIN_INFO = NULL;
GstDebugCategory *GST_CAT_PROPERTIES = NULL;
GstDebugCategory *GST_CAT_NEGOTIATION = NULL;
GstDebugCategory *GST_CAT_REFCOUNTING = NULL;
GstDebugCategory *GST_CAT_ERROR_SYSTEM = NULL;
GstDebugCategory *GST_CAT_EVENT = NULL;
GstDebugCategory *GST_CAT_MESSAGE = NULL;
GstDebugCategory *GST_CAT_PARAMS = NULL;
GstDebugCategory *GST_CAT_CALL_TRACE = NULL;
GstDebugCategory *GST_CAT_SIGNAL = NULL;
GstDebugCategory *GST_CAT_PROBE = NULL;
GstDebugCategory *GST_CAT_REGISTRY = NULL;
GstDebugCategory *GST_CAT_QOS = NULL;
200
GstDebugCategory *_priv_GST_CAT_POLL = NULL;
Wim Taymans's avatar
Wim Taymans committed
201
GstDebugCategory *GST_CAT_META = NULL;
202
GstDebugCategory *GST_CAT_LOCKING = NULL;
203
GstDebugCategory *GST_CAT_CONTEXT = NULL;
204
GstDebugCategory *_priv_GST_CAT_PROTECTION = NULL;
205

206 207 208 209 210

#endif /* !defined(GST_DISABLE_GST_DEBUG) || !defined(GST_REMOVE_DISABLED) */

#ifndef GST_DISABLE_GST_DEBUG

211 212
/* underscore is to prevent conflict with GST_CAT_DEBUG define */
GST_DEBUG_CATEGORY_STATIC (_GST_CAT_DEBUG);
213

214
#if 0
215 216
#if defined __sgi__
#include <rld_interface.h>
217 218 219 220 221 222 223 224 225
typedef struct DL_INFO
{
  const char *dli_fname;
  void *dli_fbase;
  const char *dli_sname;
  void *dli_saddr;
  int dli_version;
  int dli_reserved1;
  long dli_reserved[4];
226 227
}
Dl_info;
228

229
#define _RLD_DLADDR             14
230
int dladdr (void *address, Dl_info * dl);
231

232 233
int
dladdr (void *address, Dl_info * dl)
234 235
{
  void *v;
236 237 238

  v = _rld_new_interface (_RLD_DLADDR, address, dl);
  return (int) v;
239
}
240
#endif /* __sgi__ */
241
#endif
242

243 244
static const gchar *_gst_debug_filter = NULL;

245 246
static void gst_debug_reset_threshold (gpointer category, gpointer unused);
static void gst_debug_reset_all_thresholds (void);
247

248 249 250 251 252
struct _GstDebugMessage
{
  gchar *message;
  const gchar *format;
  va_list arguments;
253 254
};

255
/* list of all name/level pairs from --gst-debug and GST_DEBUG */
256
static GMutex __level_name_mutex;
257
static GSList *__level_name = NULL;
258 259 260 261
typedef struct
{
  GPatternSpec *pat;
  GstDebugLevel level;
262 263
}
LevelNameEntry;
264 265

/* list of all categories */
266
static GMutex __cat_mutex;
267 268
static GSList *__categories = NULL;

269 270 271
static GstDebugCategory *_gst_debug_get_category_locked (const gchar * name);


272
/* all registered debug handlers */
273 274 275 276
typedef struct
{
  GstLogFunction func;
  gpointer user_data;
277
  GDestroyNotify notify;
278 279
}
LogFuncEntry;
280
static GMutex __log_func_mutex;
281 282
static GSList *__log_functions = NULL;

283 284 285
/* whether to add the default log function in gst_init() */
static gboolean add_default_log_func = TRUE;

286 287 288
#define PRETTY_TAGS_DEFAULT  TRUE
static gboolean pretty_tags = PRETTY_TAGS_DEFAULT;

289
static volatile gint G_GNUC_MAY_ALIAS __default_level = GST_LEVEL_DEFAULT;
LRN's avatar
LRN committed
290
static volatile gint G_GNUC_MAY_ALIAS __use_color = GST_DEBUG_COLOR_MODE_ON;
Wim Taymans's avatar
Wim Taymans committed
291

292 293
/* FIXME: export this? */
gboolean
294
_priv_gst_in_valgrind (void)
295 296 297 298 299 300 301 302 303 304
{
  static enum
  {
    GST_VG_UNCHECKED,
    GST_VG_NO_VALGRIND,
    GST_VG_INSIDE
  }
  in_valgrind = GST_VG_UNCHECKED;

  if (in_valgrind == GST_VG_UNCHECKED) {
305
#ifdef HAVE_VALGRIND_VALGRIND_H
306 307 308 309 310 311 312 313 314 315 316 317 318
    if (RUNNING_ON_VALGRIND) {
      GST_CAT_INFO (GST_CAT_GST_INIT, "we're running inside valgrind");
      in_valgrind = GST_VG_INSIDE;
    } else {
      GST_CAT_LOG (GST_CAT_GST_INIT, "not doing extra valgrind stuff");
      in_valgrind = GST_VG_NO_VALGRIND;
    }
#else
    in_valgrind = GST_VG_NO_VALGRIND;
#endif
    g_assert (in_valgrind == GST_VG_NO_VALGRIND ||
        in_valgrind == GST_VG_INSIDE);
  }
319
  return (in_valgrind == GST_VG_INSIDE);
320 321
}

322
static gchar *
323 324
_replace_pattern_in_gst_debug_file_name (gchar * name, const char *token,
    guint val)
325
{
326
  gchar *token_start;
327 328
  if ((token_start = strstr (name, token))) {
    gsize token_len = strlen (token);
329 330
    gchar *name_prefix = name;
    gchar *name_suffix = token_start + token_len;
331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349
    token_start[0] = '\0';
    name = g_strdup_printf ("%s%u%s", name_prefix, val, name_suffix);
    g_free (name_prefix);
  }
  return name;
}

static gchar *
_priv_gst_debug_file_name (const gchar * env)
{
  gchar *name;

  name = g_strdup (env);
  name = _replace_pattern_in_gst_debug_file_name (name, "%p", getpid ());
  name = _replace_pattern_in_gst_debug_file_name (name, "%r", g_random_int ());

  return name;
}

350
/* Initialize the debugging system */
351
void
352
_priv_gst_debug_init (void)
353
{
354
  const gchar *env;
355
  FILE *log_file;
356

357 358 359 360 361 362
  if (add_default_log_func) {
    env = g_getenv ("GST_DEBUG_FILE");
    if (env != NULL && *env != '\0') {
      if (strcmp (env, "-") == 0) {
        log_file = stdout;
      } else {
363 364 365
        gchar *name = _priv_gst_debug_file_name (env);
        log_file = g_fopen (name, "w");
        g_free (name);
366 367 368 369 370
        if (log_file == NULL) {
          g_printerr ("Could not open log file '%s' for writing: %s\n", env,
              g_strerror (errno));
          log_file = stderr;
        }
371
      }
372 373
    } else {
      log_file = stderr;
374
    }
375 376

    gst_debug_add_log_function (gst_debug_log_default, log_file, NULL);
377 378
  }

379 380
  __gst_printf_pointer_extension_set_func
      (gst_info_printf_pointer_extension_func);
381

382
  /* do NOT use a single debug function before this line has been run */
383 384
  GST_CAT_DEFAULT = _gst_debug_category_new ("default",
      GST_DEBUG_UNDERLINE, NULL);
385
  _GST_CAT_DEBUG = _gst_debug_category_new ("GST_DEBUG",
386
      GST_DEBUG_BOLD | GST_DEBUG_FG_YELLOW, "debugging subsystem");
387 388

  /* FIXME: add descriptions here */
389 390
  GST_CAT_GST_INIT = _gst_debug_category_new ("GST_INIT",
      GST_DEBUG_BOLD | GST_DEBUG_FG_RED, NULL);
Wim Taymans's avatar
Wim Taymans committed
391 392
  GST_CAT_MEMORY = _gst_debug_category_new ("GST_MEMORY",
      GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, "memory");
393 394 395 396 397 398 399
  GST_CAT_PARENTAGE = _gst_debug_category_new ("GST_PARENTAGE",
      GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
  GST_CAT_STATES = _gst_debug_category_new ("GST_STATES",
      GST_DEBUG_BOLD | GST_DEBUG_FG_RED, NULL);
  GST_CAT_SCHEDULING = _gst_debug_category_new ("GST_SCHEDULING",
      GST_DEBUG_BOLD | GST_DEBUG_FG_MAGENTA, NULL);
  GST_CAT_BUFFER = _gst_debug_category_new ("GST_BUFFER",
400
      GST_DEBUG_BOLD | GST_DEBUG_BG_GREEN, NULL);
401 402
  GST_CAT_BUFFER_LIST = _gst_debug_category_new ("GST_BUFFER_LIST",
      GST_DEBUG_BOLD | GST_DEBUG_BG_GREEN, NULL);
403
  GST_CAT_BUS = _gst_debug_category_new ("GST_BUS", GST_DEBUG_BG_YELLOW, NULL);
404 405 406 407 408 409 410
  GST_CAT_CAPS = _gst_debug_category_new ("GST_CAPS",
      GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
  GST_CAT_CLOCK = _gst_debug_category_new ("GST_CLOCK",
      GST_DEBUG_BOLD | GST_DEBUG_FG_YELLOW, NULL);
  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",
411 412
      GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_RED, NULL);
  GST_CAT_PERFORMANCE = _gst_debug_category_new ("GST_PERFORMANCE",
413 414 415
      GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
  GST_CAT_PIPELINE = _gst_debug_category_new ("GST_PIPELINE",
      GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
416
  GST_CAT_PLUGIN_LOADING = _gst_debug_category_new ("GST_PLUGIN_LOADING",
417 418 419 420 421 422 423 424
      GST_DEBUG_BOLD | GST_DEBUG_FG_CYAN, NULL);
  GST_CAT_PLUGIN_INFO = _gst_debug_category_new ("GST_PLUGIN_INFO",
      GST_DEBUG_BOLD | GST_DEBUG_FG_CYAN, NULL);
  GST_CAT_PROPERTIES = _gst_debug_category_new ("GST_PROPERTIES",
      GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_BLUE, NULL);
  GST_CAT_NEGOTIATION = _gst_debug_category_new ("GST_NEGOTIATION",
      GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
  GST_CAT_REFCOUNTING = _gst_debug_category_new ("GST_REFCOUNTING",
425
      GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_BLUE, NULL);
426 427 428 429
  GST_CAT_ERROR_SYSTEM = _gst_debug_category_new ("GST_ERROR_SYSTEM",
      GST_DEBUG_BOLD | GST_DEBUG_FG_RED | GST_DEBUG_BG_WHITE, NULL);

  GST_CAT_EVENT = _gst_debug_category_new ("GST_EVENT",
430
      GST_DEBUG_BOLD | GST_DEBUG_FG_BLUE, NULL);
431 432
  GST_CAT_MESSAGE = _gst_debug_category_new ("GST_MESSAGE",
      GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
433 434 435 436
  GST_CAT_PARAMS = _gst_debug_category_new ("GST_PARAMS",
      GST_DEBUG_BOLD | GST_DEBUG_FG_BLACK | GST_DEBUG_BG_YELLOW, NULL);
  GST_CAT_CALL_TRACE = _gst_debug_category_new ("GST_CALL_TRACE",
      GST_DEBUG_BOLD, NULL);
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
437 438 439 440
  GST_CAT_SIGNAL = _gst_debug_category_new ("GST_SIGNAL",
      GST_DEBUG_BOLD | GST_DEBUG_FG_WHITE | GST_DEBUG_BG_RED, NULL);
  GST_CAT_PROBE = _gst_debug_category_new ("GST_PROBE",
      GST_DEBUG_BOLD | GST_DEBUG_FG_GREEN, "pad probes");
David Schleef's avatar
David Schleef committed
441
  GST_CAT_REGISTRY = _gst_debug_category_new ("GST_REGISTRY", 0, "registry");
Wim Taymans's avatar
Wim Taymans committed
442
  GST_CAT_QOS = _gst_debug_category_new ("GST_QOS", 0, "QoS");
443
  _priv_GST_CAT_POLL = _gst_debug_category_new ("GST_POLL", 0, "poll");
Wim Taymans's avatar
Wim Taymans committed
444
  GST_CAT_META = _gst_debug_category_new ("GST_META", 0, "meta");
445
  GST_CAT_LOCKING = _gst_debug_category_new ("GST_LOCKING", 0, "locking");
446
  GST_CAT_CONTEXT = _gst_debug_category_new ("GST_CONTEXT", 0, NULL);
447 448
  _priv_GST_CAT_PROTECTION =
      _gst_debug_category_new ("GST_PROTECTION", 0, "protection");
449 450

  /* print out the valgrind message if we're in valgrind */
451
  _priv_gst_in_valgrind ();
452 453 454 455 456 457 458 459

  env = g_getenv ("GST_DEBUG_OPTIONS");
  if (env != NULL) {
    if (strstr (env, "full_tags") || strstr (env, "full-tags"))
      pretty_tags = FALSE;
    else if (strstr (env, "pretty_tags") || strstr (env, "pretty-tags"))
      pretty_tags = TRUE;
  }
460 461 462 463 464 465 466

  if (g_getenv ("GST_DEBUG_NO_COLOR") != NULL)
    gst_debug_set_color_mode (GST_DEBUG_COLOR_MODE_OFF);
  env = g_getenv ("GST_DEBUG_COLOR_MODE");
  if (env)
    gst_debug_set_color_mode_from_string (env);

467 468 469
  _gst_debug_filter = g_getenv ("GST_DEBUG");
  if (_gst_debug_filter) {
    gst_debug_set_threshold_from_string (_gst_debug_filter, FALSE);
470
  }
471 472
}

473
/* we can't do this further above, because we initialize the GST_CAT_DEFAULT struct */
474
#define GST_CAT_DEFAULT _GST_CAT_DEBUG
475

476 477 478 479 480 481 482
/**
 * gst_debug_log:
 * @category: category to log
 * @level: level of the message is in
 * @file: the file that emitted the message, usually the __FILE__ identifier
 * @function: the function that emitted the message
 * @line: the line from that the message was emitted, usually __LINE__
483
 * @object: (transfer none) (allow-none): the object this message relates to,
484
 *     or %NULL if none
485 486
 * @format: a printf style format string
 * @...: optional arguments for the format
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
487
 *
488
 * Logs the given message using the currently registered debugging handlers.
489
 */
490 491 492 493
void
gst_debug_log (GstDebugCategory * category, GstDebugLevel level,
    const gchar * file, const gchar * function, gint line,
    GObject * object, const gchar * format, ...)
494 495
{
  va_list var_args;
496

497
  va_start (var_args, format);
498 499
  gst_debug_log_valist (category, level, file, function, line, object, format,
      var_args);
500 501
  va_end (var_args);
}
502

503 504 505 506 507 508 509 510 511 512 513 514 515 516 517 518 519 520 521 522 523 524 525
/* based on g_basename(), which we can't use because it was deprecated */
static inline const gchar *
gst_path_basename (const gchar * file_name)
{
  register const gchar *base;

  base = strrchr (file_name, G_DIR_SEPARATOR);

  {
    const gchar *q = strrchr (file_name, '/');
    if (base == NULL || (q != NULL && q > base))
      base = q;
  }

  if (base)
    return base + 1;

  if (g_ascii_isalpha (file_name[0]) && file_name[1] == ':')
    return file_name + 2;

  return file_name;
}

526
/**
Benjamin Otte's avatar
Benjamin Otte committed
527
 * gst_debug_log_valist:
528 529 530 531 532
 * @category: category to log
 * @level: level of the message is in
 * @file: the file that emitted the message, usually the __FILE__ identifier
 * @function: the function that emitted the message
 * @line: the line from that the message was emitted, usually __LINE__
533
 * @object: (transfer none) (allow-none): the object this message relates to,
534
 *     or %NULL if none
535 536
 * @format: a printf style format string
 * @args: optional arguments for the format
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
537
 *
538
 * Logs the given message using the currently registered debugging handlers.
539
 */
540 541 542 543
void
gst_debug_log_valist (GstDebugCategory * category, GstDebugLevel level,
    const gchar * file, const gchar * function, gint line,
    GObject * object, const gchar * format, va_list args)
544
{
545
  GstDebugMessage message;
546 547 548 549
  LogFuncEntry *entry;
  GSList *handler;

  g_return_if_fail (category != NULL);
550 551 552 553

  if (level > gst_debug_category_get_threshold (category))
    return;

554 555 556 557
  g_return_if_fail (file != NULL);
  g_return_if_fail (function != NULL);
  g_return_if_fail (format != NULL);

558 559
  message.message = NULL;
  message.format = format;
560
  G_VA_COPY (message.arguments, args);
561

562 563 564 565
  handler = __log_functions;
  while (handler) {
    entry = handler->data;
    handler = g_slist_next (handler);
566
    entry->func (category, level, file, function, line, object, &message,
567
        entry->user_data);
568 569
  }
  g_free (message.message);
570
  va_end (message.arguments);
571
}
572

573 574 575 576
/**
 * gst_debug_message_get:
 * @message: a debug message
 *
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
577
 * Gets the string representation of a #GstDebugMessage. This function is used
578
 * in debug handlers to extract the message.
579
 *
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
580
 * Returns: the string representation of a #GstDebugMessage.
581 582
 */
const gchar *
583
gst_debug_message_get (GstDebugMessage * message)
584 585
{
  if (message->message == NULL) {
586 587 588 589 590 591 592
    int len;

    len = __gst_vasprintf (&message->message, message->format,
        message->arguments);

    if (len < 0)
      message->message = NULL;
593
  }
594
  return message->message;
595
}
596

597 598 599
#define MAX_BUFFER_DUMP_STRING_LEN  100

/* structure_to_pretty_string:
600
 * @str: a serialized #GstStructure
601
 *
602 603 604
 * If the serialized structure contains large buffers such as images the hex
 * representation of those buffers will be shortened so that the string remains
 * readable.
605
 *
606
 * Returns: the filtered string
607 608
 */
static gchar *
609
prettify_structure_string (gchar * str)
610
{
611
  gchar *pos = str, *end;
612 613 614 615 616 617 618 619 620 621

  while ((pos = strstr (pos, "(buffer)"))) {
    guint count = 0;

    pos += strlen ("(buffer)");
    for (end = pos; *end != '\0' && *end != ';' && *end != ' '; ++end)
      ++count;
    if (count > MAX_BUFFER_DUMP_STRING_LEN) {
      memcpy (pos + MAX_BUFFER_DUMP_STRING_LEN - 6, "..", 2);
      memcpy (pos + MAX_BUFFER_DUMP_STRING_LEN - 4, pos + count - 4, 4);
622
      memmove (pos + MAX_BUFFER_DUMP_STRING_LEN, pos + count,
623 624 625 626 627 628 629 630 631
          strlen (pos + count) + 1);
      pos += MAX_BUFFER_DUMP_STRING_LEN;
    }
  }

  return str;
}

static inline gchar *
632
gst_info_structure_to_string (const GstStructure * s)
633
{
634
  if (G_LIKELY (s)) {
Tim-Philipp Müller's avatar
Tim-Philipp Müller committed
635
    gchar *str = gst_structure_to_string (s);
636 637 638 639 640 641 642 643 644
    if (G_UNLIKELY (pretty_tags && s->name == GST_QUARK (TAGLIST)))
      return prettify_structure_string (str);
    else
      return str;
  }
  return NULL;
}

static inline gchar *
645
gst_info_describe_buffer (GstBuffer * buffer)
646
{
647 648 649 650 651 652 653 654 655 656 657 658 659 660 661
  const gchar *offset_str = "none";
  const gchar *offset_end_str = "none";
  gchar offset_buf[32], offset_end_buf[32];

  if (GST_BUFFER_OFFSET_IS_VALID (buffer)) {
    g_snprintf (offset_buf, sizeof (offset_buf), "%" G_GUINT64_FORMAT,
        GST_BUFFER_OFFSET (buffer));
    offset_str = offset_buf;
  }
  if (GST_BUFFER_OFFSET_END_IS_VALID (buffer)) {
    g_snprintf (offset_end_buf, sizeof (offset_end_buf), "%" G_GUINT64_FORMAT,
        GST_BUFFER_OFFSET_END (buffer));
    offset_end_str = offset_end_buf;
  }

662 663
  return g_strdup_printf ("buffer: %p, pts %" GST_TIME_FORMAT ", dts %"
      GST_TIME_FORMAT ", dur %" GST_TIME_FORMAT ", size %" G_GSIZE_FORMAT
664 665
      ", offset %s, offset_end %s, flags 0x%x", buffer,
      GST_TIME_ARGS (GST_BUFFER_PTS (buffer)),
666 667
      GST_TIME_ARGS (GST_BUFFER_DTS (buffer)),
      GST_TIME_ARGS (GST_BUFFER_DURATION (buffer)),
668 669
      gst_buffer_get_size (buffer), offset_str, offset_end_str,
      GST_BUFFER_FLAGS (buffer));
670 671
}

672 673 674 675 676 677 678 679 680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695 696
static inline gchar *
gst_info_describe_buffer_list (GstBufferList * list)
{
  GstClockTime pts = GST_CLOCK_TIME_NONE;
  GstClockTime dts = GST_CLOCK_TIME_NONE;
  gsize total_size = 0;
  guint n, i;

  n = gst_buffer_list_length (list);
  for (i = 0; i < n; ++i) {
    GstBuffer *buf = gst_buffer_list_get (list, i);

    if (i == 0) {
      pts = GST_BUFFER_PTS (buf);
      dts = GST_BUFFER_DTS (buf);
    }

    total_size += gst_buffer_get_size (buf);
  }

  return g_strdup_printf ("bufferlist: %p, %u buffers, pts %" GST_TIME_FORMAT
      ", dts %" GST_TIME_FORMAT ", size %" G_GSIZE_FORMAT, list, n,
      GST_TIME_ARGS (pts), GST_TIME_ARGS (dts), total_size);
}

697
static inline gchar *
698
gst_info_describe_event (GstEvent * event)
699 700 701 702 703 704 705 706 707 708 709 710 711
{
  gchar *s, *ret;

  s = gst_info_structure_to_string (gst_event_get_structure (event));
  ret = g_strdup_printf ("%s event: %p, time %" GST_TIME_FORMAT
      ", seq-num %d, %s", GST_EVENT_TYPE_NAME (event), event,
      GST_TIME_ARGS (GST_EVENT_TIMESTAMP (event)), GST_EVENT_SEQNUM (event),
      (s ? s : "(NULL)"));
  g_free (s);
  return ret;
}

static inline gchar *
712
gst_info_describe_message (GstMessage * message)
713 714 715 716 717 718 719 720 721 722 723 724 725 726 727
{
  gchar *s, *ret;

  s = gst_info_structure_to_string (gst_message_get_structure (message));
  ret = g_strdup_printf ("%s message: %p, time %" GST_TIME_FORMAT
      ", seq-num %d, element '%s', %s", GST_MESSAGE_TYPE_NAME (message),
      message, GST_TIME_ARGS (GST_MESSAGE_TIMESTAMP (message)),
      GST_MESSAGE_SEQNUM (message),
      ((message->src) ? GST_ELEMENT_NAME (message->src) : "(NULL)"),
      (s ? s : "(NULL)"));
  g_free (s);
  return ret;
}

static inline gchar *
728
gst_info_describe_query (GstQuery * query)
729 730 731 732 733 734 735 736
{
  gchar *s, *ret;

  s = gst_info_structure_to_string (gst_query_get_structure (query));
  ret = g_strdup_printf ("%s query: %p, %s", GST_QUERY_TYPE_NAME (query),
      query, (s ? s : "(NULL)"));
  g_free (s);
  return ret;
737
}
738

739 740 741 742 743 744 745 746 747 748 749 750 751 752 753 754 755 756 757 758 759 760 761 762 763 764 765 766 767 768 769 770 771 772 773 774 775 776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791 792 793 794
static inline gchar *
gst_info_describe_stream (GstStream * stream)
{
  gchar *ret, *caps_str = NULL, *tags_str = NULL;
  GstCaps *caps;
  GstTagList *tags;

  caps = gst_stream_get_caps (stream);
  if (caps) {
    caps_str = gst_caps_to_string (caps);
    gst_caps_unref (caps);
  }

  tags = gst_stream_get_tags (stream);
  if (tags) {
    tags_str = gst_tag_list_to_string (tags);
    gst_tag_list_unref (tags);
  }

  ret =
      g_strdup_printf ("stream %s %p, ID %s, flags 0x%x, caps [%s], tags [%s]",
      gst_stream_type_get_name (gst_stream_get_stream_type (stream)), stream,
      gst_stream_get_stream_id (stream), gst_stream_get_stream_flags (stream),
      caps_str ? caps_str : "", tags_str ? tags_str : "");

  g_free (caps_str);
  g_free (tags_str);

  return ret;
}

static inline gchar *
gst_info_describe_stream_collection (GstStreamCollection * collection)
{
  gchar *ret;
  GString *streams_str;
  guint i;

  streams_str = g_string_new ("<");
  for (i = 0; i < gst_stream_collection_get_size (collection); i++) {
    GstStream *stream = gst_stream_collection_get_stream (collection, i);
    gchar *s;

    s = gst_info_describe_stream (stream);
    g_string_append_printf (streams_str, " %s,", s);
    g_free (s);
  }
  g_string_append (streams_str, " >");

  ret = g_strdup_printf ("collection %p (%d streams) %s", collection,
      gst_stream_collection_get_size (collection), streams_str->str);

  g_string_free (streams_str, TRUE);
  return ret;
}

795 796 797
static gchar *
gst_debug_print_object (gpointer ptr)
{
798
  GObject *object = (GObject *) ptr;
799 800 801 802 803 804 805

#ifdef unused
  /* This is a cute trick to detect unmapped memory, but is unportable,
   * slow, screws around with madvise, and not actually that useful. */
  {
    int ret;

806
    ret = madvise ((void *) ((unsigned long) ptr & (~0xfff)), 4096, 0);
807 808 809 810 811 812 813 814
    if (ret == -1 && errno == ENOMEM) {
      buffer = g_strdup_printf ("%p (unmapped memory)", ptr);
    }
  }
#endif

  /* nicely printed object */
  if (object == NULL) {
Andy Wingo Wingo's avatar
Andy Wingo Wingo committed
815
    return g_strdup ("(NULL)");
816
  }
817
  if (GST_IS_CAPS (ptr)) {
818
    return gst_caps_to_string ((const GstCaps *) ptr);
819
  }
820
  if (GST_IS_STRUCTURE (ptr)) {
821
    return gst_info_structure_to_string ((const GstStructure *) ptr);
822
  }
823
  if (*(GType *) ptr == GST_TYPE_CAPS_FEATURES) {
824 825
    return gst_caps_features_to_string ((const GstCapsFeatures *) ptr);
  }
826
  if (GST_IS_TAG_LIST (ptr)) {
827 828 829 830 831
    gchar *str = gst_tag_list_to_string ((GstTagList *) ptr);
    if (G_UNLIKELY (pretty_tags))
      return prettify_structure_string (str);
    else
      return str;
832 833 834 835
  }
  if (*(GType *) ptr == GST_TYPE_DATE_TIME) {
    return __gst_date_time_serialize ((GstDateTime *) ptr, TRUE);
  }
836
  if (GST_IS_BUFFER (ptr)) {
837
    return gst_info_describe_buffer (GST_BUFFER_CAST (ptr));
838
  }
839 840 841
  if (GST_IS_BUFFER_LIST (ptr)) {
    return gst_info_describe_buffer_list (GST_BUFFER_LIST_CAST (ptr));
  }
842
#ifdef USE_POISONING
843
  if (*(guint32 *) ptr == 0xffffffff) {
844 845 846
    return g_strdup_printf ("<poisoned@%p>", ptr);
  }
#endif
847
  if (GST_IS_MESSAGE (object)) {
848
    return gst_info_describe_message (GST_MESSAGE_CAST (object));
849
  }
850
  if (GST_IS_QUERY (object)) {
851
    return gst_info_describe_query (GST_QUERY_CAST (object));
852
  }
853
  if (GST_IS_EVENT (object)) {
854
    return gst_info_describe_event (GST_EVENT_CAST (object));
855
  }
856 857 858
  if (GST_IS_CONTEXT (object)) {
    GstContext *context = GST_CONTEXT_CAST (object);
    gchar *s, *ret;
859
    const gchar *type;
860 861
    const GstStructure *structure;

862
    type = gst_context_get_context_type (context);
863 864
    structure = gst_context_get_structure (context);

865
    s = gst_info_structure_to_string (structure);
866

867
    ret = g_strdup_printf ("context '%s'='%s'", type, s);
868 869 870
    g_free (s);
    return ret;
  }
871 872 873 874 875 876 877 878
  if (GST_IS_STREAM (object)) {
    return gst_info_describe_stream (GST_STREAM_CAST (object));
  }
  if (GST_IS_STREAM_COLLECTION (object)) {
    return
        gst_info_describe_stream_collection (GST_STREAM_COLLECTION_CAST
        (object));
  }
879 880 881 882 883 884 885 886 887
  if (GST_IS_PAD (object) && GST_OBJECT_NAME (object)) {
    return g_strdup_printf ("<%s:%s>", GST_DEBUG_PAD_NAME (object));
  }
  if (GST_IS_OBJECT (object) && GST_OBJECT_NAME (object)) {
    return g_strdup_printf ("<%s>", GST_OBJECT_NAME (object));
  }
  if (G_IS_OBJECT (object)) {
    return g_strdup_printf ("<%s@%p>", G_OBJECT_TYPE_NAME (object), object);
  }
888 889 890 891

  return g_strdup_printf ("%p", ptr);
}

892 893 894 895 896 897 898 899 900 901 902 903 904 905 906 907
static gchar *
gst_debug_print_segment (gpointer ptr)
{
  GstSegment *segment = (GstSegment *) ptr;

  /* nicely printed segment */
  if (segment == NULL) {
    return g_strdup ("(NULL)");
  }

  switch (segment->format) {
    case GST_FORMAT_UNDEFINED:{
      return g_strdup_printf ("UNDEFINED segment");
    }
    case GST_FORMAT_TIME:{
      return g_strdup_printf ("time segment start=%" GST_TIME_FORMAT
908 909 910 911 912
          ", offset=%" GST_TIME_FORMAT ", stop=%" GST_TIME_FORMAT
          ", rate=%f, applied_rate=%f" ", flags=0x%02x, time=%" GST_TIME_FORMAT
          ", base=%" GST_TIME_FORMAT ", position %" GST_TIME_FORMAT
          ", duration %" GST_TIME_FORMAT, GST_TIME_ARGS (segment->start),
          GST_TIME_ARGS (segment->offset), GST_TIME_ARGS (segment->stop),
913
          segment->rate, segment->applied_rate, (guint) segment->flags,
914
          GST_TIME_ARGS (segment->time), GST_TIME_ARGS (segment->base),
915
          GST_TIME_ARGS (segment->position), GST_TIME_ARGS (segment->duration));
916 917 918 919 920 921 922 923
    }
    default:{
      const gchar *format_name;

      format_name = gst_format_get_name (segment->format);
      if (G_UNLIKELY (format_name == NULL))
        format_name = "(UNKNOWN FORMAT)";
      return g_strdup_printf ("%s segment start=%" G_GINT64_FORMAT
924 925 926 927 928 929 930
          ", offset=%" G_GINT64_FORMAT ", stop=%" G_GINT64_FORMAT
          ", rate=%f, applied_rate=%f" ", flags=0x%02x, time=%" G_GINT64_FORMAT
          ", base=%" G_GINT64_FORMAT ", position %" G_GINT64_FORMAT
          ", duration %" G_GINT64_FORMAT, format_name, segment->start,
          segment->offset, segment->stop, segment->rate, segment->applied_rate,
          (guint) segment->flags, segment->time, segment->base,
          segment->position, segment->duration);
931 932 933
    }
  }
}
934 935 936 937 938 939 940 941 942 943 944 945 946 947

static char *
gst_info_printf_pointer_extension_func (const char *format, void *ptr)
{
  char *s = NULL;

  if (format[0] == 'p' && format[1] == '\a') {
    switch (format[2]) {
      case 'A':                /* GST_PTR_FORMAT     */
        s = gst_debug_print_object (ptr);
        break;
      case 'B':                /* GST_SEGMENT_FORMAT */
        s = gst_debug_print_segment (ptr);
        break;
948 949 950
      case 'a':                /* GST_WRAPPED_PTR_FORMAT */
        s = priv_gst_string_take_and_wrap (gst_debug_print_object (ptr));
        break;
951 952 953 954 955 956 957 958 959 960 961
      default:
        /* must have been compiled against a newer version with an extension
         * we don't known about yet - just ignore and fallback to %p below */
        break;
    }
  }
  if (s == NULL)
    s = g_strdup_printf ("%p", ptr);

  return s;
}
962

963 964 965
/**
 * gst_debug_construct_term_color:
 * @colorinfo: the color info
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
966
 *
967 968 969
 * Constructs a string that can be used for getting the desired color in color
 * terminals.
 * You need to free the string after use.
Thomas Vander Stichele's avatar
Thomas Vander Stichele committed
970
 *
971 972
 * Returns: (transfer full) (type gchar*): a string containing the color
 *     definition
973 974 975 976 977
 */
gchar *
gst_debug_construct_term_color (guint colorinfo)
{
  GString *color;
978

979
  color = g_string_new ("\033[00");
980

981
  if (colorinfo & GST_DEBUG_BOLD) {
982
    g_string_append_len (color, ";01", 3);
983 984
  }
  if (colorinfo & GST_DEBUG_UNDERLINE) {
985
    g_string_append_len (color, ";04", 3);
986 987 988 989 990
  }
  if (colorinfo & GST_DEBUG_FG_MASK) {
    g_string_append_printf (color, ";3%1d", colorinfo & GST_DEBUG_FG_MASK);
  }
  if (colorinfo & GST_DEBUG_BG_MASK) {
991
    g_string_append_printf (color, ";4%1d",
992
        (colorinfo & GST_DEBUG_BG_MASK) >> 4);
993
  }
994
  g_string_append_c (color, 'm');
995

996
  return g_string_free (color, FALSE);
997
}
998

999 1000 1001 1002 1003 1004 1005 1006
/**
 * gst_debug_construct_win_color:
 * @colorinfo: the color info
 *
 * Constructs an integer that can be used for getting the desired color in
 * windows' terminals (cmd.exe). As there is no mean to underline, we simply
 * ignore this attribute.
 *
1007 1008
 * This function returns 0 on non-windows machines.
 *
1009 1010 1011 1012 1013 1014
 * Returns: an integer containing the color definition
 */
gint
gst_debug_construct_win_color (guint colorinfo)
{
  gint color = 0;
1015
#ifdef G_OS_WIN32
1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031 1032 1033 1034 1035 1036 1037
  static const guchar ansi_to_win_fg[8] = {
    0,                          /* black   */
    FOREGROUND_RED,             /* red     */
    FOREGROUND_GREEN,           /* green   */
    FOREGROUND_RED | FOREGROUND_GREEN,  /* yellow  */
    FOREGROUND_BLUE,            /* blue    */
    FOREGROUND_RED | FOREGROUND_BLUE,   /* magenta */
    FOREGROUND_GREEN | FOREGROUND_BLUE, /* cyan    */
    FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE /* white   */
  };
  static const guchar ansi_to_win_bg[8] = {
    0,
    BACKGROUND_RED,
    BACKGROUND_GREEN,
    BACKGROUND_RED | BACKGROUND_GREEN,
    BACKGROUND_BLUE,
    BACKGROUND_RED | BACKGROUND_BLUE,
    BACKGROUND_GREEN | FOREGROUND_BLUE,
    BACKGROUND_RED | BACKGROUND_GREEN | BACKGROUND_BLUE
  };

  /* we draw black as white, as cmd.exe can only have black bg */
1038 1039 1040 1041 1042
  if ((colorinfo & (GST_DEBUG_FG_MASK | GST_DEBUG_BG_MASK)) == 0) {
    color = ansi_to_win_fg[7];
  }
  if (colorinfo & GST_DEBUG_UNDERLINE) {
    color |= BACKGROUND_INTENSITY;
1043 1044 1045 1046 1047 1048 1049 1050 1051 1052
  }
  if (colorinfo & GST_DEBUG_BOLD) {
    color |= FOREGROUND_INTENSITY;
  }
  if (colorinfo & GST_DEBUG_FG_MASK) {
    color |= ansi_to_win_fg[colorinfo & GST_DEBUG_FG_MASK];
  }
  if (colorinfo & GST_DEBUG_BG_MASK) {
    color |= ansi_to_win_bg[(colorinfo & GST_DEBUG_BG_MASK) >> 4];
  }
1053
#endif
1054 1055 1056
  return color;
}

1057 1058 1059 1060 1061 1062 1063 1064 1065 1066 1067 1068 1069
/* width of %p varies depending on actual value of pointer, which can make
 * output unevenly aligned if multiple threads are involved, hence the %14p
 * (should really be %18p, but %14p seems a good compromise between too many
 * white spaces and likely unalignment on my system) */
#if defined (GLIB_SIZEOF_VOID_P) && GLIB_SIZEOF_VOID_P == 8
#define PTR_FMT "%14p"
#else
#define PTR_FMT "%10p"
#endif
#define PID_FMT "%5d"
#define CAT_FMT "%20s %s:%d:%s:%s"

#ifdef G_OS_WIN32
LRN's avatar
LRN committed
1070
static const guchar levelcolormap_w32[GST_LEVEL_COUNT] = {
1071 1072 1073 1074 1075 1076 1077 1078 1079 1080 1081
  /* GST_LEVEL_NONE */
  FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE,
  /* GST_LEVEL_ERROR */
  FOREGROUND_RED | FOREGROUND_INTENSITY,
  /* GST_LEVEL_WARNING */
  FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_INTENSITY,
  /* GST_LEVEL_INFO */
  FOREGROUND_GREEN | FOREGROUND_INTENSITY,
  /* GST_LEVEL_DEBUG */
  FOREGROUND_GREEN | FOREGROUND_BLUE,
  /* GST_LEVEL_LOG */
1082 1083 1084
  FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE,
  /* GST_LEVEL_FIXME */
  FOREGROUND_RED | FOREGROUND_GREEN,
1085 1086
  /* GST_LEVEL_TRACE */
  FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE,
1087 1088 1089
  /* placeholder for log level 8 */
  0,
  /* GST_LEVEL_MEMDUMP */
1090 1091 1092
  FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE
};

1093
static const guchar available_colors[] = {
1094 1095 1096 1097
  FOREGROUND_RED, FOREGROUND_GREEN, FOREGROUND_RED | FOREGROUND_GREEN,
  FOREGROUND_BLUE, FOREGROUND_RED | FOREGROUND_BLUE,
  FOREGROUND_GREEN | FOREGROUND_BLUE,
};
LRN's avatar
LRN committed
1098
#endif /* G_OS_WIN32 */
1099
static const gchar *levelcolormap[GST_LEVEL_COUNT] = {
1100 1101 1102 1103 1104
  "\033[37m",                   /* GST_LEVEL_NONE */
  "\033[31;01m",                /* GST_LEVEL_ERROR */
  "\033[33;01m",                /* GST_LEVEL_WARNING */
  "\033[32;01m",                /* GST_LEVEL_INFO */
  "\033[36m",                   /* GST_LEVEL_DEBUG */
1105 1106
  "\033[37m",                   /* GST_LEVEL_LOG */
  "\033[33;01m",                /* GST_LEVEL_FIXME */
1107
  "\033[37m",                   /* GST_LEVEL_TRACE */
1108 1109
  "\033[37m",                   /* placeholder for log level 8 */
  "\033[37m"                    /* GST_LEVEL_MEMDUMP */
1110 1111 1112 1113 1114 1115 1116 1117 1118 1119
};

/**
 * gst_debug_log_default:
 * @category: category to log
 * @level: level of the message
 * @file: the file that emitted the message, usually the __FILE__ identifier
 * @function: the function that emitted the message
 * @line: the line from that the message was emitted, usually __LINE__
 * @message: the actual message
1120
 * @object: (transfer none) (allow-none): the object this message relates to,
1121
 *     or %NULL if none
1122
 * @user_data: the FILE* to log to
1123 1124
 *
 * The default logging handler used by GStreamer. Logging functions get called
1125 1126 1127 1128
 * whenever a macro like GST_DEBUG or similar is used. By default this function
 * is setup to output the message and additional info to stderr (or the log file
 * specified via the GST_DEBUG_FILE environment variable) as received via
 * @user_data.
1129
 *
1130 1131 1132 1133
 * You can add other handlers by using gst_debug_add_log_function().
 * And you can remove this handler by calling
 * gst_debug_remove_log_function(gst_debug_log_default);
 */
1134 1135 1136
void
gst_debug_log_default (GstDebugCategory * category, GstDebugLevel level,
    const gchar * file, const gchar * function, gint line,
1137
    GObject * object, GstDebugMessage * message, gpointer user_data)
1138
{
1139
  gint pid;
1140
  GstClockTime elapsed;
1141
  gchar *obj = NULL;
LRN's avatar
LRN committed
1142
  GstDebugColorMode color_mode;
1143
  FILE *log_file = user_data ? user_data : stderr;
1144
  gchar c;
1145

1146 1147 1148 1149 1150 1151 1152 1153 1154
  /* __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);
  }

1155
  pid = getpid ();
LRN's avatar
LRN committed
1156
  color_mode = gst_debug_get_color_mode ();
1157

1158 1159 1160
  if (object) {
    obj = gst_debug_print_object (object);
  } else {
1161
    obj = (gchar *) "";
1162 1163
  }

1164
  elapsed = GST_CLOCK_DIFF (_priv_gst_start_time, gst_util_get_timestamp ());
1165

LRN's avatar
LRN committed
1166 1167 1168
  if (color_mode != GST_DEBUG_COLOR_MODE_OFF) {
#ifdef G_OS_WIN32
    /* We take a lock to keep colors and content together.
1169 1170
     * Maybe there is a better way but for now this will do the right
     * thing. */
1171
    static GMutex win_print_mutex;
LRN's avatar
LRN committed
1172 1173 1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187 1188 1189 1190 1191 1192 1193 1194 1195 1196 1197 1198 1199
    g_mutex_lock (&win_print_mutex);
    if (color_mode == GST_DEBUG_COLOR_MODE_UNIX) {
#endif
      /* colors, non-windows */
      gchar *color = NULL;
      const gchar *clear;
      gchar pidcolor[10];
      const gchar *levelcolor;

      color = gst_debug_construct_term_color (gst_debug_category_get_color
          (category));
      clear = "\033[00m";
      g_sprintf (pidcolor, "\033[3%1dm", pid % 6 + 31);
      levelcolor = levelcolormap[level];

#define PRINT_FMT " %s"PID_FMT"%s "PTR_FMT" %s%s%s %s"CAT_FMT"%s %s\n"
      fprintf (log_file, "%" GST_TIME_FORMAT PRINT_FMT, GST_TIME_ARGS (elapsed),
          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));
      fflush (log_file);
#undef PRINT_FMT
      g_free (color);
#ifdef G_OS_WIN32
    } else {
      /* colors, windows. */
      const gint clear = FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE;
1200
#define SET_COLOR(c) G_STMT_START { \
1201
  if (log_file == stderr) \
1202 1203
    SetConsoleTextAttribute (GetStdHandle (STD_ERROR_HANDLE), (c)); \
  } G_STMT_END
LRN's avatar
LRN committed
1204 1205 1206 1207 1208 1209 1210 1211 1212 1213 1214 1215 1216 1217 1218 1219 1220 1221 1222 1223 1224 1225 1226 1227 1228 1229
      /* timestamp */
      fprintf (log_file, "%" GST_TIME_FORMAT " ", GST_TIME_ARGS (elapsed));
      fflush (log_file);
      /* pid */
      SET_COLOR (available_colors[pid % G_N_ELEMENTS (available_colors)]);
      fprintf (log_file, PID_FMT, pid);
      fflush (log_file);
      /* thread */
      SET_COLOR (clear);
      fprintf (log_file, " " PTR_FMT " ", g_thread_self ());
      fflush (log_file);
      /* level */
      SET_COLOR (levelcolormap_w32[level]);
      fprintf (log_file, "%s ", gst_debug_level_get_name (level));
      fflush (log_file);
      /* category */
      SET_COLOR (gst_debug_construct_win_color (gst_debug_category_get_color
              (category)));
      fprintf (log_file, CAT_FMT, gst_debug_category_get_name (category),