Debugging GStreamer applications using Nushell
Nushell is a new shell (get it?) in development since 2019. Where other shells like bash and zsh treat all data as raw text, nu instead provides a type system for all data flowing through its pipelines, with many commands inspired by functional languages to manipulate that data. The examples on their homepage and in the README.md demonstrate this well, and I recommend taking a quick look if you’re not familiar with the language.
I have been getting familiar with Nu for a few months now, and found it a lot more approachable and user-friendly than traditional shells, and particularly helpful for exploring logs.
Where to find documentation #
I won’t go over all the commands I use in detail, so if anything is ever unclear, have a look at the Command Reference.
The most relevant categories for our use case are probably Strings and Filters.
From inside nushell, you can also use help some_cmd or some_cmd --help, or help commands for a full table of commands that can be manipulated and searched like
any other table in nu. And for debugging a pipeline, describe is a very useful command that describes the type of its input.
Set-up for analyzing GStreamer logs #
First of all, we need some custom commands to parse the raw logs into a nu table. Luckily, nushell provides a parse command for exacly this use case, and we can define this regex to use with it:
let gst_regex: ([
'(?<time>[0-9.:]+) +'
'(?<pid>\w+) +'
'(?<thread>\w+) +'
'(?<level>\w+) +'
'(?<category>[\w-]+) +'
'(?<file>[\w.-]+)?:'
'(?<line>\w+):'
'(?<function>[\w()~-]+)?:'
'(?<object><[^>]*>)? +'
'(?<msg>.*)$'
] | str join)
(I use a simple pipeline here to split the string over multiple lines for better readability, it just concatenates the list elements.)
Lets run a simple pipeline to get some logs to play around with:
GST_DEBUG=*:DEBUG GST_DEBUG_FILE=sample.log gst-launch-1.0 videotestsrc ! videoconvert ! autovideosink
For parsing the file, we need to be careful to remove any ansi escapes, and split the input into lines. On top of that, we will also store the result to a variable for ease of use:
let gst_log = open sample.log | ansi strip | lines | parse --regex $gst_regex
You can also define a custom command for this, which would look something like:
def "from gst logs" []: string -> table {
$in | ansi strip | lines | parse --regex ([
'(?<time>[0-9.:]+) +'
'(?<pid>\w+) +'
'(?<thread>\w+) +'
'(?<level>\w+) +'
'(?<category>[\w-]+) +'
'(?<file>[\w.-]+)?:'
'(?<line>\w+):'
'(?<function>[\w()~-]+)?:'
'(?<object><[^>]*>)? +'
'(?<msg>.*)$'
] | str join)
}
Define it directly on the command line, or place it in your configuration files. Either way, use the command like this:
let gst_log = open sample.log | from gst logs
Some basic commands for working with the parsed data #
If you take a look at a few lines of the table, it should look something like this:
$gst_log | skip 10 | take 10
╭────┬────────────────────┬───────┬────────────┬────────┬─────────────────────┬────────────────┬───────┬──────────────────────────────┬─────────────┬───────────────────────────────────────────────╮
│ # │ time │ pid │ thread │ level │ category │ file │ line │ function │ object │ msg │
├────┼────────────────────┼───────┼────────────┼────────┼─────────────────────┼────────────────┼───────┼──────────────────────────────┼─────────────┼───────────────────────────────────────────────┤
│ 0 │ 0:00:00.003607288 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_ELEMENT_PADS │ gstelement.c │ 315 │ gst_element_base_class_init │ │ type GstBin : factory (nil) │
│ 1 │ 0:00:00.003927025 │ 5161 │ 0x1ceba80 │ INFO │ GST_INIT │ gstcontext.c │ 86 │ _priv_gst_context_initialize │ │ init contexts │
│ 2 │ 0:00:00.004117399 │ 5161 │ 0x1ceba80 │ INFO │ GST_PLUGIN_LOADING │ gstplugin.c │ 328 │ _priv_gst_plugin_initialize │ │ registering 0 static plugins │
│ 3 │ 0:00:00.004164980 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_REGISTRY │ gstregistry.c │ 592 │ gst_registry_add_feature │ <registry0> │ adding feature 0x1d08c70 (bin) │
│ 4 │ 0:00:00.004176720 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_REFCOUNTING │ gstobject.c │ 710 │ gst_object_set_parent │ <bin> │ set parent (ref and sink) │
│ 5 │ 0:00:00.004197201 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_ELEMENT_PADS │ gstelement.c │ 315 │ gst_element_base_class_init │ │ type GstPipeline : factory 0x1d09310 │
│ 6 │ 0:00:00.004243022 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_REGISTRY │ gstregistry.c │ 592 │ gst_registry_add_feature │ <registry0> │ adding feature 0x1d09310 (pipeline) │
│ 7 │ 0:00:00.004254252 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_REFCOUNTING │ gstobject.c │ 710 │ gst_object_set_parent │ <pipeline> │ set parent (ref and sink) │
│ 8 │ 0:00:00.004265272 │ 5161 │ 0x1ceba80 │ INFO │ GST_PLUGIN_LOADING │ gstplugin.c │ 236 │ gst_plugin_register_static │ │ registered static plugin "staticelements" │
│ 9 │ 0:00:00.004276813 │ 5161 │ 0x1ceba80 │ DEBUG │ GST_REGISTRY │ gstregistry.c │ 476 │ gst_registry_add_plugin │ <registry0> │ adding plugin 0x1d084d0 for filename "(NULL)" │
╰────┴────────────────────┴───────┴────────────┴────────┴─────────────────────┴────────────────┴───────┴──────────────────────────────┴─────────────┴───────────────────────────────────────────────╯
skip and take do exactly what it says on the tin - removing the first N rows, and showing only the first N rows, respectively. I use them here to keep the examples short.
To ignore columns, use reject:
$gst_log | skip 10 | take 5 | reject time pid thread
╭───┬───────┬────────────────────┬───────────────┬──────┬──────────────────────────────┬─────────────┬────────────────────────────────╮
│ # │ level │ category │ file │ line │ function │ object │ msg │
├───┼───────┼────────────────────┼───────────────┼──────┼──────────────────────────────┼─────────────┼────────────────────────────────┤
│ 0 │ DEBUG │ GST_ELEMENT_PADS │ gstelement.c │ 315 │ gst_element_base_class_init │ │ type GstBin : factory (nil) │
│ 1 │ INFO │ GST_INIT │ gstcontext.c │ 86 │ _priv_gst_context_initialize │ │ init contexts │
│ 2 │ INFO │ GST_PLUGIN_LOADING │ gstplugin.c │ 328 │ _priv_gst_plugin_initialize │ │ registering 0 static plugins │
│ 3 │ DEBUG │ GST_REGISTRY │ gstregistry.c │ 592 │ gst_registry_add_feature │ <registry0> │ adding feature 0x1d08c70 (bin) │
│ 4 │ DEBUG │ GST_REFCOUNTING │ gstobject.c │ 710 │ gst_object_set_parent │ <bin> │ set parent (ref and sink) │
╰───┴───────┴────────────────────┴───────────────┴──────┴──────────────────────────────┴─────────────┴────────────────────────────────╯
Or its counterpart, select, which is also useful for reordering columns:
$gst_log | skip 10 | take 5 | select msg category level
╭───┬────────────────────────────────┬────────────────────┬───────╮
│ # │ msg │ category │ level │
├───┼────────────────────────────────┼────────────────────┼───────┤
│ 0 │ type GstBin : factory (nil) │ GST_ELEMENT_PADS │ DEBUG │
│ 1 │ init contexts │ GST_INIT │ INFO │
│ 2 │ registering 0 static plugins │ GST_PLUGIN_LOADING │ INFO │
│ 3 │ adding feature 0x1d08c70 (bin) │ GST_REGISTRY │ DEBUG │
│ 4 │ set parent (ref and sink) │ GST_REFCOUNTING │ DEBUG │
╰───┴────────────────────────────────┴────────────────────┴───────╯
Meanwhile, get returns a single column as a list, which can for example be used with uniq to get a list of all objects in the log:
$gst_log | get object | uniq | take 5
╭───┬──────────────╮
│ 0 │ │
│ 1 │ <registry0> │
│ 2 │ <bin> │
│ 3 │ <pipeline> │
│ 4 │ <capsfilter> │
╰───┴──────────────╯
Filtering rows by different criteria works really well with where.
$gst_log | where thread in ['0x7f467c000b90' '0x232fefa0'] and category == GST_STATES | take 5
╭────┬────────────────────┬───────┬─────────────────┬────────┬─────────────┬──────────┬──────┬───────────────────────┬──────────────────┬───────────────────────────────────────────────────────────╮
│ # │ time │ pid │ thread │ level │ category │ file │ line │ function │ object │ msg │
├────┼────────────────────┼───────┼─────────────────┼────────┼─────────────┼──────────┼──────┼───────────────────────┼──────────────────┼───────────────────────────────────────────────────────────┤
│ 0 │ 0:00:01.318390245 │ 5158 │ 0x7f467c000b90 │ DEBUG │ GST_STATES │ gstbin.c │ 1957 │ bin_element_is_sink │ <autovideosink0> │ child autovideosink0-actual-sink-xvimage is sink │
│ 1 │ 0:00:01.318523898 │ 5158 │ 0x7f467c000b90 │ DEBUG │ GST_STATES │ gstbin.c │ 1957 │ bin_element_is_sink │ <pipeline0> │ child autovideosink0 is sink │
│ 2 │ 0:00:01.318558109 │ 5158 │ 0x7f467c000b90 │ DEBUG │ GST_STATES │ gstbin.c │ 1957 │ bin_element_is_sink │ <pipeline0> │ child videoconvert0 is not sink │
│ 3 │ 0:00:01.318569169 │ 5158 │ 0x7f467c000b90 │ DEBUG │ GST_STATES │ gstbin.c │ 1957 │ bin_element_is_sink │ <pipeline0> │ child videotestsrc0 is not sink │
│ 4 │ 0:00:01.338298058 │ 5158 │ 0x7f467c000b90 │ INFO │ GST_STATES │ gstbin.c │ 3408 │ bin_handle_async_done │ <autovideosink0> │ committing state from READY to PAUSED, old pending PAUSED │
╰────┴────────────────────┴───────┴─────────────────┴────────┴─────────────┴──────────┴──────┴───────────────────────┴──────────────────┴───────────────────────────────────────────────────────────╯
It provides special shorthands called row conditions - have a look at the reference for more examples.
Of course, get and where can also be combined:
$gst_log | get category | uniq | where $it starts-with GST | take 5
╭───┬────────────────────╮
│ 0 │ GST_REGISTRY │
│ 1 │ GST_INIT │
│ 2 │ GST_MEMORY │
│ 3 │ GST_ELEMENT_PADS │
│ 4 │ GST_PLUGIN_LOADING │
╰───┴────────────────────╯
And if you need to merge multiple logs, I recommend using sort-by time. This could look like
let gst_log = (open sample.log) + (open other.log) | from gst logs | sort-by time
Interactively exploring logs #
While there are many other useful commands, there is one more command I find incredbly useful: explore.
It is essentially the nushell equivalent to less, and while it is still quite rough around the edges,
I’ve been using it all the time, mostly for its interactive REPL.
First, just pipe the parsed log into explore:
$gst_log | explore
Now, using the :try command opens its REPL. Enter any pipeline at the top, and you will be able to explore its output below:
Switch between the command line and the pager using Tab, and while focused on the pager, search forwards or backwards using / and ?, or enter :help for explanations.
Also have a look at the documentation on explore in the Nushell Book.