tracing: add hooks for gst_pad_send_event_unchecked()

Similar to de30de865c, this allows to follow the flow of events as they
arrive to a pad rather than only when they are pushed to a peer.

The hook is installed in gst_pad_send_event_unchecked() instead of
gst_pad_send_event() because the latter is often omitted: that is the
case especifically in gst_pad_push_event_unchecked(), where most event
propagation occurs.

This patch also makes use of the new hooks in the log tracer to log the
begining and end of the send_event processing.

Part-of: <https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/8330>

subprojects/gstreamer/gst/gstpad.c

@@ -5903,6 +5903,7 @@ gst_pad_send_event_unchecked (GstPad * pad, GstEvent * event,
   GstObject *parent;
   gint64 old_pad_offset;
 
+  GST_TRACER_PAD_SEND_EVENT_PRE (pad, event);
   GST_OBJECT_LOCK (pad);
 
   old_pad_offset = pad->offset;
@@ -6078,7 +6079,7 @@ gst_pad_send_event_unchecked (GstPad * pad, GstEvent * event,
   if (need_unlock)
     GST_PAD_STREAM_UNLOCK (pad);
 
-  return ret;
+  goto done;
 
   /* ERROR handling */
 flushing:
@@ -6089,7 +6090,8 @@ flushing:
     GST_CAT_INFO_OBJECT (GST_CAT_EVENT, pad,
         "Received event on flushing pad. Discarding");
     gst_event_unref (event);
-    return GST_FLOW_FLUSHING;
+    ret = GST_FLOW_FLUSHING;
+    goto done;
   }
 inactive:
   {
@@ -6099,7 +6101,8 @@ inactive:
     GST_CAT_INFO_OBJECT (GST_CAT_EVENT, pad,
         "Received flush-stop on inactive pad. Discarding");
     gst_event_unref (event);
-    return GST_FLOW_FLUSHING;
+    ret = GST_FLOW_FLUSHING;
+    goto done;
   }
 eos:
   {
@@ -6109,7 +6112,8 @@ eos:
     GST_CAT_INFO_OBJECT (GST_CAT_EVENT, pad,
         "Received event on EOS pad. Discarding");
     gst_event_unref (event);
-    return GST_FLOW_EOS;
+    ret = GST_FLOW_EOS;
+    goto done;
   }
 probe_stopped:
   {
@@ -6130,7 +6134,7 @@ probe_stopped:
         GST_DEBUG_OBJECT (pad, "an error occurred %s", gst_flow_get_name (ret));
         break;
     }
-    return ret;
+    goto done;
   }
 no_function:
   {
@@ -6140,7 +6144,8 @@ no_function:
     if (need_unlock)
       GST_PAD_STREAM_UNLOCK (pad);
     gst_event_unref (event);
-    return GST_FLOW_NOT_SUPPORTED;
+    ret = GST_FLOW_NOT_SUPPORTED;
+    goto done;
   }
 no_parent:
   {
@@ -6149,7 +6154,8 @@ no_parent:
     if (need_unlock)
       GST_PAD_STREAM_UNLOCK (pad);
     gst_event_unref (event);
-    return GST_FLOW_FLUSHING;
+    ret = GST_FLOW_FLUSHING;
+    goto done;
   }
 precheck_failed:
   {
@@ -6158,8 +6164,11 @@ precheck_failed:
     if (need_unlock)
       GST_PAD_STREAM_UNLOCK (pad);
     gst_event_unref (event);
-    return ret;
+    goto done;
   }
+done:
+  GST_TRACER_PAD_SEND_EVENT_POST (pad, ret);
+  return ret;
 }
 
 /**

subprojects/gstreamer/gst/gsttracerutils.c

@@ -57,7 +57,7 @@ static const gchar *_quark_strings[] = {
   "object-destroyed", "mini-object-reffed", "mini-object-unreffed",
   "object-reffed", "object-unreffed", "plugin-feature-loaded",
   "pad-chain-pre", "pad-chain-post", "pad-chain-list-pre",
-  "pad-chain-list-post",
+  "pad-chain-list-post", "pad-send-event-pre", "pad-send-event-post",
 };
 
 GQuark _priv_gst_tracer_quark_table[GST_TRACER_QUARK_MAX];

subprojects/gstreamer/gst/gsttracerutils.h

@@ -84,6 +84,8 @@ typedef enum /*< skip >*/
   GST_TRACER_QUARK_HOOK_PAD_CHAIN_POST,
   GST_TRACER_QUARK_HOOK_PAD_CHAIN_LIST_PRE,
   GST_TRACER_QUARK_HOOK_PAD_CHAIN_LIST_POST,
+  GST_TRACER_QUARK_HOOK_PAD_SEND_EVENT_PRE,
+  GST_TRACER_QUARK_HOOK_PAD_SEND_EVENT_POST,
   GST_TRACER_QUARK_MAX
 } GstTracerQuarkId;
 
@@ -269,6 +271,38 @@ typedef void (*GstTracerHookPadPushEventPost) (GObject *self, GstClockTime ts,
     GstTracerHookPadPushEventPost, (GST_TRACER_ARGS, pad, res)); \
 }G_STMT_END
 
+/**
+ * GstTracerHookPadSendEventPre:
+ * @self: the tracer instance
+ * @ts: the current timestamp
+ * @pad: the pad
+ * @event: the event
+ *
+ * Pre-hook for gst_pad_send_event_unchecked() named "pad-send-event-pre".
+ */
+typedef void (*GstTracerHookPadSendEventPre) (GObject *self, GstClockTime ts,
+    GstPad *pad, GstEvent *event);
+#define GST_TRACER_PAD_SEND_EVENT_PRE(pad, event) G_STMT_START{ \
+  GST_TRACER_DISPATCH(GST_TRACER_QUARK(HOOK_PAD_SEND_EVENT_PRE), \
+    GstTracerHookPadSendEventPre, (GST_TRACER_ARGS, pad, event)); \
+}G_STMT_END
+
+/**
+ * GstTracerHookPadSendEventPost:
+ * @self: the tracer instance
+ * @ts: the current timestamp
+ * @pad: the pad
+ * @res: the result of gst_pad_send_event_unchecked()
+ *
+ * Post-hook for gst_pad_send_event_unchecked() named "pad-send-event-post".
+ */
+typedef void (*GstTracerHookPadSendEventPost) (GObject *self, GstClockTime ts,
+    GstPad *pad, GstFlowReturn res);
+#define GST_TRACER_PAD_SEND_EVENT_POST(pad, res) G_STMT_START{ \
+  GST_TRACER_DISPATCH(GST_TRACER_QUARK(HOOK_PAD_SEND_EVENT_POST), \
+    GstTracerHookPadSendEventPost, (GST_TRACER_ARGS, pad, res)); \
+}G_STMT_END
+
 /**
  * GstTracerHookPadQueryPre:
  * @self: the tracer instance

subprojects/gstreamer/plugins/tracers/gstlog.c

@@ -58,6 +58,7 @@
  *    * `pad-chain-list-pre`, `pad-chain-list-post`
  *  * `GST_DEBUG=GST_EVENT:TRACE`
  *    * `pad-push-event-pre`, `pad-push-event-post`
+ *    * `pad-send-event-pre`, `pad-send-event-post`
  *  * `GST_DEBUG=GST_QUERY:TRACE`
  *    * `pad-query-pre`, `pad-query-post`
  *    * `element-query-pre`, `element-query-post`
@@ -260,6 +261,23 @@ do_push_event_post (GstTracer * self, guint64 ts, GstPad * pad, gboolean res)
       GST_TIME_ARGS (ts), pad, res);
 }
 
+static void
+do_send_event_pre (GstTracer * self, guint64 ts, GstPad * pad, GstEvent * event)
+{
+  do_log (GST_CAT_EVENT, GST_FUNCTION, (GObject *) pad,
+      "%" GST_TIME_FORMAT ", pad=%" GST_PTR_FORMAT ", event=%" GST_PTR_FORMAT,
+      GST_TIME_ARGS (ts), pad, event);
+}
+
+static void
+do_send_event_post (GstTracer * self, guint64 ts, GstPad * pad,
+    GstFlowReturn res)
+{
+  do_log (GST_CAT_EVENT, GST_FUNCTION, (GObject *) pad,
+      "%" GST_TIME_FORMAT ", pad=%" GST_PTR_FORMAT ", res=%s",
+      GST_TIME_ARGS (ts), pad, gst_flow_get_name (res));
+}
+
 static void
 do_pad_query_pre (GstTracer * self, guint64 ts, GstPad * pad, GstQuery * query)
 {
@@ -491,6 +509,10 @@ gst_log_tracer_init (GstLogTracer * self)
       G_CALLBACK (do_push_event_pre));
   gst_tracing_register_hook (tracer, "pad-push-event-post",
       G_CALLBACK (do_push_event_post));
+  gst_tracing_register_hook (tracer, "pad-send-event-pre",
+      G_CALLBACK (do_send_event_pre));
+  gst_tracing_register_hook (tracer, "pad-send-event-post",
+      G_CALLBACK (do_send_event_post));
   gst_tracing_register_hook (tracer, "pad-query-pre",
       G_CALLBACK (do_pad_query_pre));
   gst_tracing_register_hook (tracer, "pad-query-post",