gstreamer_tracing/
log.rs

1use crate::callsite::GstCallsiteKind;
2use gst::{
3    glib::{GStr, translate::*},
4    prelude::*,
5};
6use std::sync::{LazyLock, Mutex};
7use tracing_core::{Callsite, Event, Level};
8
9fn log_handler(
10    category: gst::DebugCategory,
11    level: gst::DebugLevel,
12    file: &gst::glib::GStr,
13    module: &gst::glib::GStr,
14    line: u32,
15    object: Option<&gst::LoggedObject>,
16    message: &gst::DebugMessage,
17) {
18    skip_assert_initialized!();
19    let level = match level {
20        gst::DebugLevel::Error => Level::ERROR,
21        gst::DebugLevel::Warning | gst::DebugLevel::Fixme => Level::WARN,
22        gst::DebugLevel::Info => Level::INFO,
23        gst::DebugLevel::Debug | gst::DebugLevel::Log => Level::DEBUG,
24        gst::DebugLevel::Trace | gst::DebugLevel::Memdump => Level::TRACE,
25        _ => return,
26    };
27    let category_name = category.name();
28    let callsite = crate::callsite::DynamicCallsites::get().callsite_for(
29        level,
30        "",
31        category_name,
32        Some(file.as_str()),
33        Some(module.as_str()),
34        Some(line),
35        GstCallsiteKind::Event,
36        &[
37            "message",
38            "gobject.address",
39            "gobject.type",
40            "gstobject.name",
41            "gstelement.state",
42            "gstelement.pending_state",
43            "gstpad.state",
44            "gstpad.parent.name",
45            "gstpad.parent.state",
46            "gstpad.parent.pending_state",
47        ],
48    );
49    let interest = callsite.interest();
50    if interest.is_never() {
51        return;
52    }
53    let meta = callsite.metadata();
54    tracing_core::dispatcher::get_default(move |dispatcher| {
55        if !dispatcher.enabled(meta) {
56            return;
57        }
58        let fields = meta.fields();
59        let message_str = message.get();
60        let message_value = message_str.as_deref().map(|g| g.as_str());
61
62        let gobject = object.map(|o| o.as_ptr());
63        let gobject = unsafe {
64            // SAFETY: we check for null pointer before we dereference it. While the object
65            // contents might not otherwise be super defined while ref_count is 0, reading the
66            // ref_count itself here should be good, still.
67            gobject.and_then(|ptr| {
68                if (*ptr).ref_count == 0 {
69                    None
70                } else {
71                    Some(ptr)
72                }
73            })
74        };
75        let gobject_address_value = gobject.map(|obj| obj as usize);
76        let gobject_with_ty = gobject.and_then(|obj| unsafe {
77            let ty: gst::glib::Type =
78                from_glib(obj.as_ref()?.g_type_instance.g_class.as_ref()?.g_type);
79            Some((obj, ty))
80        });
81        let gobject_type_value = gobject_with_ty.as_ref().map(|(_, ty)| ty.name());
82        let gstobject = gobject_with_ty.and_then(|(obj, ty)| {
83            if ty.is_a(gst::Object::static_type()) {
84                Some(obj as *mut gst::ffi::GstObject)
85            } else {
86                None
87            }
88        });
89
90        let gstobject_name = gstobject.as_ref().and_then(|gstobject| unsafe {
91            // SAFETY: GstObject type has been verified above, `name` can be null and we
92            // check for it. It "should" be valid null-terminated string if not null,
93            // however.
94            Some(GStr::from_ptr((*(*gstobject)).name.as_ref()?).as_str())
95        });
96
97        let user_span = gstobject.as_ref().and_then(|gstobject| unsafe {
98            let quark = *span_quark();
99            let obj: gst::Object = ref_gst_object(*gstobject);
100            obj.qdata::<tracing::Span>(quark)
101                .map(|s| s.as_ref().clone())
102        });
103
104        let gstobject_name_value = gstobject_name;
105        let gstelement = gobject_with_ty.as_ref().and_then(|(obj, ty)| {
106            if ty.is_a(gst::Element::static_type()) {
107                Some(*obj as *mut gst::ffi::GstElement)
108            } else {
109                None
110            }
111        });
112        let gstelement_states = gstelement.map(|e| unsafe {
113            let curr: gst::State = from_glib((*e).current_state);
114            let pend: gst::State = from_glib((*e).pending_state);
115            (curr.name().as_str(), pend.name().as_str())
116        });
117        let gstelement_state_value = gstelement_states.map(|(c, _)| c);
118        let gstelement_pending_state_value = gstelement_states.map(|(_, p)| p);
119        let gstpad = gobject_with_ty.as_ref().and_then(|(obj, ty)| {
120            if ty.is_a(gst::Pad::static_type()) {
121                Some(*obj as *mut gst::ffi::GstPad)
122            } else {
123                None
124            }
125        });
126        let gstpad_flags = gstpad.map(|p| unsafe {
127            // SAFETY: `p` is a valid pointer.
128            let flags = gst::PadFlags::from_bits_truncate((*p).object.flags);
129            tracing_core::field::display(flags)
130        });
131        let gstpad_parent = gstpad.and_then(|p| unsafe {
132            // SAFETY: `p` is a valid pointer.
133            let parent = (*p).object.parent;
134            if parent.is_null() || (*parent).object.ref_count == 0 {
135                None
136            } else {
137                Some(parent)
138            }
139        });
140        let gstpad_parent_name = gstpad_parent.and_then(|obj| unsafe {
141            //SAFETY: same as for gstelement_name above.
142            Some(GStr::from_ptr((*obj).name.as_ref()?).as_str())
143        });
144        let gstpad_parent_name_value = gstpad_parent_name;
145
146        let gstpad_parent_states = gstpad_parent.and_then(|obj| unsafe {
147            let ty: gst::glib::Type =
148                from_glib((*obj).object.g_type_instance.g_class.as_ref()?.g_type);
149            if ty.is_a(gst::Element::static_type()) {
150                let e = obj as *mut gst::ffi::GstElement;
151                let curr: gst::State = from_glib((*e).current_state);
152                let pend: gst::State = from_glib((*e).pending_state);
153                Some((curr.name().as_str(), pend.name().as_str()))
154            } else {
155                None
156            }
157        });
158        let gstpad_parent_state_value = gstpad_parent_states.map(|(c, _)| c);
159        let gstpad_parent_pending_state_value = gstpad_parent_states.map(|(_, p)| p);
160        let mut fields_iter = fields.into_iter();
161        let values = field_values![fields_iter =>
162            // /!\ /!\ /!\ Must be in the same order as the field list above /!\ /!\ /!\
163            "message" = message_value;
164            "gobject.address" = gobject_address_value;
165            "gobject.type" = gobject_type_value;
166            "gstobject.name" = gstobject_name_value;
167            "gstelement.state" = gstelement_state_value;
168            "gstelement.pending_state" = gstelement_pending_state_value;
169            "gstpad.flags" = gstpad_flags;
170            "gstpad.parent.name" = gstpad_parent_name_value;
171            "gstpad.parent.state" = gstpad_parent_state_value;
172            "gstpad.parent.pending_state" = gstpad_parent_pending_state_value;
173        ];
174        let valueset = fields.value_set(&values);
175
176        let event = match user_span {
177            Some(user_span) => Event::new_child_of(user_span, meta, &valueset),
178            None => Event::new(meta, &valueset),
179        };
180
181        dispatcher.event(&event);
182    });
183}
184
185static LOG_FUNCTION: Mutex<Option<gst::log::DebugLogFunction>> = Mutex::new(None);
186
187pub(crate) fn debug_add_log_function() {
188    let handle = gst::log::add_log_function(log_handler);
189    *LOG_FUNCTION.lock().unwrap() = Some(handle);
190}
191
192pub(crate) fn debug_remove_log_function() {
193    if let Some(handle) = LOG_FUNCTION.lock().unwrap().take() {
194        gst::log::remove_log_function(handle);
195    }
196}
197
198/// Like `from_glib_none` but uses `g_object_ref` instead of `g_object_ref_sink`,
199/// so it does not sink floating references. This is necessary because the log
200/// callback can fire during object construction when the object still has a
201/// floating ref — sinking it would cause finalization on drop.
202unsafe fn ref_gst_object(ptr: *mut gst::ffi::GstObject) -> gst::Object {
203    unsafe {
204        gst::glib::gobject_ffi::g_object_ref(ptr as *mut gst::glib::gobject_ffi::GObject);
205        from_glib_full(ptr)
206    }
207}
208
209#[inline]
210pub(crate) fn span_quark() -> &'static gst::glib::Quark {
211    // Generate a unique TypeId specifically for Span quark's name. This gives some probabilistic
212    // security against users of this library overwriting our span with their own types, making
213    // attach_span unsound.
214    //
215    // We're still going to be storing `tracing::Span` within the objects directly, because that's
216    // just more convenient.
217    #[allow(dead_code)]
218    struct QDataTracingSpan(tracing::Span);
219
220    static ELEMENT_SPAN_QUARK: LazyLock<gst::glib::Quark> = LazyLock::new(|| {
221        let type_id = std::any::TypeId::of::<QDataTracingSpan>();
222        let mut hasher = std::collections::hash_map::DefaultHasher::new();
223        std::hash::Hash::hash(&type_id, &mut hasher);
224        let type_id_hash = std::hash::Hasher::finish(&hasher);
225        let key = format!("tracing-gstreamer:{type_id_hash}\0");
226        let gstr = GStr::from_utf8_with_nul(key.as_bytes()).unwrap();
227        gst::glib::Quark::from_str(gstr)
228    });
229
230    &ELEMENT_SPAN_QUARK
231}
232
233/// Attach a span to a GStreamer object.
234///
235/// All events logged for this object and its children will have the provided span as the parent.
236/// This can be used to associate extra context to a pipeline for example.
237///
238/// # Safety
239///
240/// This function is racy and must not be called when an element or any of its children may want to
241/// emit a log message. It is generally safe to call this function during early initialization of a
242/// pipeline, or when the code in calling this has exclusive control of the elements involved.
243///
244/// # Examples
245///
246/// ```
247/// # use gstreamer_tracing as gst_tracing;
248/// gst::init().unwrap();
249///
250/// let pipeline = gst::Pipeline::new();
251/// let gst_log_span = tracing::info_span!(
252///     parent: None,
253///     "gst log",
254///     pipeline = "encoding",
255///     id = 42,
256/// );
257/// unsafe {
258///     gst_tracing::attach_span(&pipeline, gst_log_span);
259/// }
260/// ```
261pub unsafe fn attach_span<O: IsA<gst::Object>>(object: &O, span: tracing::Span) {
262    if unsafe { gst::ffi::gst_is_initialized() == gst::glib::ffi::GTRUE } {
263        static INIT_PROPAGATION_TRACER: std::sync::Once = std::sync::Once::new();
264        INIT_PROPAGATION_TRACER.call_once(|| {
265            // Keep the propagation tracer alive for the rest of the process.
266            let tracer = gst::glib::Object::new::<crate::tracer::SpanPropagationTracer>();
267            std::mem::forget(tracer);
268        });
269    }
270
271    unsafe {
272        // SAFETY:
273        //
274        // **Type safety**: We have given our best shot at making sure that no other random piece
275        // of code, either our own, or any other, interacting with this crate, overwrites our
276        // `qdata` with their own code. In that sense the only thing that might get stored is a
277        // `tracing::Span`.
278        //
279        // **Datarace safety**: TODO: this function can be still called in a loop in a separate
280        // thread to introduce a data race with a function that reads this data out.
281        object.set_qdata(*span_quark(), span);
282    }
283}
gstreamer_tracing/log.rs

gstreamer_tracing/
log.rs
