2016-05-27 02:21:04 +00:00
|
|
|
|
# Basic tutorial 11: Debugging tools
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
## Goal
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
Sometimes things won’t go as expected and the error messages retrieved
|
|
|
|
|
from the bus (if any) just don’t provide enough information. Luckily,
|
|
|
|
|
GStreamer ships with massive amounts of debug information, which usually
|
|
|
|
|
hint what the problem might be. This tutorial shows:
|
|
|
|
|
|
|
|
|
|
- How to get more debug information from GStreamer.
|
|
|
|
|
|
|
|
|
|
- How to print your own debug information into the GStreamer log.
|
|
|
|
|
|
|
|
|
|
- How to get pipeline graphs
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
## Printing debug information
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
### The debug log
|
|
|
|
|
|
|
|
|
|
GStreamer and its plugins are full of debug traces, this is, places in
|
|
|
|
|
the code where a particularly interesting piece of information is
|
|
|
|
|
printed to the console, along with time stamping, process, category,
|
|
|
|
|
source code file, function and element information.
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
The debug output is controlled with the `GST_DEBUG` environment
|
2017-07-28 21:38:10 +00:00
|
|
|
|
variable. Here’s an example with `GST_DEBUG=2`:
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
2016-05-27 02:48:36 +00:00
|
|
|
|
```
|
2016-05-16 14:30:34 +00:00
|
|
|
|
0:00:00.868050000 1592 09F62420 WARN filesrc gstfilesrc.c:1044:gst_file_src_start:<filesrc0> error: No such file "non-existing-file.webm"
|
|
|
|
|
```
|
|
|
|
|
|
|
|
|
|
As you can see, this is quite a bit of information. In fact, the
|
|
|
|
|
GStreamer debug log is so verbose, that when fully enabled it can render
|
|
|
|
|
applications unresponsive (due to the console scrolling) or fill up
|
|
|
|
|
megabytes of text files (when redirected to a file). For this reason,
|
|
|
|
|
the logs are categorized, and you seldom need to enable all categories
|
|
|
|
|
at once.
|
|
|
|
|
|
|
|
|
|
The first category is the Debug Level, which is a number specifying the
|
|
|
|
|
amount of desired output:
|
|
|
|
|
|
2017-07-28 21:38:10 +00:00
|
|
|
|
```
|
|
|
|
|
| # | Name | Description |
|
|
|
|
|
|---|---------|----------------------------------------------------------------|
|
|
|
|
|
| 0 | none | No debug information is output. |
|
|
|
|
|
| 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. |
|
|
|
|
|
| 2 | WARNING | Logs all warnings. Typically these are non-fatal, but |
|
|
|
|
|
| | | user-visible problems are expected to happen. |
|
|
|
|
|
| 3 | FIXME | Logs all "fixme" messages. Those typically that a codepath that|
|
|
|
|
|
| | | is known to be incomplete has been triggered. It may work in |
|
2018-09-13 04:24:24 +00:00
|
|
|
|
| | | most cases, but may cause problems in specific instances. |
|
2017-07-28 21:38:10 +00:00
|
|
|
|
| 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. |
|
|
|
|
|
| 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, etc. |
|
|
|
|
|
| 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.|
|
|
|
|
|
| 7 | TRACE | Logs all trace messages. Those are message that happen very |
|
2018-09-13 04:24:24 +00:00
|
|
|
|
| | | very often. This is for example is each time the reference |
|
2017-07-28 21:38:10 +00:00
|
|
|
|
| | | count of a GstMiniObject, such as a GstBuffer or GstEvent, is |
|
|
|
|
|
| | | modified. |
|
|
|
|
|
| 8 | MEMDUMP | Logs all memory dump messages. This is the heaviest logging and|
|
|
|
|
|
| | | may include dumping the content of blocks of memory. |
|
|
|
|
|
+------------------------------------------------------------------------------+
|
|
|
|
|
```
|
2016-06-16 00:00:24 +00:00
|
|
|
|
|
|
|
|
|
To enable debug output, set the `GST_DEBUG` environment variable to the
|
2016-05-16 14:30:34 +00:00
|
|
|
|
desired debug level. All levels below that will also be shown (i.e., if
|
2016-06-16 00:00:24 +00:00
|
|
|
|
you set `GST_DEBUG=2`, you will get both `ERROR` and
|
|
|
|
|
`WARNING` messages).
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
Furthermore, each plugin or part of the GStreamer defines its own
|
|
|
|
|
category, so you can specify a debug level for each individual category.
|
2016-06-16 00:00:24 +00:00
|
|
|
|
For example, `GST_DEBUG=2,audiotestsrc:6`, will use Debug Level 6 for
|
|
|
|
|
the `audiotestsrc` element, and 2 for all the others.
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
The `GST_DEBUG` environment variable, then, is a comma-separated list of
|
2016-05-16 14:30:34 +00:00
|
|
|
|
*category*:*level* pairs, with an optional *level* at the beginning,
|
|
|
|
|
representing the default debug level for all categories.
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
The `'*'` wildcard is also available. For example
|
|
|
|
|
`GST_DEBUG=2,audio*:6` will use Debug Level 5 for all categories
|
|
|
|
|
starting with the word `audio`. `GST_DEBUG=*:2` is equivalent to
|
2016-05-16 14:30:34 +00:00
|
|
|
|
`GST_DEBUG=2`.
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
Use `gst-launch-1.0 --gst-debug-help` to obtain the list of all
|
2016-05-16 14:30:34 +00:00
|
|
|
|
registered categories. Bear in mind that each plugin registers its own
|
|
|
|
|
categories, so, when installing or removing plugins, this list can
|
|
|
|
|
change.
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
Use `GST_DEBUG` when the error information posted on the GStreamer bus
|
2016-05-16 14:30:34 +00:00
|
|
|
|
does not help you nail down a problem. It is common practice to redirect
|
|
|
|
|
the output log to a file, and then examine it later, searching for
|
|
|
|
|
specific messages.
|
|
|
|
|
|
2017-07-28 21:38:10 +00:00
|
|
|
|
GStreamer allows for custom debugging information handlers but when
|
|
|
|
|
using the default one, the content of each line in the debug output
|
|
|
|
|
looks like:
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
2016-05-27 02:48:36 +00:00
|
|
|
|
```
|
2016-05-16 14:30:34 +00:00
|
|
|
|
0:00:00.868050000 1592 09F62420 WARN filesrc gstfilesrc.c:1044:gst_file_src_start:<filesrc0> error: No such file "non-existing-file.webm"
|
|
|
|
|
```
|
|
|
|
|
|
2017-07-28 21:38:10 +00:00
|
|
|
|
And this is how the information formatted:
|
2016-06-16 00:00:24 +00:00
|
|
|
|
|
2017-07-28 21:38:10 +00:00
|
|
|
|
```
|
|
|
|
|
| Example | Explained |
|
|
|
|
|
|------------------|-----------------------------------------------------------|
|
|
|
|
|
|0:00:00.868050000 | Time stamp in HH:MM:SS.sssssssss format since the start of|
|
|
|
|
|
| | the program. |
|
|
|
|
|
|1592 | Process ID from which the message was issued. Useful when |
|
|
|
|
|
| | your problem involves multiple processes. |
|
|
|
|
|
|09F62420 | Thread ID from which the message was issued. Useful when |
|
|
|
|
|
| | your problem involves multiple threads. |
|
|
|
|
|
|WARN | Debug level of the message. |
|
|
|
|
|
|filesrc | Debug Category of the message. |
|
|
|
|
|
|gstfilesrc.c:1044 | Source file and line in the GStreamer source code where |
|
|
|
|
|
| | this message was issued. |
|
|
|
|
|
|gst_file_src_start| Function that issued the message. |
|
|
|
|
|
|<filesrc0> | 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 |
|
|
|
|
|
| | makes this debug output more readable but GStreamer |
|
|
|
|
|
| | assigns each new element a unique name by default. |
|
|
|
|
|
| error: No such | |
|
|
|
|
|
| file .... | The actual message. |
|
|
|
|
|
+------------------------------------------------------------------------------+
|
|
|
|
|
```
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
### Adding your own debug information
|
|
|
|
|
|
|
|
|
|
In the parts of your code that interact with GStreamer, it is
|
|
|
|
|
interesting to use GStreamer’s debugging facilities. In this way, you
|
|
|
|
|
have all debug output in the same file and the temporal relationship
|
|
|
|
|
between different messages is preserved.
|
|
|
|
|
|
|
|
|
|
To do so, use the `GST_ERROR()`, `GST_WARNING()`, `GST_INFO()`,
|
2016-06-16 00:00:24 +00:00
|
|
|
|
`GST_LOG()` and `GST_DEBUG()` macros. They accept the same parameters as
|
|
|
|
|
`printf`, and they use the `default` category (`default` will be shown
|
2016-05-16 14:30:34 +00:00
|
|
|
|
as the Debug category in the output log).
|
|
|
|
|
|
|
|
|
|
To change the category to something more meaningful, add these two lines
|
|
|
|
|
at the top of your code:
|
|
|
|
|
|
2016-06-06 00:58:09 +00:00
|
|
|
|
``` c
|
2016-05-16 14:30:34 +00:00
|
|
|
|
GST_DEBUG_CATEGORY_STATIC (my_category);
|
|
|
|
|
#define GST_CAT_DEFAULT my_category
|
|
|
|
|
```
|
|
|
|
|
|
|
|
|
|
And then this one after you have initialized GStreamer with
|
|
|
|
|
`gst_init()`:
|
|
|
|
|
|
2016-06-06 00:58:09 +00:00
|
|
|
|
``` c
|
2016-05-16 14:30:34 +00:00
|
|
|
|
GST_DEBUG_CATEGORY_INIT (my_category, "my category", 0, "This is my very own");
|
|
|
|
|
```
|
|
|
|
|
|
|
|
|
|
This registers a new category (this is, for the duration of your
|
|
|
|
|
application: it is not stored in any file), and sets it as the default
|
2016-06-16 00:00:24 +00:00
|
|
|
|
category for your code. See the documentation
|
|
|
|
|
for `GST_DEBUG_CATEGORY_INIT()`.
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
### Getting pipeline graphs
|
|
|
|
|
|
|
|
|
|
For those cases where your pipeline starts to grow too large and you
|
|
|
|
|
lose track of what is connected with what, GStreamer has the capability
|
2016-06-16 00:00:24 +00:00
|
|
|
|
to output graph files. These are `.dot` files, readable with free
|
2016-05-16 14:30:34 +00:00
|
|
|
|
programs like [GraphViz](http://www.graphviz.org), that describe the
|
|
|
|
|
topology of your pipeline, along with the caps negotiated in each link.
|
|
|
|
|
|
2016-05-27 18:19:02 +00:00
|
|
|
|
This is also very handy when using all-in-one elements like `playbin`
|
2016-06-16 00:00:24 +00:00
|
|
|
|
or `uridecodebin`, which instantiate several elements inside them. Use
|
|
|
|
|
the `.dot` files to learn what pipeline they have created inside (and
|
2016-05-16 14:30:34 +00:00
|
|
|
|
learn a bit of GStreamer along the way).
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
To obtain `.dot` files, simply set
|
|
|
|
|
the `GST_DEBUG_DUMP_DOT_DIR` environment variable to point to the
|
2016-05-27 16:10:42 +00:00
|
|
|
|
folder where you want the files to be placed. `gst-launch-1.0` will create
|
2016-06-16 00:00:24 +00:00
|
|
|
|
a `.dot` file at each state change, so you can see the evolution of the
|
2016-05-16 14:30:34 +00:00
|
|
|
|
caps negotiation. Unset the variable to disable this facility. From
|
|
|
|
|
within your application, you can use the
|
2016-06-16 00:00:24 +00:00
|
|
|
|
`GST_DEBUG_BIN_TO_DOT_FILE()` and
|
|
|
|
|
`GST_DEBUG_BIN_TO_DOT_FILE_WITH_TS()` macros to generate `.dot` files
|
2016-05-16 14:30:34 +00:00
|
|
|
|
at your convenience.
|
|
|
|
|
|
2016-05-27 18:19:02 +00:00
|
|
|
|
Here you have an example of the kind of pipelines that playbin
|
2016-06-16 00:00:24 +00:00
|
|
|
|
generates. It is very complex because `playbin` can handle many
|
2016-05-16 14:30:34 +00:00
|
|
|
|
different cases: Your manual pipelines normally do not need to be this
|
|
|
|
|
long. If your manual pipeline is starting to get very big, consider
|
2016-05-27 18:19:02 +00:00
|
|
|
|
using `playbin`.
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
2016-06-17 19:47:44 +00:00
|
|
|
|
![](images/playbin.png)
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
To download the full-size picture, use the attachments link at the top
|
|
|
|
|
of this page (It's the paperclip icon).
|
|
|
|
|
|
2016-06-16 00:00:24 +00:00
|
|
|
|
## Conclusion
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
|
|
|
|
This tutorial has shown:
|
|
|
|
|
|
|
|
|
|
- How to get more debug information from GStreamer using the
|
2016-06-16 00:00:24 +00:00
|
|
|
|
`GST_DEBUG` environment variable.
|
2016-05-16 14:30:34 +00:00
|
|
|
|
- How to print your own debug information into the GStreamer log with
|
2016-06-16 00:00:24 +00:00
|
|
|
|
the `GST_ERROR()` macro and relatives.
|
2016-05-16 14:30:34 +00:00
|
|
|
|
- How to get pipeline graphs with the
|
2016-06-16 00:00:24 +00:00
|
|
|
|
`GST_DEBUG_DUMP_DOT_DIR` environment variable.
|
2016-05-16 14:30:34 +00:00
|
|
|
|
|
2016-06-16 01:01:51 +00:00
|
|
|
|
It has been a pleasure having you here, and see you soon!
|