Skip to content

Add more information in traces from GstTracer #12

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 4 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -31,3 +31,6 @@ tracing-tracy = "0.10"

[package.metadata.docs.rs]
rustdoc-args = ["--cfg", "tracing_gstreamer_docs"]

[features]
v1_22 = ["gstreamer/v1_22"]
16 changes: 16 additions & 0 deletions src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -91,6 +91,22 @@ fn state_desc(state: gstreamer::ffi::GstState) -> &'static str {
}
}

fn query_name(query: &gstreamer::QueryRef) -> &'static str {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why not use the proper bindings API for this but instead go via FFI?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do not expose that API yet? The only reference I found was in our fmt::Debug implementation which is clearly not what I want here. Should we add it?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems useful to have, yes

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it is fine to keep this open and rebase later on. I don't consider open PRs to be a maintenance burden on repos with as low traffic as this.

use gstreamer::ffi as gffi;
unsafe {
let type_ = gffi::gst_query_type_get_name((*query.as_ptr()).type_);
std::ffi::CStr::from_ptr(type_).to_str().unwrap()
}
}

fn message_name(message: &gstreamer::Message) -> &'static str {
use gstreamer::ffi as gffi;
unsafe {
let type_ = gffi::gst_message_type_get_name((*message.as_ptr()).type_);
std::ffi::CStr::from_ptr(type_).to_str().unwrap()
}
}

/// Enable the integration between GStreamer logging system and the `tracing` library.
///
/// Once enabled the default [`tracing::Subscriber`][tracing_core::subscriber::Subscriber] will
Expand Down
253 changes: 214 additions & 39 deletions src/tracer.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ use glib::subclass::basic;
use gstreamer::{
glib,
prelude::PadExtManual,
prelude::*,
subclass::prelude::*,
traits::{GstObjectExt, PadExt},
Buffer, FlowError, FlowSuccess, Object, Pad, Tracer,
Expand All @@ -19,6 +20,153 @@ pub struct TracingTracerPriv {
span_stack: thread_local::ThreadLocal<RefCell<Vec<EnteredSpan>>>,
}

struct SpanBuilder<'a> {
name: &'static str,
pad: Option<&'a Pad>,
element: Option<&'a gstreamer::Element>,
event: Option<&'a gstreamer::Event>,
query: Option<&'a gstreamer::QueryRef>,
message: Option<&'a gstreamer::Message>,
}

impl<'a> SpanBuilder<'a> {
fn new_element(name: &'static str, element: &'a gstreamer::Element) -> Self {
Self {
name,
pad: None,
event: None,
query: None,
element: Some(element),
message: None,
}
}

fn new_pad(name: &'static str, pad: &'a Pad) -> Self {
Self {
name,
pad: Some(pad),
event: None,
query: None,
element: None,
message: None,
}
}

fn event(self, event: &'a gstreamer::Event) -> Self {
Self {
event: Some(event),
..self
}
}

fn query(self, query: &'a gstreamer::QueryRef) -> Self {
Self {
query: Some(query),
..self
}
}

fn message(self, message: &'a gstreamer::Message) -> Self {
Self {
message: Some(message),
..self
}
}

fn build(self, tracer: &TracingTracerPriv) {
let callsite = crate::callsite::DynamicCallsites::get().callsite_for(
tracing::Level::ERROR,
self.name,
self.name,
None,
None,
None,
GstCallsiteKind::Span,
self.pad.as_ref().map_or(
// List of fields for element traces
&[
"gstelement.name",
"gstelement.state",
"gstelement.next_state",
"gstelement.message.type",
],
|_| {
// List of fields for pad traces
&[
"gstpad.flags",
"gstpad.name",
"gstpad.parent.name",
"gstpad.event.type",
"gstpad.query.type",
]
},
),
);
let interest = callsite.interest();
if interest.is_never() {
return;
}
let meta = callsite.metadata();
let dispatch = tracing_core::dispatcher::get_default(move |dispatch| dispatch.clone());
if !dispatch.enabled(meta) {
return;
}
let fields = meta.fields();

let mut fields_iter = fields.into_iter();
if let Some(element) = self.element {
let (_, state, next_state) =
element.state(Some(gstreamer::ClockTime::from_mseconds(0)));
let state_value = Some(crate::state_desc(state as i32));
let next_state_value = Some(crate::state_desc(next_state as i32));
let name = element.name();
let name_value = Some(name.as_str());
let message_type_name = self.message.map(crate::message_name);

// /!\ /!\ /!\ Must be in the same order as the list of fields for element above /!\ /!\ /!\
let values = field_values![fields_iter =>
"gstelement.name" = name_value;
"gstelement.state" = state_value;
"gstelement.next_state" = next_state_value;
"gstelement.message.type" = message_type_name;
];

let valueset = fields.value_set(&values);
let attrs = tracing::span::Attributes::new_root(meta, &valueset);

tracer.push_span(dispatch, attrs);
} else {
let pad = self.pad.unwrap();

let gstpad_flags_value = Some(tracing_core::field::display(crate::PadFlags(
pad.pad_flags().bits(),
)));
let name = pad.name();
let name_value = Some(name.as_str());
let gstpad_parent = pad.parent_element();
let gstpad_parent_name_value = gstpad_parent.map(|p| p.name());
let gstpad_parent_name_value = gstpad_parent_name_value.as_ref().map(|n| n.as_str());
let event_type = self.event.map(|e| e.type_().name());
let event_type_name = event_type.as_ref().map(|n| n.as_str());
let query_type_name = self.query.map(crate::query_name);

let values = field_values![fields_iter =>
// /!\ /!\ /!\ Must be in the same order as the list of fields for pad above /!\ /!\ /!\
"gstpad.flags" = gstpad_flags_value;
"gstpad.name" = name_value;
"gstpad.parent.name" = gstpad_parent_name_value;
"gstpad.event.type" = event_type_name;
"gstpad.query.type" = query_type_name;
];

let valueset = fields.value_set(&values);
let attrs = tracing::span::Attributes::new_root(meta, &valueset);

tracer.push_span(dispatch, attrs);
}
}
}

impl TracingTracerPriv {
fn push_span(&self, dispatch: Dispatch, attributes: Attributes) {
let span_id = dispatch.new_span(&attributes);
Expand All @@ -43,41 +191,9 @@ impl TracingTracerPriv {
}

fn pad_pre(&self, name: &'static str, pad: &Pad) {
let callsite = crate::callsite::DynamicCallsites::get().callsite_for(
tracing::Level::ERROR,
name,
name,
None,
None,
None,
GstCallsiteKind::Span,
&["gstpad.state", "gstpad.parent.name"],
);
let interest = callsite.interest();
if interest.is_never() {
return;
}
let meta = callsite.metadata();
let dispatch = tracing_core::dispatcher::get_default(move |dispatch| dispatch.clone());
if !dispatch.enabled(meta) {
return;
}
let gstpad_flags_value = Some(tracing_core::field::display(crate::PadFlags(
pad.pad_flags().bits(),
)));
let gstpad_parent = pad.parent_element();
let gstpad_parent_name_value = gstpad_parent.map(|p| p.name());
let gstpad_parent_name_value = gstpad_parent_name_value.as_ref().map(|n| n.as_str());
let fields = meta.fields();
let mut fields_iter = fields.into_iter();
let values = field_values![fields_iter =>
// /!\ /!\ /!\ Must be in the same order as the field list above /!\ /!\ /!\
"gstpad.flags" = gstpad_flags_value;
"gstpad.parent.name" = gstpad_parent_name_value;
];
let valueset = fields.value_set(&values);
let attrs = tracing::span::Attributes::new_root(meta, &valueset);
self.push_span(dispatch, attrs);
let builder = SpanBuilder::new_pad(name, pad);

builder.build(self);
}
}

Expand Down Expand Up @@ -115,12 +231,48 @@ impl ObjectImpl for TracingTracerPriv {
self.register_hook(TracerHook::PadPushEventPre);
self.register_hook(TracerHook::PadPullRangePost);
self.register_hook(TracerHook::PadPullRangePre);
self.register_hook(TracerHook::ElementChangeStatePre);
self.register_hook(TracerHook::ElementChangeStatePost);

self.register_hook(TracerHook::ElementPostMessagePre);
self.register_hook(TracerHook::ElementPostMessagePost);

#[cfg(feature = "v1_22")]
{
self.register_hook(TracerHook::PadChainPre);
self.register_hook(TracerHook::PadChainPost);
}
}
}

impl GstObjectImpl for TracingTracerPriv {}

impl TracerImpl for TracingTracerPriv {
fn element_post_message_pre(
&self,
_ts: u64,
element: &gstreamer::Element,
message: &gstreamer::Message,
) {
SpanBuilder::new_element("message", element)
.message(message)
.build(self);
}

fn element_change_state_pre(
&self,
_ts: u64,
element: &gstreamer::Element,
_change: gstreamer::StateChange,
) {
SpanBuilder::new_element("element_state", element).build(self);
}

#[cfg(feature = "v1_22")]
fn pad_chain_pre(&self, _: u64, pad: &Pad, _: &Buffer) {
self.pad_pre("pad_chain", pad);
}

fn pad_push_pre(&self, _: u64, pad: &Pad, _: &Buffer) {
self.pad_pre("pad_push", pad);
}
Expand All @@ -129,12 +281,16 @@ impl TracerImpl for TracingTracerPriv {
self.pad_pre("pad_push_list", pad);
}

fn pad_query_pre(&self, _: u64, pad: &Pad, _: &gstreamer::QueryRef) {
self.pad_pre("pad_query", pad);
fn pad_query_pre(&self, _: u64, pad: &Pad, query: &gstreamer::QueryRef) {
SpanBuilder::new_pad("pad_query", pad)
.query(query)
.build(self);
}

fn pad_push_event_pre(&self, _: u64, pad: &Pad, _: &gstreamer::Event) {
self.pad_pre("pad_event", pad);
fn pad_push_event_pre(&self, _: u64, pad: &Pad, event: &gstreamer::Event) {
SpanBuilder::new_pad("pad_event", pad)
.event(event)
.build(self);
}

fn pad_pull_range_pre(&self, _: u64, pad: &Pad, _: u64, _: u32) {
Expand All @@ -157,7 +313,26 @@ impl TracerImpl for TracingTracerPriv {
self.pop_span();
}

#[cfg(feature = "v1_22")]
fn pad_chain_post(&self, _: u64, _: &Pad, _: Result<FlowSuccess, FlowError>) {
self.pop_span();
}

fn pad_query_post(&self, _: u64, _: &Pad, _: &gstreamer::QueryRef, _: bool) {
self.pop_span();
}

fn element_change_state_post(
&self,
_: u64,
_: &gstreamer::Element,
_: gstreamer::StateChange,
_: Result<gstreamer::StateChangeSuccess, gstreamer::StateChangeError>,
) {
self.pop_span();
}

fn element_post_message_post(&self, _ts: u64, _element: &gstreamer::Element, _success: bool) {
self.pop_span();
}
}