Notes:
-
That there’s already an (almost) identical question, but I wanted to give more context (and marked that one as a duplicate)
-
I’ll be comparing log levels (probably using terms like: lower, higher, smaller, greater, decrease, increase, <, >, …). That applies to their verbosity (amount of produced output):
ERROR < WARNING < ... < INFO < ... < TRACE < ..., and NOT to their criticality (impact)
Working on a task to make logging on a complex GStreamer application consistent / uniform. One part is having GStreamer elements logs (generated by GST_* macros (expanding to GST_CAT_LEVEL_LOG, which in turn expands to a gst_debug_log call)) in Python.
That should be possible using [FreeDesktop.GStreamer]: GstInfo – Gst.debug_add_log_function (noticed the G_GNUC_NO_INSTRUMENT remark, but don’t think there’s anything that can be done at Python level).
Things generally work fine, although I fear that if left to run for long times (and higher log levels) some problems (memory consumption increase, even SegFaults, …) may arise (but I’m not there yet).
But some elements run into serious problems.
Environment
Nvidia‘s DeepStream 6.2 container (Ubuntu 20.04.5 LTS – debugged mostly on Triton flavor, but reproducible on the others):
Narrowed the problem down to a MVCE: to have a pipeline that is short (both textually and also structurally (e.g.: not using bins – which have a short name but can be complex, containing a bunch of other elements)).
code00.py:
#!/usr/bin/env python
import sys
import time
import gi
gi.require_version("Gst", "1.0")
from gi.repository import GLib, Gst
def log_function(
category: Gst.DebugCategory,
level: Gst.DebugLevel,
file: str,
function: str,
line: int,
obj: Gst.Object,
msg: Gst.DebugMessage,
# user_data: Any = None,
):
txt = (
f"{Gst.debug_level_get_name(level)} {category.name} - {file}:{line}:{function}:",
f"<{getattr(obj, 'name', None)} ({getattr(obj.__class__, '__name__')})>" if obj else "<None> ",
f"{msg.get()}"
)
print("".join(txt))
def main(*argv):
custom_log = bool(argv) # Custom log if any argument passed
pipeline_string = "videotestsrc pattern=18 ! nvvideoconvert ! nvv4l2h264enc ! fakesink sync=0"
#pipeline_string = "filesrc location=\"/opt/nvidia/deepstream/deepstream/samples/streams/sample_1080p_h264.mp4\" ! qtdemux ! h264parse ! nvv4l2decoder ! nvvideoconvert ! xvimagesink sync=0"
print(f"---\nCustom log function: {custom_log}\nRunning pipeline:\n gst-launch-1.0 -e {pipeline_string}\n---\n")
Gst.init(None)
if custom_log:
Gst.debug_remove_log_function()
Gst.debug_add_log_function(log_function)
pipeline = Gst.parse_launch(pipeline_string)
loop = GLib.MainLoop()
bus = pipeline.get_bus()
#bus.add_signal_watch()
pipeline.set_state(Gst.State.PLAYING)
start_time = time.time()
try:
loop.run()
except KeyboardInterrupt:
print("<Ctrl+C> pressed.")
except:
print(f"Funky exception caught: {sys.exc_info()[:2]}")
finally:
pipeline.set_state(Gst.State.NULL)
loop.quit()
print(f"--- Ran for {time.time() - start_time:.3f} seconds")
if __name__ == "__main__":
print("Python {:s} {:03d}bit on {:s}\n".format(" ".join(elem.strip() for elem in sys.version.split("\n")),
64 if sys.maxsize > 0x100000000 else 32, sys.platform))
rc = main(*sys.argv[1:])
print("\nDone.\n")
sys.exit(rc)
Some may argue that code is not complete (no callback to monitor messages on the bus), but I wanted to keep it simple (and I don’t care if when playing a video, at the end pipeline doesn’t quit – I interrupt it by pressing Ctrl + C anyway). Just to be explicit, I did try with a complete version, but same results.
Output:
[root@cfati-5510-0:~/Work/Dev/StackExchange/StackOverflow/q077932526]> ls code00.py [root@cfati-5510-0:~/Work/Dev/StackExchange/StackOverflow/q077932526]> # Custom log [root@cfati-5510-0:~/Work/Dev/StackExchange/StackOverflow/q077932526]> GST_DEBUG=2 python code00.py 1 Python 3.8.10 (default, Jun 22 2022, 20:18:18) [GCC 9.4.0] 064bit on linux --- Custom log function: True Running pipeline: gst-launch-1.0 -e videotestsrc pattern=18 ! nvvideoconvert ! nvv4l2h264enc ! fakesink sync=0 --- WARN v4l2 - gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<sink (Pad)>Unable to try format: Unknown error -1 WARN v4l2 - gstv4l2object.c:2942:gst_v4l2_object_probe_caps_for_format:<sink (Pad)>Could not probe minimum capture size for pixelformat YM12 WARN v4l2 - gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<sink (Pad)>Unable to try format: Unknown error -1 WARN v4l2 - gstv4l2object.c:2948:gst_v4l2_object_probe_caps_for_format:<sink (Pad)>Could not probe maximum capture size for pixelformat YM12 code00.py:44: Warning: g_object_is_floating: assertion 'G_IS_OBJECT (object)' failed pipeline.set_state(Gst.State.PLAYING) code00.py:44: Warning: g_object_get_qdata: assertion 'G_IS_OBJECT (object)' failed pipeline.set_state(Gst.State.PLAYING) Segmentation fault (core dumped) [root@cfati-5510-0:~/Work/Dev/StackExchange/StackOverflow/q077932526]> [root@cfati-5510-0:~/Work/Dev/StackExchange/StackOverflow/q077932526]> # Default log [root@cfati-5510-0:~/Work/Dev/StackExchange/StackOverflow/q077932526]> GST_DEBUG=2 python code00.py Python 3.8.10 (default, Jun 22 2022, 20:18:18) [GCC 9.4.0] 064bit on linux --- Custom log function: False Running pipeline: gst-launch-1.0 -e videotestsrc pattern=18 ! nvvideoconvert ! nvv4l2h264enc ! fakesink sync=0 --- 0:00:00.038000133 2604541 0x1385550 WARN v4l2 gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<nvv4l2h264enc0:sink> Unable to try format: Unknown error -1 0:00:00.038029358 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2942:gst_v4l2_object_probe_caps_for_format:<nvv4l2h264enc0:sink> Could not probe minimum capture size for pixelformat YM12 0:00:00.038046357 2604541 0x1385550 WARN v4l2 gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<nvv4l2h264enc0:sink> Unable to try format: Unknown error -1 0:00:00.038061061 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2948:gst_v4l2_object_probe_caps_for_format:<nvv4l2h264enc0:sink> Could not probe maximum capture size for pixelformat YM12 0:00:00.038080317 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2395:gst_v4l2_object_add_interlace_mode:0x13873f0 Failed to determine interlace mode 0:00:00.038109676 2604541 0x1385550 WARN v4l2 gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<nvv4l2h264enc0:sink> Unable to try format: Unknown error -1 0:00:00.038123283 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2942:gst_v4l2_object_probe_caps_for_format:<nvv4l2h264enc0:sink> Could not probe minimum capture size for pixelformat NM12 0:00:00.038134452 2604541 0x1385550 WARN v4l2 gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<nvv4l2h264enc0:sink> Unable to try format: Unknown error -1 0:00:00.038148304 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2948:gst_v4l2_object_probe_caps_for_format:<nvv4l2h264enc0:sink> Could not probe maximum capture size for pixelformat NM12 0:00:00.038161000 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2395:gst_v4l2_object_add_interlace_mode:0x13873f0 Failed to determine interlace mode 0:00:00.038243374 2604541 0x1385550 WARN v4l2 gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<nvv4l2h264enc0:src> Unable to try format: Unknown error -1 0:00:00.038262117 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2942:gst_v4l2_object_probe_caps_for_format:<nvv4l2h264enc0:src> Could not probe minimum capture size for pixelformat H264 0:00:00.038276388 2604541 0x1385550 WARN v4l2 gstv4l2object.c:3057:gst_v4l2_object_get_nearest_size:<nvv4l2h264enc0:src> Unable to try format: Unknown error -1 0:00:00.038289047 2604541 0x1385550 WARN v4l2 gstv4l2object.c:2948:gst_v4l2_object_probe_caps_for_format:<nvv4l2h264enc0:src> Could not probe maximum capture size for pixelformat H264 0:00:00.098620457 2604541 0x107bde0 WARN v4l2bufferpool gstv4l2bufferpool.c:1082:gst_v4l2_buffer_pool_start:<nvv4l2h264enc0:pool:src> Uncertain or not enough buffers, enabling copy threshold 0:00:00.103610735 2604541 0x1399060 WARN v4l2bufferpool gstv4l2bufferpool.c:1533:gst_v4l2_buffer_pool_dqbuf:<nvv4l2h264enc0:pool:src> Driver should never set v4l2_buffer.field to ANY ^C<Ctrl+C> pressed. --- Ran for 4.508 seconds Done.
Notes:
-
Error is reproducible for any of the 3 coders in the NVV4L2 plugin
-
Looking at the above differences, the 1st line that appears in the good run after the last one seen in the crashed one is:
v4l2 gstv4l2object.c:2395:gst_v4l2_object_add_interlace_mode:0x13873f0 Failed to determine interlace mode(this happens every time) -
Works fine when decreasing the log level (ERROR, 1), but then it’s pretty much (log wise) unusable
Based on the observations above, one can conclude that the error has something to do with that particular line. Worth mentioning that I browsed several Gst-Plugins-Good versions (gst-plugins-good/sys/v4l2/gstv4l2object.c) but none of them has the exact line numbers (those particular lines of code don’t seem to change though).
Also noted that error occurs even for:
References:
