1*4882a593SmuzhiyunFrom e1e2d8d58c1e09e065849cdb1f6466c0537a7c51 Mon Sep 17 00:00:00 2001
2*4882a593SmuzhiyunFrom: =?UTF-8?q?Sebastian=20Dr=C3=B6ge?= <sebastian@centricular.com>
3*4882a593SmuzhiyunDate: Tue, 21 Jun 2022 11:51:35 +0300
4*4882a593SmuzhiyunSubject: [PATCH] bin: Fix race conditions in tests
5*4882a593Smuzhiyun
6*4882a593SmuzhiyunThe latency messages are non-deterministic and can arrive before/after
7*4882a593Smuzhiyunasync-done or during state-changes as they are posted by e.g. sinks from
8*4882a593Smuzhiyuntheir streaming thread but bins are finishing asynchronous state changes
9*4882a593Smuzhiyunfrom a secondary helper thread.
10*4882a593Smuzhiyun
11*4882a593SmuzhiyunTo solve this, expect latency messages at any time and assert that we
12*4882a593Smuzhiyunreceive one at some point during the test.
13*4882a593Smuzhiyun
14*4882a593SmuzhiyunPart-of: <https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/2643>
15*4882a593Smuzhiyun
16*4882a593SmuzhiyunUpstream-Status: Backport [https://gitlab.freedesktop.org/gstreamer/gstreamer/-/merge_requests/2643]
17*4882a593SmuzhiyunSigned-off-by: Jose Quaresma <quaresma.jose@gmail.com>
18*4882a593Smuzhiyun---
19*4882a593Smuzhiyun .../gstreamer/tests/check/gst/gstbin.c        | 132 ++++++++++++------
20*4882a593Smuzhiyun 1 file changed, 92 insertions(+), 40 deletions(-)
21*4882a593Smuzhiyun
22*4882a593Smuzhiyundiff --git a/subprojects/gstreamer/tests/check/gst/gstbin.c b/subprojects/gstreamer/tests/check/gst/gstbin.c
23*4882a593Smuzhiyunindex e366d5fe20f..88ff44db0c3 100644
24*4882a593Smuzhiyun--- a/subprojects/gstreamer/tests/check/gst/gstbin.c
25*4882a593Smuzhiyun+++ b/subprojects/gstreamer/tests/check/gst/gstbin.c
26*4882a593Smuzhiyun@@ -27,50 +27,95 @@
27*4882a593Smuzhiyun #include <gst/base/gstbasesrc.h>
28*4882a593Smuzhiyun
29*4882a593Smuzhiyun static void
30*4882a593Smuzhiyun-pop_async_done (GstBus * bus)
31*4882a593Smuzhiyun+pop_async_done (GstBus * bus, gboolean * had_latency)
32*4882a593Smuzhiyun {
33*4882a593Smuzhiyun   GstMessage *message;
34*4882a593Smuzhiyun+  GstMessageType types = GST_MESSAGE_ASYNC_DONE;
35*4882a593Smuzhiyun+
36*4882a593Smuzhiyun+  if (!*had_latency)
37*4882a593Smuzhiyun+    types |= GST_MESSAGE_LATENCY;
38*4882a593Smuzhiyun
39*4882a593Smuzhiyun   GST_DEBUG ("popping async-done message");
40*4882a593Smuzhiyun-  message = gst_bus_poll (bus, GST_MESSAGE_ASYNC_DONE, -1);
41*4882a593Smuzhiyun
42*4882a593Smuzhiyun-  fail_unless (message && GST_MESSAGE_TYPE (message)
43*4882a593Smuzhiyun-      == GST_MESSAGE_ASYNC_DONE, "did not get GST_MESSAGE_ASYNC_DONE");
44*4882a593Smuzhiyun+  do {
45*4882a593Smuzhiyun+    message = gst_bus_poll (bus, types, -1);
46*4882a593Smuzhiyun
47*4882a593Smuzhiyun-  gst_message_unref (message);
48*4882a593Smuzhiyun-  GST_DEBUG ("popped message");
49*4882a593Smuzhiyun+    fail_unless (message);
50*4882a593Smuzhiyun+    GST_DEBUG ("popped message %s",
51*4882a593Smuzhiyun+        gst_message_type_get_name (GST_MESSAGE_TYPE (message)));
52*4882a593Smuzhiyun+
53*4882a593Smuzhiyun+    if (GST_MESSAGE_TYPE (message) == GST_MESSAGE_LATENCY) {
54*4882a593Smuzhiyun+      fail_unless (*had_latency == FALSE);
55*4882a593Smuzhiyun+      *had_latency = TRUE;
56*4882a593Smuzhiyun+      gst_clear_message (&message);
57*4882a593Smuzhiyun+      types &= ~GST_MESSAGE_LATENCY;
58*4882a593Smuzhiyun+      continue;
59*4882a593Smuzhiyun+    }
60*4882a593Smuzhiyun+
61*4882a593Smuzhiyun+    fail_unless (GST_MESSAGE_TYPE (message)
62*4882a593Smuzhiyun+        == GST_MESSAGE_ASYNC_DONE, "did not get GST_MESSAGE_ASYNC_DONE");
63*4882a593Smuzhiyun+
64*4882a593Smuzhiyun+    gst_clear_message (&message);
65*4882a593Smuzhiyun+    break;
66*4882a593Smuzhiyun+  } while (TRUE);
67*4882a593Smuzhiyun }
68*4882a593Smuzhiyun
69*4882a593Smuzhiyun static void
70*4882a593Smuzhiyun-pop_latency (GstBus * bus)
71*4882a593Smuzhiyun+pop_latency (GstBus * bus, gboolean * had_latency)
72*4882a593Smuzhiyun {
73*4882a593Smuzhiyun   GstMessage *message;
74*4882a593Smuzhiyun
75*4882a593Smuzhiyun-  GST_DEBUG ("popping async-done message");
76*4882a593Smuzhiyun+  if (*had_latency)
77*4882a593Smuzhiyun+    return;
78*4882a593Smuzhiyun+
79*4882a593Smuzhiyun+  GST_DEBUG ("popping latency message");
80*4882a593Smuzhiyun   message = gst_bus_poll (bus, GST_MESSAGE_LATENCY, -1);
81*4882a593Smuzhiyun
82*4882a593Smuzhiyun-  fail_unless (message && GST_MESSAGE_TYPE (message)
83*4882a593Smuzhiyun+  fail_unless (message);
84*4882a593Smuzhiyun+  fail_unless (GST_MESSAGE_TYPE (message)
85*4882a593Smuzhiyun       == GST_MESSAGE_LATENCY, "did not get GST_MESSAGE_LATENCY");
86*4882a593Smuzhiyun
87*4882a593Smuzhiyun-  gst_message_unref (message);
88*4882a593Smuzhiyun-  GST_DEBUG ("popped message");
89*4882a593Smuzhiyun+  GST_DEBUG ("popped message %s",
90*4882a593Smuzhiyun+      gst_message_type_get_name (GST_MESSAGE_TYPE (message)));
91*4882a593Smuzhiyun+  gst_clear_message (&message);
92*4882a593Smuzhiyun+
93*4882a593Smuzhiyun+  *had_latency = TRUE;
94*4882a593Smuzhiyun }
95*4882a593Smuzhiyun
96*4882a593Smuzhiyun static void
97*4882a593Smuzhiyun-pop_state_changed (GstBus * bus, int count)
98*4882a593Smuzhiyun+pop_state_changed (GstBus * bus, int count, gboolean * had_latency)
99*4882a593Smuzhiyun {
100*4882a593Smuzhiyun   GstMessage *message;
101*4882a593Smuzhiyun-
102*4882a593Smuzhiyun+  GstMessageType types = GST_MESSAGE_STATE_CHANGED;
103*4882a593Smuzhiyun   int i;
104*4882a593Smuzhiyun
105*4882a593Smuzhiyun+  if (!*had_latency)
106*4882a593Smuzhiyun+    types |= GST_MESSAGE_LATENCY;
107*4882a593Smuzhiyun+
108*4882a593Smuzhiyun   GST_DEBUG ("popping %d messages", count);
109*4882a593Smuzhiyun   for (i = 0; i < count; ++i) {
110*4882a593Smuzhiyun-    message = gst_bus_poll (bus, GST_MESSAGE_STATE_CHANGED, -1);
111*4882a593Smuzhiyun-
112*4882a593Smuzhiyun-    fail_unless (message && GST_MESSAGE_TYPE (message)
113*4882a593Smuzhiyun-        == GST_MESSAGE_STATE_CHANGED, "did not get GST_MESSAGE_STATE_CHANGED");
114*4882a593Smuzhiyun-
115*4882a593Smuzhiyun-    gst_message_unref (message);
116*4882a593Smuzhiyun+    do {
117*4882a593Smuzhiyun+      message = gst_bus_poll (bus, types, -1);
118*4882a593Smuzhiyun+
119*4882a593Smuzhiyun+      fail_unless (message);
120*4882a593Smuzhiyun+      GST_DEBUG ("popped message %s",
121*4882a593Smuzhiyun+          gst_message_type_get_name (GST_MESSAGE_TYPE (message)));
122*4882a593Smuzhiyun+
123*4882a593Smuzhiyun+      if (GST_MESSAGE_TYPE (message) == GST_MESSAGE_LATENCY) {
124*4882a593Smuzhiyun+        fail_unless (*had_latency == FALSE);
125*4882a593Smuzhiyun+        *had_latency = TRUE;
126*4882a593Smuzhiyun+        gst_clear_message (&message);
127*4882a593Smuzhiyun+        types &= ~GST_MESSAGE_LATENCY;
128*4882a593Smuzhiyun+        continue;
129*4882a593Smuzhiyun+      }
130*4882a593Smuzhiyun+
131*4882a593Smuzhiyun+      fail_unless (GST_MESSAGE_TYPE (message)
132*4882a593Smuzhiyun+          == GST_MESSAGE_STATE_CHANGED,
133*4882a593Smuzhiyun+          "did not get GST_MESSAGE_STATE_CHANGED");
134*4882a593Smuzhiyun+
135*4882a593Smuzhiyun+      gst_message_unref (message);
136*4882a593Smuzhiyun+      break;
137*4882a593Smuzhiyun+    } while (TRUE);
138*4882a593Smuzhiyun   }
139*4882a593Smuzhiyun   GST_DEBUG ("popped %d messages", count);
140*4882a593Smuzhiyun }
141*4882a593Smuzhiyun@@ -538,6 +583,7 @@ GST_START_TEST (test_message_state_changed_children)
142*4882a593Smuzhiyun   GstBus *bus;
143*4882a593Smuzhiyun   GstStateChangeReturn ret;
144*4882a593Smuzhiyun   GstState current, pending;
145*4882a593Smuzhiyun+  gboolean had_latency = FALSE;
146*4882a593Smuzhiyun
147*4882a593Smuzhiyun   pipeline = GST_PIPELINE (gst_pipeline_new (NULL));
148*4882a593Smuzhiyun   fail_unless (pipeline != NULL, "Could not create pipeline");
149*4882a593Smuzhiyun@@ -576,7 +622,7 @@ GST_START_TEST (test_message_state_changed_children)
150*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (sink, "sink", 2);
151*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (pipeline, "pipeline", 2);
152*4882a593Smuzhiyun
153*4882a593Smuzhiyun-  pop_state_changed (bus, 3);
154*4882a593Smuzhiyun+  pop_state_changed (bus, 3, &had_latency);
155*4882a593Smuzhiyun   fail_if (gst_bus_have_pending (bus), "unexpected pending messages");
156*4882a593Smuzhiyun
157*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (bus, "bus", 2);
158*4882a593Smuzhiyun@@ -619,9 +665,9 @@ GST_START_TEST (test_message_state_changed_children)
159*4882a593Smuzhiyun    * its state_change message */
160*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT_BETWEEN (pipeline, "pipeline", 3, 4);
161*4882a593Smuzhiyun
162*4882a593Smuzhiyun-  pop_state_changed (bus, 3);
163*4882a593Smuzhiyun-  pop_async_done (bus);
164*4882a593Smuzhiyun-  pop_latency (bus);
165*4882a593Smuzhiyun+  pop_state_changed (bus, 3, &had_latency);
166*4882a593Smuzhiyun+  pop_async_done (bus, &had_latency);
167*4882a593Smuzhiyun+  pop_latency (bus, &had_latency);
168*4882a593Smuzhiyun   fail_if ((gst_bus_pop (bus)) != NULL);
169*4882a593Smuzhiyun
170*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT_BETWEEN (bus, "bus", 2, 3);
171*4882a593Smuzhiyun@@ -648,7 +694,7 @@ GST_START_TEST (test_message_state_changed_children)
172*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT_BETWEEN (sink, "sink", 2, 4);
173*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (pipeline, "pipeline", 3);
174*4882a593Smuzhiyun
175*4882a593Smuzhiyun-  pop_state_changed (bus, 3);
176*4882a593Smuzhiyun+  pop_state_changed (bus, 3, &had_latency);
177*4882a593Smuzhiyun   fail_if ((gst_bus_pop (bus)) != NULL);
178*4882a593Smuzhiyun
179*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (bus, "bus", 2);
180*4882a593Smuzhiyun@@ -669,7 +715,7 @@ GST_START_TEST (test_message_state_changed_children)
181*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT_BETWEEN (sink, "sink", 3, 4);
182*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (pipeline, "pipeline", 3);
183*4882a593Smuzhiyun
184*4882a593Smuzhiyun-  pop_state_changed (bus, 6);
185*4882a593Smuzhiyun+  pop_state_changed (bus, 6, &had_latency);
186*4882a593Smuzhiyun   fail_if ((gst_bus_pop (bus)) != NULL);
187*4882a593Smuzhiyun
188*4882a593Smuzhiyun   ASSERT_OBJECT_REFCOUNT (src, "src", 1);
189*4882a593Smuzhiyun@@ -696,6 +742,7 @@ GST_START_TEST (test_watch_for_state_change)
190*4882a593Smuzhiyun   GstElement *src, *sink, *bin;
191*4882a593Smuzhiyun   GstBus *bus;
192*4882a593Smuzhiyun   GstStateChangeReturn ret;
193*4882a593Smuzhiyun+  gboolean had_latency = FALSE;
194*4882a593Smuzhiyun
195*4882a593Smuzhiyun   bin = gst_element_factory_make ("bin", NULL);
196*4882a593Smuzhiyun   fail_unless (bin != NULL, "Could not create bin");
197*4882a593Smuzhiyun@@ -722,9 +769,9 @@ GST_START_TEST (test_watch_for_state_change)
198*4882a593Smuzhiyun       GST_CLOCK_TIME_NONE);
199*4882a593Smuzhiyun   fail_unless (ret == GST_STATE_CHANGE_SUCCESS);
200*4882a593Smuzhiyun
201*4882a593Smuzhiyun-  pop_state_changed (bus, 6);
202*4882a593Smuzhiyun-  pop_async_done (bus);
203*4882a593Smuzhiyun-  pop_latency (bus);
204*4882a593Smuzhiyun+  pop_state_changed (bus, 6, &had_latency);
205*4882a593Smuzhiyun+  pop_async_done (bus, &had_latency);
206*4882a593Smuzhiyun+  pop_latency (bus, &had_latency);
207*4882a593Smuzhiyun
208*4882a593Smuzhiyun   fail_unless (gst_bus_have_pending (bus) == FALSE,
209*4882a593Smuzhiyun       "Unexpected messages on bus");
210*4882a593Smuzhiyun@@ -732,16 +779,17 @@ GST_START_TEST (test_watch_for_state_change)
211*4882a593Smuzhiyun   ret = gst_element_set_state (GST_ELEMENT (bin), GST_STATE_PLAYING);
212*4882a593Smuzhiyun   fail_unless (ret == GST_STATE_CHANGE_SUCCESS);
213*4882a593Smuzhiyun
214*4882a593Smuzhiyun-  pop_state_changed (bus, 3);
215*4882a593Smuzhiyun+  pop_state_changed (bus, 3, &had_latency);
216*4882a593Smuzhiyun
217*4882a593Smuzhiyun+  had_latency = FALSE;
218*4882a593Smuzhiyun   /* this one might return either SUCCESS or ASYNC, likely SUCCESS */
219*4882a593Smuzhiyun   ret = gst_element_set_state (GST_ELEMENT (bin), GST_STATE_PAUSED);
220*4882a593Smuzhiyun   gst_element_get_state (GST_ELEMENT (bin), NULL, NULL, GST_CLOCK_TIME_NONE);
221*4882a593Smuzhiyun
222*4882a593Smuzhiyun-  pop_state_changed (bus, 3);
223*4882a593Smuzhiyun+  pop_state_changed (bus, 3, &had_latency);
224*4882a593Smuzhiyun   if (ret == GST_STATE_CHANGE_ASYNC) {
225*4882a593Smuzhiyun-    pop_async_done (bus);
226*4882a593Smuzhiyun-    pop_latency (bus);
227*4882a593Smuzhiyun+    pop_async_done (bus, &had_latency);
228*4882a593Smuzhiyun+    pop_latency (bus, &had_latency);
229*4882a593Smuzhiyun   }
230*4882a593Smuzhiyun
231*4882a593Smuzhiyun   fail_unless (gst_bus_have_pending (bus) == FALSE,
232*4882a593Smuzhiyun@@ -898,6 +946,7 @@ GST_START_TEST (test_children_state_change_order_flagged_sink)
233*4882a593Smuzhiyun   GstStateChangeReturn ret;
234*4882a593Smuzhiyun   GstState current, pending;
235*4882a593Smuzhiyun   GstBus *bus;
236*4882a593Smuzhiyun+  gboolean had_latency = FALSE;
237*4882a593Smuzhiyun
238*4882a593Smuzhiyun   pipeline = gst_pipeline_new (NULL);
239*4882a593Smuzhiyun   fail_unless (pipeline != NULL, "Could not create pipeline");
240*4882a593Smuzhiyun@@ -951,10 +1000,11 @@ GST_START_TEST (test_children_state_change_order_flagged_sink)
241*4882a593Smuzhiyun   ASSERT_STATE_CHANGE_MSG (bus, sink, GST_STATE_READY, GST_STATE_PAUSED, 107);
242*4882a593Smuzhiyun #else
243*4882a593Smuzhiyun
244*4882a593Smuzhiyun-  pop_state_changed (bus, 2);   /* pop remaining ready => paused messages off the bus */
245*4882a593Smuzhiyun+  pop_state_changed (bus, 2, &had_latency);     /* pop remaining ready => paused messages off the bus */
246*4882a593Smuzhiyun   ASSERT_STATE_CHANGE_MSG (bus, pipeline, GST_STATE_READY, GST_STATE_PAUSED,
247*4882a593Smuzhiyun       108);
248*4882a593Smuzhiyun-  pop_async_done (bus);
249*4882a593Smuzhiyun+  pop_async_done (bus, &had_latency);
250*4882a593Smuzhiyun+  pop_latency (bus, &had_latency);
251*4882a593Smuzhiyun #endif
252*4882a593Smuzhiyun   /* PAUSED => PLAYING */
253*4882a593Smuzhiyun   GST_DEBUG ("popping PAUSED -> PLAYING messages");
254*4882a593Smuzhiyun@@ -972,8 +1022,8 @@ GST_START_TEST (test_children_state_change_order_flagged_sink)
255*4882a593Smuzhiyun   fail_if (ret != GST_STATE_CHANGE_SUCCESS, "State change to READY failed");
256*4882a593Smuzhiyun
257*4882a593Smuzhiyun   /* TODO: do we need to check downwards state change order as well? */
258*4882a593Smuzhiyun-  pop_state_changed (bus, 4);   /* pop playing => paused messages off the bus */
259*4882a593Smuzhiyun-  pop_state_changed (bus, 4);   /* pop paused => ready messages off the bus */
260*4882a593Smuzhiyun+  pop_state_changed (bus, 4, &had_latency);     /* pop playing => paused messages off the bus */
261*4882a593Smuzhiyun+  pop_state_changed (bus, 4, &had_latency);     /* pop paused => ready messages off the bus */
262*4882a593Smuzhiyun
263*4882a593Smuzhiyun   while (GST_OBJECT_REFCOUNT_VALUE (pipeline) > 1)
264*4882a593Smuzhiyun     THREAD_SWITCH ();
265*4882a593Smuzhiyun@@ -1002,6 +1052,7 @@ GST_START_TEST (test_children_state_change_order_semi_sink)
266*4882a593Smuzhiyun   GstStateChangeReturn ret;
267*4882a593Smuzhiyun   GstState current, pending;
268*4882a593Smuzhiyun   GstBus *bus;
269*4882a593Smuzhiyun+  gboolean had_latency = FALSE;
270*4882a593Smuzhiyun
271*4882a593Smuzhiyun   /* (2) Now again, but check other code path where we don't have
272*4882a593Smuzhiyun    *     a proper sink correctly flagged as such, but a 'semi-sink' */
273*4882a593Smuzhiyun@@ -1056,10 +1107,11 @@ GST_START_TEST (test_children_state_change_order_semi_sink)
274*4882a593Smuzhiyun   ASSERT_STATE_CHANGE_MSG (bus, src, GST_STATE_READY, GST_STATE_PAUSED, 206);
275*4882a593Smuzhiyun   ASSERT_STATE_CHANGE_MSG (bus, sink, GST_STATE_READY, GST_STATE_PAUSED, 207);
276*4882a593Smuzhiyun #else
277*4882a593Smuzhiyun-  pop_state_changed (bus, 2);   /* pop remaining ready => paused messages off the bus */
278*4882a593Smuzhiyun+  pop_state_changed (bus, 2, &had_latency);     /* pop remaining ready => paused messages off the bus */
279*4882a593Smuzhiyun   ASSERT_STATE_CHANGE_MSG (bus, pipeline, GST_STATE_READY, GST_STATE_PAUSED,
280*4882a593Smuzhiyun       208);
281*4882a593Smuzhiyun-  pop_async_done (bus);
282*4882a593Smuzhiyun+  pop_async_done (bus, &had_latency);
283*4882a593Smuzhiyun+  pop_latency (bus, &had_latency);
284*4882a593Smuzhiyun
285*4882a593Smuzhiyun   /* PAUSED => PLAYING */
286*4882a593Smuzhiyun   GST_DEBUG ("popping PAUSED -> PLAYING messages");
287*4882a593Smuzhiyun@@ -1076,8 +1128,8 @@ GST_START_TEST (test_children_state_change_order_semi_sink)
288*4882a593Smuzhiyun   fail_if (ret != GST_STATE_CHANGE_SUCCESS, "State change to READY failed");
289*4882a593Smuzhiyun
290*4882a593Smuzhiyun   /* TODO: do we need to check downwards state change order as well? */
291*4882a593Smuzhiyun-  pop_state_changed (bus, 4);   /* pop playing => paused messages off the bus */
292*4882a593Smuzhiyun-  pop_state_changed (bus, 4);   /* pop paused => ready messages off the bus */
293*4882a593Smuzhiyun+  pop_state_changed (bus, 4, &had_latency);     /* pop playing => paused messages off the bus */
294*4882a593Smuzhiyun+  pop_state_changed (bus, 4, &had_latency);     /* pop paused => ready messages off the bus */
295*4882a593Smuzhiyun
296*4882a593Smuzhiyun   GST_DEBUG ("waiting for pipeline to reach refcount 1");
297*4882a593Smuzhiyun   while (GST_OBJECT_REFCOUNT_VALUE (pipeline) > 1)
298*4882a593Smuzhiyun--
299*4882a593SmuzhiyunGitLab
300*4882a593Smuzhiyun
301