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