When running the GstValidate change_state_intensive scenario on RTSP stream, we have a race where going back to PLAYING times out trying to connect to the server to retrieve the SDP.

This issue happens with any stream.

Logs example:

=================
Test name: validate.rtsp.playback.change_state_intensive.vorbis_vp8_1_webm
Command: '/home/thiblahute/devel/gstreamer/gst-build/build/subprojects/gst-devtools/validate/tools/gst-validate-1.0 playbin uri=rtsp://127.0.0.1:45897/test audio-sink=fakesink sync=true video-sink=fakesink sync=true qos=true max-lateness=20000000 --set-media-info /home/thiblahute/gst-validate/gst-integration-testsuites/medias/defaults/webm/vorbis_vp8.1.webm.media_info'
=================


=========================================
Running scenario change_state_intensive on pipeline playbin0
=========================================
Starting pipeline
Prerolling...
Pipeline started
Executing (40/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.396170150)
Executing (39/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.386018905)
Executing (38/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.370561907)
Executing (37/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.379416772)
Executing (36/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.372735544)
Executing (35/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.375469067)
Executing (34/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.372242035)
Executing (33/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.379282019)
Executing (32/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.384176014)
Executing (31/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.376992469)
Executing (30/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.380841170)
Executing (29/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.370176525)
Executing (28/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.375556683)
Executing (27/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.372499633)
Executing (26/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.384619616)
Executing (25/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.376216970)
Executing (24/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.377693217)
Executing (23/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.376284539)
Executing (22/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.374066716)
Executing (21/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.377430032)
Executing (20/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.382110615)
Executing (19/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.370325036)
Executing (18/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.379305769)
Executing (17/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.377927701)
Executing (16/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.380539763)
Executing (15/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.379554751)
Executing (14/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.374322413)
Executing (13/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
  -> Action set-state done (duration: 0:00:00.376795187)
Executing (12/40) set-state: state=null repeat=40 
Executing (subaction) set-state: state=playing 
0:00:30.821920623 [332m14101[00m 0x561af013d230 [31;01mERROR  [00m [00m            validate gst-validate-reporter.c:195:gst_validate_report_valist:[00m <playbin0> 2258 (critical) : runtime: We got an ERROR message on the bus : Got error: Could not read from resource. -- Debug message: ../subprojects/gst-plugins-good/gst/rtsp/gstrtspsrc.c(5449): gst_rtspsrc_try_send (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin29/GstRTSPSrc:source:
Could not receive message. (Timeout while waiting for server response)
0:00:30.822518919 [332m14101[00m 0x561af00cda40 [31;01mERROR  [00m [00;33m gstvalidatescenario gst-validate-scenario.c:2700:message_cb:[00m Actions: 
                    set-state, state=(string)null, sub-action=(string)"set-state\,\ state\=playing", repeat=(int)40;
0:00:30.842309778 [332m14101[00m 0x561af00cda40 [31;01mERROR  [00m [00m            validate gst-validate-reporter.c:195:gst_validate_report_valist:[00m <change_state_intensive> 2261 (critical) : scenario: The program stopped before some actions were executed : 1 actions were not executed: 
                    set-state, state=(string)null, sub-action=(string)"set-state\,\ state\=playing", repeat=(int)40;
Executing  stop: 
   warning : received the same caps twice
             Detected on <rtpvp8depay0:sink>
             Detected on <vp8dec0:sink>
             Detected on <vorbisdec0:sink>
             Detected on <rtpvorbisdepay0:sink>
             Detected on <rtpvp8depay1:sink>
             Detected on <vp8dec1:sink>
             Detected on <vorbisdec1:sink>
             Detected on <rtpvorbisdepay1:sink>
             Detected on <rtpvp8depay2:sink>
             Detected on <vp8dec2:sink>
             Detected on <vorbisdec2:sink>
             Detected on <rtpvorbisdepay2:sink>
             Detected on <rtpvp8depay3:sink>
             Detected on <vp8dec3:sink>
             Detected on <vorbisdec3:sink>
             Detected on <rtpvorbisdepay3:sink>
             Detected on <rtpvp8depay4:sink>
             Detected on <vp8dec4:sink>
             Detected on <vorbisdec4:sink>
             Detected on <rtpvorbisdepay4:sink>
             Detected on <rtpvp8depay5:sink>
             Detected on <vp8dec5:sink>
             Detected on <vorbisdec5:sink>
             Detected on <rtpvorbisdepay5:sink>
             Detected on <rtpvp8depay6:sink>
             Detected on <vp8dec6:sink>
             Detected on <vorbisdec6:sink>
             Detected on <rtpvorbisdepay6:sink>
             Detected on <rtpvp8depay7:sink>
             Detected on <vp8dec7:sink>
             Detected on <vorbisdec7:sink>
             Detected on <rtpvorbisdepay7:sink>
             Detected on <rtpvp8depay8:sink>
             Detected on <vp8dec8:sink>
             Detected on <vorbisdec8:sink>
             Detected on <rtpvorbisdepay8:sink>
             Detected on <rtpvp8depay9:sink>
             Detected on <vp8dec9:sink>
             Detected on <vorbisdec9:sink>
             Detected on <rtpvorbisdepay9:sink>
             Detected on <rtpvp8depay10:sink>
             Detected on <vp8dec10:sink>
             Detected on <vorbisdec10:sink>
             Detected on <rtpvorbisdepay10:sink>
             Detected on <rtpvp8depay11:sink>
             Detected on <vp8dec11:sink>
             Detected on <vorbisdec11:sink>
             Detected on <rtpvorbisdepay11:sink>
             Detected on <rtpvp8depay12:sink>
             Detected on <vp8dec12:sink>
             Detected on <vorbisdec12:sink>
             Detected on <rtpvorbisdepay12:sink>
             Detected on <rtpvp8depay13:sink>
             Detected on <vp8dec13:sink>
             Detected on <vorbisdec13:sink>
             Detected on <rtpvorbisdepay13:sink>
             Detected on <rtpvp8depay14:sink>
             Detected on <vp8dec14:sink>
             Detected on <vorbisdec14:sink>
             Detected on <rtpvorbisdepay14:sink>
             Detected on <rtpvp8depay15:sink>
             Detected on <vp8dec15:sink>
             Detected on <vorbisdec15:sink>
             Detected on <rtpvorbisdepay15:sink>
             Detected on <rtpvp8depay16:sink>
             Detected on <vp8dec16:sink>
             Detected on <vorbisdec16:sink>
             Detected on <rtpvorbisdepay16:sink>
             Detected on <rtpvp8depay17:sink>
             Detected on <vp8dec17:sink>
             Detected on <vorbisdec17:sink>
             Detected on <rtpvorbisdepay17:sink>
             Detected on <rtpvp8depay18:sink>
             Detected on <vp8dec18:sink>
             Detected on <vorbisdec18:sink>
             Detected on <rtpvorbisdepay18:sink>
             Detected on <rtpvp8depay19:sink>
             Detected on <vp8dec19:sink>
             Detected on <vorbisdec19:sink>
             Detected on <rtpvorbisdepay19:sink>
             Detected on <rtpvp8depay20:sink>
             Detected on <vp8dec20:sink>
             Detected on <vorbisdec20:sink>
             Detected on <rtpvorbisdepay20:sink>
             Detected on <rtpvp8depay21:sink>
             Detected on <vp8dec21:sink>
             Detected on <vorbisdec21:sink>
             Detected on <rtpvorbisdepay21:sink>
             Detected on <rtpvp8depay22:sink>
             Detected on <vp8dec22:sink>
             Detected on <vorbisdec22:sink>
             Detected on <rtpvorbisdepay22:sink>
             Detected on <rtpvp8depay23:sink>
             Detected on <vp8dec23:sink>
             Detected on <vorbisdec23:sink>
             Detected on <rtpvorbisdepay23:sink>
             Detected on <rtpvp8depay24:sink>
             Detected on <vp8dec24:sink>
             Detected on <vorbisdec24:sink>
             Detected on <rtpvorbisdepay24:sink>
             Detected on <rtpvp8depay25:sink>
             Detected on <vp8dec25:sink>
             Detected on <vorbisdec25:sink>
             Detected on <rtpvorbisdepay25:sink>
             Detected on <rtpvp8depay26:sink>
             Detected on <vp8dec26:sink>
             Detected on <vorbisdec26:sink>
             Detected on <rtpvorbisdepay26:sink>
             Detected on <rtpvp8depay27:sink>
             Detected on <vp8dec27:sink>
             Detected on <vorbisdec27:sink>
             Detected on <rtpvorbisdepay27:sink>

   warning : a new segment event has different value than the received one
             Detected on <rtpvp8depay0:src>
             Detected on <rtpvorbisdepay0:src>
             Detected on <rtpvp8depay1:src>
             Detected on <rtpvorbisdepay1:src>
             Detected on <rtpvp8depay2:src>
             Detected on <rtpvorbisdepay2:src>
             Detected on <rtpvp8depay3:src>
             Detected on <rtpvorbisdepay3:src>
             Detected on <rtpvp8depay4:src>
             Detected on <rtpvorbisdepay4:src>
             Detected on <rtpvp8depay5:src>
             Detected on <rtpvorbisdepay5:src>
             Detected on <rtpvp8depay6:src>
             Detected on <rtpvorbisdepay6:src>
             Detected on <rtpvp8depay7:src>
             Detected on <rtpvorbisdepay7:src>
             Detected on <rtpvp8depay8:src>
             Detected on <rtpvorbisdepay8:src>
             Detected on <rtpvp8depay9:src>
             Detected on <rtpvorbisdepay9:src>
             Detected on <rtpvp8depay10:src>
             Detected on <rtpvorbisdepay10:src>
             Detected on <rtpvp8depay11:src>
             Detected on <rtpvorbisdepay11:src>
             Detected on <rtpvp8depay12:src>
             Detected on <rtpvorbisdepay12:src>
             Detected on <rtpvp8depay13:src>
             Detected on <rtpvorbisdepay13:src>
             Detected on <rtpvp8depay14:src>
             Detected on <rtpvorbisdepay14:src>
             Detected on <rtpvp8depay15:src>
             Detected on <rtpvorbisdepay15:src>
             Detected on <rtpvp8depay16:src>
             Detected on <rtpvorbisdepay16:src>
             Detected on <rtpvp8depay17:src>
             Detected on <rtpvorbisdepay17:src>
             Detected on <rtpvp8depay18:src>
             Detected on <rtpvorbisdepay18:src>
             Detected on <rtpvp8depay19:src>
             Detected on <rtpvorbisdepay19:src>
             Detected on <rtpvp8depay20:src>
             Detected on <rtpvorbisdepay20:src>
             Detected on <rtpvp8depay21:src>
             Detected on <rtpvorbisdepay21:src>
             Detected on <rtpvp8depay22:src>
             Detected on <rtpvorbisdepay22:src>
             Detected on <rtpvp8depay23:src>
             Detected on <rtpvorbisdepay23:src>
             Detected on <rtpvp8depay24:src>
             Detected on <rtpvorbisdepay24:src>
             Detected on <rtpvp8depay25:src>
             Detected on <rtpvorbisdepay25:src>
             Detected on <rtpvp8depay26:src>
             Detected on <rtpvorbisdepay26:src>
             Detected on <rtpvp8depay27:src>
             Detected on <rtpvorbisdepay27:src>
             Description : when receiving a new segment, an element should push an equivalentsegment downstream

  critical : We got an ERROR message on the bus
             Detected on <playbin0>
             Details : Got error: Could not read from resource. -- Debug message: ../subprojects/gst-plugins-good/gst/rtsp/gstrtspsrc.c(5449): gst_rtspsrc_try_send (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin29/GstRTSPSrc:source:
                     Could not receive message. (Timeout while waiting for server response)
             dotfile : /home/thiblahute/.cache/gstmkdump//0:00:30.802809687-validate-report-critical-on-playbin0-runtime::error-on-bus.dot
             backtrace :
               gst_debug_get_stack_trace (gstinfo.c:2787)
               gst_validate_report_new (gst-validate-report.c:710)
               gst_validate_report_valist (gst-validate-reporter.c:186)
               gst_validate_report (gst-validate-reporter.c:301)
               _bus_handler (gst-validate-pipeline-monitor.c:503)
               ffi_call_unix64 (/usr/lib/libffi.so.6.0.4:0x7fa294a0a1c4)
               ffi_call (/usr/lib/libffi.so.6.0.4:0x7fa294a09c26)
               g_cclosure_marshal_generic (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967cd7aa)
               g_closure_invoke (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967ccecb)
               ?? (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967def7e)
               g_signal_emit_valist (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967e7bd8)
               g_signal_emit (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967e7fbb)
               gst_bus_sync_signal_handler (gstbus.c:1274)
               gst_bus_post (gstbus.c:342)
               gst_element_post_message_default (gstelement.c:1789)
               gst_bin_post_message (gstbin.c:2856)
               gst_element_post_message (gstelement.c:1832)
               gst_bin_handle_message_func (gstbin.c:4107)
               gst_pipeline_handle_message (gstpipeline.c:600)
               gst_play_bin_handle_message (gstplaybin2.c:3012)
               bin_bus_handler (gstbin.c:3327)
               gst_bus_post (gstbus.c:336)
               gst_element_post_message_default (gstelement.c:1789)
               gst_bin_post_message (gstbin.c:2856)
               gst_element_post_message (gstelement.c:1832)
               gst_bin_handle_message_func (gstbin.c:4107)
               handle_message (gsturidecodebin.c:2438)
               bin_bus_handler (gstbin.c:3327)
               gst_bus_post (gstbus.c:336)
               gst_element_post_message_default (gstelement.c:1789)
               gst_bin_post_message (gstbin.c:2856)
               gst_element_post_message (gstelement.c:1832)
               gst_element_message_full_with_details (gstelement.c:1968)
               gst_element_message_full (gstelement.c:2007)
               gst_rtspsrc_try_send (gstrtspsrc.c:5448)
               gst_rtspsrc_send (gstrtspsrc.c:5520)
               gst_rtspsrc_retrieve_sdp (gstrtspsrc.c:6684)
               gst_rtspsrc_open (gstrtspsrc.c:6823)
               gst_rtspsrc_thread (gstrtspsrc.c:7616)
               gst_task_func (gsttask.c:332)
               default_func (gsttaskpool.c:69)
               ?? (/usr/lib/libglib-2.0.so.0.5200.2:0x7fa296a81c8a)
               ?? (/usr/lib/libglib-2.0.so.0.5200.2:0x7fa296a81291)
               start_thread (/usr/lib/libpthread-2.25.so:0x7fa296211293)
               __clone (/usr/lib/libc-2.25.so:0x7fa295f5225b)
               

  critical : The program stopped before some actions were executed
             Detected on <change_state_intensive>
             Details : 1 actions were not executed: 
                                         set-state, state=(string)null, sub-action=(string)"set-state\,\ state\=playing", repeat=(int)40;
             dotfile : /home/thiblahute/.cache/gstmkdump//0:00:30.823199351-validate-report-critical-on-change_state_intensive-scenario::not-ended.dot
             backtrace :
               gst_debug_get_stack_trace (gstinfo.c:2787)
               gst_validate_report_new (gst-validate-report.c:710)
               gst_validate_report_valist (gst-validate-reporter.c:186)
               gst_validate_report (gst-validate-reporter.c:301)
               message_cb (gst-validate-scenario.c:2702)
               ffi_call_unix64 (/usr/lib/libffi.so.6.0.4:0x7fa294a0a1c4)
               ffi_call (/usr/lib/libffi.so.6.0.4:0x7fa294a09c26)
               g_cclosure_marshal_generic (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967cd7aa)
               g_closure_invoke (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967ccf71)
               ?? (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967def7e)
               g_signal_emit_valist (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967e7bd8)
               g_signal_emit (/usr/lib/libgobject-2.0.so.0.5200.2:0x7fa2967e7fbb)
               gst_bus_async_signal_func (gstbus.c:1247)
               gst_bus_source_dispatch (gstbus.c:841)
               g_main_context_dispatch (/usr/lib/libglib-2.0.so.0.5200.2:0x7fa296a59666)
               ?? (/usr/lib/libglib-2.0.so.0.5200.2:0x7fa296a59a1c)
               g_main_loop_run (/usr/lib/libglib-2.0.so.0.5200.2:0x7fa296a59d3e)
               main (gst-validate.c:509)
               __libc_start_main (/usr/lib/libc-2.25.so:0x7fa295e85436)
               _start (/home/thiblahute/devel/gstreamer/gst-build/build/subprojects/gst-devtools/validate/tools/gst-validate-1.0:0x561aee96f716)
               



==== Got criticals. Return value set to 18 ====
     Critical error Got error: Could not read from resource. -- Debug message: ../subprojects/gst-plugins-good/gst/rtsp/gstrtspsrc.c(5449): gst_rtspsrc_try_send (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin29/GstRTSPSrc:source:
Could not receive message. (Timeout while waiting for server response)
     Critical error 1 actions were not executed: 
                    set-state, state=(string)null, sub-action=(string)"set-state\,\ state\=playing", repeat=(int)40;

Issues found: 4
Returning 18 as errors were found

=======> Test FAILED (Return value: 18)