markdown/tutorials/basic/debugging-tools.md

   1 # Basic tutorial 11: Debugging tools
   2
   3 ## Goal
   4
   5 Sometimes things won’t go as expected and the error messages retrieved
   6 from the bus (if any) just don’t provide enough information. Luckily,
   7 GStreamer ships with massive amounts of debug information, which usually
   8 hint what the problem might be. This tutorial shows:
   9
  10   - How to get more debug information from GStreamer.
  11
  12   - How to print your own debug information into the GStreamer log.
  13
  14   - How to get pipeline graphs
  15
  16 ## Printing debug information
  17
  18 ### The debug log
  19
  20 GStreamer and its plugins are full of debug traces, this is, places in
  21 the code where a particularly interesting piece of information is
  22 printed to the console, along with time stamping, process, category,
  23 source code file, function and element information.
  24
  25 The debug output is controlled with the `GST_DEBUG` environment
  26 variable. Here’s an example with
  27 `GST_DEBUG=2`:
  28
  29 ```
  30 0:00:00.868050000  1592   09F62420 WARN                 filesrc gstfilesrc.c:1044:gst_file_src_start:<filesrc0> error: No such file "non-existing-file.webm"
  31 ```
  32
  33 As you can see, this is quite a bit of information. In fact, the
  34 GStreamer debug log is so verbose, that when fully enabled it can render
  35 applications unresponsive (due to the console scrolling) or fill up
  36 megabytes of text files (when redirected to a file). For this reason,
  37 the logs are categorized, and you seldom need to enable all categories
  38 at once.
  39
  40 The first category is the Debug Level, which is a number specifying the
  41 amount of desired output:
  42
  43 | # | Name    | Description |
  44 |---|---------|---|
  45 | 0 | none    | No debug information is output. |
  46 | 1 | ERROR   | Logs all fatal errors. These are errors that do not allow the core or elements to perform the requested action. The application can still recover if programmed to handle the conditions that triggered the error. |
  47 | 2 | WARNING | Logs all warnings. Typically these are non-fatal, but user-visible problems are expected to happen. |
  48 | 3 | FIXME   | Logs all "fixme" messages. Those typically that a codepath that is known to be incomplete has been triggered. It may work in most cases, but mauy cause problems in specific instances. |
  49 | 4 | INFO    | Logs all informational messages. These are typically used for events in the system that only happen once, or are important and rare enough to be logged at this level. |
  50 | 5 | DEBUG   | Logs all debug messages. These are general debug messages for events that happen only a limited number of times during an object's lifetime; these include setup, teardown, change of parameters, ... |
  51 | 6 | LOG     | Logs all log messages. These are messages for events that happen repeatedly during an object's lifetime; these include streaming and steady-state conditions. This is used for log messages that happen on every buffer in an element for example. |
  52 | 7 | TRACE   | Logs all trace messages. Those are message that happen very very often. This is for example is each each time the reference count of a GstMiniObject, such as a GstBuffer or GstEvent, is modified. |
  53 | 8 | MEMDUMP | Logs all memory dump messages. This is the heaviest logging and may include dumping the content of blocks of memory. |
  54
  55 To enable debug output, set the `GST_DEBUG` environment variable to the
  56 desired debug level. All levels below that will also be shown (i.e., if
  57 you set `GST_DEBUG=2`, you will get both `ERROR` and
  58 `WARNING` messages).
  59
  60 Furthermore, each plugin or part of the GStreamer defines its own
  61 category, so you can specify a debug level for each individual category.
  62 For example, `GST_DEBUG=2,audiotestsrc:6`, will use Debug Level 6 for
  63 the `audiotestsrc` element, and 2 for all the others.
  64
  65 The `GST_DEBUG` environment variable, then, is a comma-separated list of
  66 *category*:*level* pairs, with an optional *level* at the beginning,
  67 representing the default debug level for all categories.
  68
  69 The `'*'` wildcard is also available. For example
  70 `GST_DEBUG=2,audio*:6` will use Debug Level 5 for all categories
  71 starting with the word `audio`. `GST_DEBUG=*:2` is equivalent to
  72 `GST_DEBUG=2`.
  73
  74 Use `gst-launch-1.0 --gst-debug-help` to obtain the list of all
  75 registered categories. Bear in mind that each plugin registers its own
  76 categories, so, when installing or removing plugins, this list can
  77 change.
  78
  79 Use `GST_DEBUG` when the error information posted on the GStreamer bus
  80 does not help you nail down a problem. It is common practice to redirect
  81 the output log to a file, and then examine it later, searching for
  82 specific messages.
  83
  84 The content of each line in the debug output
  85 is:
  86
  87 ```
  88 0:00:00.868050000  1592   09F62420 WARN                 filesrc gstfilesrc.c:1044:gst_file_src_start:<filesrc0> error: No such file "non-existing-file.webm"
  89 ```
  90
  91
  92 | Example             | Explained |
  93 |---------------------|-----------|
  94 | `0:00:00.868050000` | Time stamp in HH:MM:SS.sssssssss format since the start of the program |
  95 | `1592`              | Process ID from which the message was issued. Useful when your problem involves multiple processes |
  96 | `09F62420`          | Thread ID from which the message was issued. Useful when your problem involves multiple threads |
  97 | `WARN`              | Debug level of the message |
  98 | `filesrc`           | Debug Category of the message |
  99 | `gstfilesrc.c:1044` | Source file and line in the GStreamer source code where this message is printed |
 100 | `gst_file_src_start`| Function from which the message was issued |
 101 | `&lt;filesrc0&gt;`  | Name of the object that issued the message. It can be an element, a Pad, or something else. Useful when you have multiple elements of the same kind and need to distinguish among them. Naming your elements with the name property will make this debug output more readable (otherwise, GStreamer assigns each new element a unique name). |
 102 | `error: No such file &quot;non-existing-file.webm&quot;` | The actual message.|
 103
 104 ### Adding your own debug information
 105
 106 In the parts of your code that interact with GStreamer, it is
 107 interesting to use GStreamer’s debugging facilities. In this way, you
 108 have all debug output in the same file and the temporal relationship
 109 between different messages is preserved.
 110
 111 To do so, use the `GST_ERROR()`, `GST_WARNING()`, `GST_INFO()`,
 112 `GST_LOG()` and `GST_DEBUG()` macros. They accept the same parameters as
 113 `printf`, and they use the `default` category (`default` will be shown
 114 as the Debug category in the output log).
 115
 116 To change the category to something more meaningful, add these two lines
 117 at the top of your code:
 118
 119 ``` c
 120 GST_DEBUG_CATEGORY_STATIC (my_category);
 121 #define GST_CAT_DEFAULT my_category
 122 ```
 123
 124 And then this one after you have initialized GStreamer with
 125 `gst_init()`:
 126
 127 ``` c
 128 GST_DEBUG_CATEGORY_INIT (my_category, "my category", 0, "This is my very own");
 129 ```
 130
 131 This registers a new category (this is, for the duration of your
 132 application: it is not stored in any file), and sets it as the default
 133 category for your code. See the documentation
 134 for `GST_DEBUG_CATEGORY_INIT()`.
 135
 136 ### Getting pipeline graphs
 137
 138 For those cases where your pipeline starts to grow too large and you
 139 lose track of what is connected with what, GStreamer has the capability
 140 to output graph files. These are `.dot` files, readable with free
 141 programs like [GraphViz](http://www.graphviz.org), that describe the
 142 topology of your pipeline, along with the caps negotiated in each link.
 143
 144 This is also very handy when using all-in-one elements like `playbin`
 145  or `uridecodebin`, which instantiate several elements inside them. Use
 146 the `.dot` files to learn what pipeline they have created inside (and
 147 learn a bit of GStreamer along the way).
 148
 149 To obtain `.dot` files, simply set
 150 the `GST_DEBUG_DUMP_DOT_DIR` environment variable to point to the
 151 folder where you want the files to be placed. `gst-launch-1.0` will create
 152 a `.dot` file at each state change, so you can see the evolution of the
 153 caps negotiation. Unset the variable to disable this facility. From
 154 within your application, you can use the
 155 `GST_DEBUG_BIN_TO_DOT_FILE()` and
 156 `GST_DEBUG_BIN_TO_DOT_FILE_WITH_TS()` macros to generate `.dot` files
 157 at your convenience.
 158
 159 Here you have an example of the kind of pipelines that playbin
 160 generates. It is very complex because `playbin` can handle many
 161 different cases: Your manual pipelines normally do not need to be this
 162 long. If your manual pipeline is starting to get very big, consider
 163 using `playbin`.
 164
 165 ![](images/playbin.png)
 166
 167 To download the full-size picture, use the attachments link at the top
 168 of this page (It's the paperclip icon).
 169
 170 ## Conclusion
 171
 172 This tutorial has shown:
 173
 174   - How to get more debug information from GStreamer using the
 175     `GST_DEBUG` environment variable.
 176   - How to print your own debug information into the GStreamer log with
 177     the `GST_ERROR()` macro and relatives.
 178   - How to get pipeline graphs with the
 179     `GST_DEBUG_DUMP_DOT_DIR` environment variable.
 180
 181 It has been a pleasure having you here, and see you soon!