GNOME Bugzilla – Bug 764905
rtspsrc stops playback after a while
Last modified: 2016-10-31 16:00:55 UTC
I encounter odd behaviour with rtspsrc. I have Gst-backed RTSP server that encodes opus audio stream and rtspsrc on the other side that tries to play it back. Generally speaking it works fine but it just stops playback after some time (5-10 min) with no error, warning, message etc. (I am logging everything that appears on the pipeline's bus). When I restart the receiver pipeline it just starts to work again so I assume that problem is on the receiver side. If sometimes happen that two identical receivers are connected to the same mount of the same RTSP server and while one is silent, another plays back, so I assume that RTSP server is sending data correctky. The receiver's pipeline is rtspsrc location=rtsp://.... user-agent=... drop-on-latency=true latency=500 tls-database=... protocols=... username=... password=... ! decodebin ! audioconvert ! audioresample ! queue2 ! openslessink (protocols are 0x00000001 | 0x00000002 | 0x00000004 | 0x00000010 | 0x00000020) I am using 1.8.0 on both sides. I am not sure if this is related but during playback on Android I ocassionally get 04-11 16:38:41.989 21543 21629 W GStreamer+audiobasesink: 0:04:35.920673280 0xb8e045b0 gstaudiobasesink.c:1484:gst_audio_base_sink_skew_slaving:<audio_interface_playback> correct clock skew +0:00:00.020063566 > +0:00:00.020000000 04-11 16:38:42.006 21543 21629 W GStreamer+audiobasesink: 0:04:35.938068176 0xb8e045b0 gstaudiobasesink.c:1512:gst_audio_base_sink_skew_slaving:<audio_interface_playback> correct clock skew -0:00:00.020290466 < -+0:00:00.020000000 I have managed to reproduce the issue on Mac OS X. I've used gst-launch -m -vv to run identical pipeline and the only output was /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0/GstRtpBin:manager/GstRtpSession:rtpsession0: stats = "application/x-rtp-session-stats\,\ rtx-drop-count\=\(uint\)0\,\ sent-nack-count\=\(uint\)0\,\ recv-nack-count\=\(uint\)0\,\ source-stats\=\(GValueArray\)NULL\,\ rtx-count\=\(uint\)0\;" (repeated many times) and it kept appearing even when audio was not playing. I have run it with GST_DEBUG=*:4,rtspsrc:5,opus:5 and there were no messages prior to hanging. I've added level element to the pipeline to see whether it emits anything when audio stops playing. As I anticipated, level stops emitting messages when audio stops playing.
Can you get a full debug log with level 6? Also check with gdb what all threads are doing while nothing is happening anymore.
(lldb) attach -p 54598 Process 54598 stopped * thread #1: tid = 0x24bd3c, 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP frame #0: 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10 libsystem_kernel.dylib`mach_msg_trap: -> 0x7fff91cf7386 <+10>: retq 0x7fff91cf7387 <+11>: nop libsystem_kernel.dylib`mach_msg_overwrite_trap: 0x7fff91cf7388 <+0>: movq %rcx, %r10 0x7fff91cf738b <+3>: movl $0x1000020, %eax Executable module set to "/Library/Frameworks/GStreamer.framework/Versions/1.0/Commands/gst-launch-1.0". Architecture set to: x86_64-apple-macosx. (lldb) bt all * thread #1: tid = 0x24bd3c, 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP * frame #0: 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10 frame #1: 0x00007fff91cf67c7 libsystem_kernel.dylib`mach_msg + 55 frame #2: 0x00007fff9bab4624 CoreFoundation`__CFRunLoopServiceMachPort + 212 frame #3: 0x00007fff9bab3aec CoreFoundation`__CFRunLoopRun + 1356 frame #4: 0x00007fff9bab3338 CoreFoundation`CFRunLoopRunSpecific + 296 frame #5: 0x00007fff9e3c0935 HIToolbox`RunCurrentEventLoopInMode + 235 frame #6: 0x00007fff9e3c076f HIToolbox`ReceiveNextEventCommon + 432 frame #7: 0x00007fff9e3c05af HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 71 frame #8: 0x00007fff8fd500ee AppKit`_DPSNextEvent + 1067 frame #9: 0x00007fff9011c943 AppKit`-[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 454 frame #10: 0x000000010e00ac23 libglib-2.0.0.dylib`cocoa_poll_func + 179 frame #11: 0x000000010e00bc9d libglib-2.0.0.dylib`g_main_context_iterate + 333 frame #12: 0x000000010e00c01f libglib-2.0.0.dylib`g_main_loop_run + 223 frame #13: 0x000000010ddfc95e libgstreamer-1.0.0.dylib`gst_bus_poll + 286 frame #14: 0x000000010ddd6004 gst-launch-1.0`event_loop + 3412 frame #15: 0x000000010ddd4cfa gst-launch-1.0`main + 2010 frame #16: 0x00007fff987d25ad libdyld.dylib`start + 1 frame #17: 0x00007fff987d25ad libdyld.dylib`start + 1 thread #2: tid = 0x24bd4a, 0x00007fff91cfdff6 libsystem_kernel.dylib`kevent_qos + 10, queue = 'com.apple.libdispatch-manager' frame #0: 0x00007fff91cfdff6 libsystem_kernel.dylib`kevent_qos + 10 frame #1: 0x00007fff9a4b7099 libdispatch.dylib`_dispatch_mgr_invoke + 216 frame #2: 0x00007fff9a4b6d01 libdispatch.dylib`_dispatch_mgr_thread + 52 thread #3: tid = 0x24bd64, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'queue2-0:src' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010e05308f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x000000010eb87742 libgstcoreelements.so`gst_queue2_loop + 866 frame #4: 0x000000010de5e5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #5: 0x000000010e0343c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #6: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #4: tid = 0x24bd65, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'task0' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010e01a0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x000000010e5285ea libgio-2.0.0.dylib`g_socket_condition_timed_wait + 362 frame #3: 0x000000010e5270a7 libgio-2.0.0.dylib`g_socket_receive_with_blocking + 359 frame #4: 0x000000010e50bfef libgio-2.0.0.dylib`g_input_stream_read + 207 frame #5: 0x000000010e3f3469 libgstrtsp-1.0.0.dylib`fill_raw_bytes + 89 frame #6: 0x000000010e3eff84 libgstrtsp-1.0.0.dylib`read_bytes + 292 frame #7: 0x000000010e3f0728 libgstrtsp-1.0.0.dylib`build_next + 1144 frame #8: 0x000000010e3f015d libgstrtsp-1.0.0.dylib`gst_rtsp_connection_receive + 173 frame #9: 0x000000010e3c5503 libgstrtsp.so`gst_rtspsrc_thread + 435 frame #10: 0x000000010de5e5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #11: 0x000000010e0343c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #12: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #13: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #14: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #15: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #5: tid = 0x24bd66, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'gmain' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010e01a0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x000000010e00bc9d libglib-2.0.0.dylib`g_main_context_iterate + 333 frame #3: 0x000000010e00bd84 libglib-2.0.0.dylib`g_main_context_iteration + 100 frame #4: 0x000000010e00d5c6 libglib-2.0.0.dylib`glib_worker_main + 54 frame #5: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #6: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #7: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #8: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #6: tid = 0x24bd6c, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'CocoaSelectThread' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010e01a0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x000000010e00dbea libglib-2.0.0.dylib`cocoa_select_thread_func + 122 frame #3: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #4: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #5: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #6: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #7: tid = 0x24bd7f, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'rtpjitterbuffer0:src' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010e05308f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x000000011141188a libgstrtpmanager.so`gst_rtp_jitter_buffer_loop + 330 frame #4: 0x000000010de5e5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #5: 0x000000010e0343c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #6: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #8: tid = 0x24bda8, 0x00007fff91cfce3a libsystem_kernel.dylib`__pselect + 10, name = 'rtpsession-rtcp-thread' frame #0: 0x00007fff91cfce3a libsystem_kernel.dylib`__pselect + 10 frame #1: 0x00007fff91cfa51f libsystem_kernel.dylib`pselect$1050 + 82 frame #2: 0x000000010de3fe6f libgstreamer-1.0.0.dylib`gst_poll_wait + 1231 frame #3: 0x000000010de57da6 libgstreamer-1.0.0.dylib`gst_system_clock_id_wait_jitter_unlocked + 774 frame #4: 0x000000010de04f81 libgstreamer-1.0.0.dylib`gst_clock_id_wait + 97 frame #5: 0x0000000111434579 libgstrtpmanager.so`rtcp_thread + 409 frame #6: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #9: tid = 0x24bda9, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'timer' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010e05308f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x0000000111415ab1 libgstrtpmanager.so`wait_next_timeout + 6385 frame #4: 0x000000010e03344a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #5: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #6: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #7: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #10: tid = 0x24bdac, 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.audio.IOThread.client' frame #0: 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10 frame #1: 0x00007fff91cf67c7 libsystem_kernel.dylib`mach_msg + 55 frame #2: 0x00007fff8a6405ee CoreAudio`HALB_MachPort::SendMessageWithReply(unsigned int, unsigned int, unsigned int, unsigned int, mach_msg_header_t*, bool, unsigned int) + 98 frame #3: 0x00007fff8a64057c CoreAudio`HALB_MachPort::SendSimpleMessageWithSimpleReply(unsigned int, unsigned int, int, int&, bool, unsigned int) + 42 frame #4: 0x00007fff8a63e939 CoreAudio`HALC_ProxyIOContext::IOWorkLoop() + 1149 frame #5: 0x00007fff8a63e3ee CoreAudio`HALC_ProxyIOContext::IOThreadEntry(void*) + 88 frame #6: 0x00007fff8a63e2c3 CoreAudio`HALB_IOThread::Entry(void*) + 75 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 Log is coming soon.
Here is the link to the full log with GST_DEBUG=*:6: https://pub.radiokit.org/gstbug764905/log6.txt.gz I have also noticed that just before stopping the audio becomes distorted for a few seconds, and then it disappears but regular glitches (such as chk chk chk for a few seconds) are heard, and then silence. I will try to record this. More info about test case: I am using Opus for transmitting audio with PLC and FEC. On Android I use GStreamer 1.8.0 built via cerber, except bumping Opus to the most recent version. On Mac OS X I use plain GStreamer 1.8.0 from official builds so Opus is slightly older and the same happens. On the server side I use GStreamer 1.8.0 (built manually) but underlying libraries come from plain Ubuntu 14.04 so they may be slightly outdated.
That could mean that the audio sink ringbuffer underruns and never fills up again, continuing to output silence because the decoded output doesn't catch up. (didn't look at the log yet)
I have tried to revert to 1.6.3 on the client side and it plays silence all the time, despite RTSP being connected. Can audiorate help with potential issues with buffer underrun so it will always output perfect stream to the sink?
If my guess about the problem is correct, no. That should be checked from the logs first though before trying anything else. Check if the ringbuffer runs empty and stays behind.
Antother stack trace: (lldb) attach -p 57147 Process 57147 stopped * thread #1: tid = 0x25d1dd, 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP frame #0: 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10 libsystem_kernel.dylib`mach_msg_trap: -> 0x7fff91cf7386 <+10>: retq 0x7fff91cf7387 <+11>: nop libsystem_kernel.dylib`mach_msg_overwrite_trap: 0x7fff91cf7388 <+0>: movq %rcx, %r10 0x7fff91cf738b <+3>: movl $0x1000020, %eax Executable module set to "/Library/Frameworks/GStreamer.framework/Versions/1.0/Commands/gst-launch-1.0". Architecture set to: x86_64-apple-macosx. (lldb) bt all * thread #1: tid = 0x25d1dd, 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP * frame #0: 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10 frame #1: 0x00007fff91cf67c7 libsystem_kernel.dylib`mach_msg + 55 frame #2: 0x00007fff9bab4624 CoreFoundation`__CFRunLoopServiceMachPort + 212 frame #3: 0x00007fff9bab3aec CoreFoundation`__CFRunLoopRun + 1356 frame #4: 0x00007fff9bab3338 CoreFoundation`CFRunLoopRunSpecific + 296 frame #5: 0x00007fff9e3c0935 HIToolbox`RunCurrentEventLoopInMode + 235 frame #6: 0x00007fff9e3c076f HIToolbox`ReceiveNextEventCommon + 432 frame #7: 0x00007fff9e3c05af HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter + 71 frame #8: 0x00007fff8fd500ee AppKit`_DPSNextEvent + 1067 frame #9: 0x00007fff9011c943 AppKit`-[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 454 frame #10: 0x00000001005fec23 libglib-2.0.0.dylib`cocoa_poll_func + 179 frame #11: 0x00000001005ffc9d libglib-2.0.0.dylib`g_main_context_iterate + 333 frame #12: 0x000000010060001f libglib-2.0.0.dylib`g_main_loop_run + 223 frame #13: 0x00000001003f995e libgstreamer-1.0.0.dylib`gst_bus_poll + 286 frame #14: 0x00000001003d5004 gst-launch-1.0`event_loop + 3412 frame #15: 0x00000001003d3cfa gst-launch-1.0`main + 2010 frame #16: 0x00007fff987d25ad libdyld.dylib`start + 1 thread #2: tid = 0x25d1e0, 0x00007fff91cfdff6 libsystem_kernel.dylib`kevent_qos + 10, queue = 'com.apple.libdispatch-manager' frame #0: 0x00007fff91cfdff6 libsystem_kernel.dylib`kevent_qos + 10 frame #1: 0x00007fff9a4b7099 libdispatch.dylib`_dispatch_mgr_invoke + 216 frame #2: 0x00007fff9a4b6d01 libdispatch.dylib`_dispatch_mgr_thread + 52 thread #3: tid = 0x25d1fb, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'queue2-0:src' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010064708f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x0000000101179742 libgstcoreelements.so`gst_queue2_loop + 866 frame #4: 0x000000010045b5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #5: 0x00000001006283c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #6: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #4: tid = 0x25d1fc, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'task0' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010060e0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x0000000100b1a5ea libgio-2.0.0.dylib`g_socket_condition_timed_wait + 362 frame #3: 0x0000000100b190a7 libgio-2.0.0.dylib`g_socket_receive_with_blocking + 359 frame #4: 0x0000000100afdfef libgio-2.0.0.dylib`g_input_stream_read + 207 frame #5: 0x00000001009e5469 libgstrtsp-1.0.0.dylib`fill_raw_bytes + 89 frame #6: 0x00000001009e1f84 libgstrtsp-1.0.0.dylib`read_bytes + 292 frame #7: 0x00000001009e2728 libgstrtsp-1.0.0.dylib`build_next + 1144 frame #8: 0x00000001009e215d libgstrtsp-1.0.0.dylib`gst_rtsp_connection_receive + 173 frame #9: 0x00000001009b7aa2 libgstrtsp.so`gst_rtspsrc_thread + 1874 frame #10: 0x000000010045b5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #11: 0x00000001006283c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #12: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #13: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #14: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #15: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #5: tid = 0x25d1fd, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'gmain' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010060e0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x00000001005ffc9d libglib-2.0.0.dylib`g_main_context_iterate + 333 frame #3: 0x00000001005ffd84 libglib-2.0.0.dylib`g_main_context_iteration + 100 frame #4: 0x00000001006015c6 libglib-2.0.0.dylib`glib_worker_main + 54 frame #5: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #6: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #7: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #8: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #6: tid = 0x25d201, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'CocoaSelectThread' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010060e0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x0000000100601bea libglib-2.0.0.dylib`cocoa_select_thread_func + 122 frame #3: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #4: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #5: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #6: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #7: tid = 0x25d205, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'fakesrc0:src' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010064708f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x000000010045b5d5 libgstreamer-1.0.0.dylib`gst_task_func + 389 frame #4: 0x00000001006283c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #5: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #6: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #7: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #8: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #8: tid = 0x25d206, 0x00007fff91cfce3a libsystem_kernel.dylib`__pselect + 10, name = 'rtpsession-rtcp-thread' frame #0: 0x00007fff91cfce3a libsystem_kernel.dylib`__pselect + 10 frame #1: 0x00007fff91cfa51f libsystem_kernel.dylib`pselect$1050 + 82 frame #2: 0x000000010043ce6f libgstreamer-1.0.0.dylib`gst_poll_wait + 1231 frame #3: 0x0000000100454da6 libgstreamer-1.0.0.dylib`gst_system_clock_id_wait_jitter_unlocked + 774 frame #4: 0x0000000100401f81 libgstreamer-1.0.0.dylib`gst_clock_id_wait + 97 frame #5: 0x0000000103a38579 libgstrtpmanager.so`rtcp_thread + 409 frame #6: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #9: tid = 0x25d207, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'udpsrc1:src' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010060e0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x0000000100b1a5ea libgio-2.0.0.dylib`g_socket_condition_timed_wait + 362 frame #3: 0x00000001039ef8a6 libgstudp.so`gst_udpsrc_create + 486 frame #4: 0x0000000100a83cac libgstbase-1.0.0.dylib`gst_base_src_get_range + 380 frame #5: 0x0000000100a833d4 libgstbase-1.0.0.dylib`gst_base_src_loop + 1684 frame #6: 0x000000010045b5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #7: 0x00000001006283c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #8: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #9: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #10: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #11: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #10: tid = 0x25d208, 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10, name = 'udpsrc2:src' frame #0: 0x00007fff91cfd176 libsystem_kernel.dylib`__select + 10 frame #1: 0x000000010060e0fa libglib-2.0.0.dylib`g_poll + 410 frame #2: 0x0000000100b1a5ea libgio-2.0.0.dylib`g_socket_condition_timed_wait + 362 frame #3: 0x00000001039ef8a6 libgstudp.so`gst_udpsrc_create + 486 frame #4: 0x0000000100a83cac libgstbase-1.0.0.dylib`gst_base_src_get_range + 380 frame #5: 0x0000000100a833d4 libgstbase-1.0.0.dylib`gst_base_src_loop + 1684 frame #6: 0x000000010045b5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #7: 0x00000001006283c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #8: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #9: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #10: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #11: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #11: tid = 0x25d209, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'timer' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010064708f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x0000000103a19ab1 libgstrtpmanager.so`wait_next_timeout + 6385 frame #4: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #5: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #6: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #7: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #12: tid = 0x25d20a, 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'rtpjitterbuffer0:src' frame #0: 0x00007fff91cfceb2 libsystem_kernel.dylib`__psynch_cvwait + 10 frame #1: 0x00007fff91935150 libsystem_pthread.dylib`_pthread_cond_wait + 767 frame #2: 0x000000010064708f libglib-2.0.0.dylib`g_cond_wait + 47 frame #3: 0x0000000103a1588a libgstrtpmanager.so`gst_rtp_jitter_buffer_loop + 330 frame #4: 0x000000010045b5a3 libgstreamer-1.0.0.dylib`gst_task_func + 339 frame #5: 0x00000001006283c2 libglib-2.0.0.dylib`g_thread_pool_thread_proxy + 50 frame #6: 0x000000010062744a libglib-2.0.0.dylib`g_thread_proxy + 90 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13 thread #13: tid = 0x25d220, 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.audio.IOThread.client' frame #0: 0x00007fff91cf7386 libsystem_kernel.dylib`mach_msg_trap + 10 frame #1: 0x00007fff91cf67c7 libsystem_kernel.dylib`mach_msg + 55 frame #2: 0x00007fff8a6405ee CoreAudio`HALB_MachPort::SendMessageWithReply(unsigned int, unsigned int, unsigned int, unsigned int, mach_msg_header_t*, bool, unsigned int) + 98 frame #3: 0x00007fff8a64057c CoreAudio`HALB_MachPort::SendSimpleMessageWithSimpleReply(unsigned int, unsigned int, int, int&, bool, unsigned int) + 42 frame #4: 0x00007fff8a63e939 CoreAudio`HALC_ProxyIOContext::IOWorkLoop() + 1149 frame #5: 0x00007fff8a63e3ee CoreAudio`HALC_ProxyIOContext::IOThreadEntry(void*) + 88 frame #6: 0x00007fff8a63e2c3 CoreAudio`HALB_IOThread::Entry(void*) + 75 frame #7: 0x00007fff91934c13 libsystem_pthread.dylib`_pthread_body + 131 frame #8: 0x00007fff91934b90 libsystem_pthread.dylib`_pthread_start + 168 frame #9: 0x00007fff91932375 libsystem_pthread.dylib`thread_start + 13
I have found another pattern. I can't say whether this behaviour is justified or not, but I prefer to share. When playback stops to occur, messages from level stop being emitted. rtspsession however keeps posting such message once per second: /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0/GstRtpBin:manager/GstRtpSession:rtpsession0: stats = "application/x-rtp-session-stats\,\ rtx-drop-count\=\(uint\)0\,\ sent-nack-count\=\(uint\)0\,\ recv-nack-count\=\(uint\)0\,\ source-stats\=\(GValueArray\)NULL\,\ rtx-count\=\(uint\)0\;" If then I attach debugger and keep it attached for a while (+/- minute or more) once I detach, the EOS is emitted: Got message #3223 from element "level0" (element): level, endtime=(guint64)300040000000, timestamp=(guint64)300019433997, stream-time=(guint64)300000000000, running-time=(guint64)300019433997, duration=(guint64)40000000, rms=(GValueArray)NULL, peak=(GValueArray)NULL, decay=(GValueArray)NULL; /GstPipeline:pipeline0/GstRTSPSrc:rtspsrc0/GstRtpBin:manager/GstRtpSession:rtpsession0: stats = "application/x-rtp-session-stats\,\ rtx-drop-count\=\(uint\)0\,\ sent-nack-count\=\(uint\)0\,\ recv-nack-count\=\(uint\)0\,\ source-stats\=\(GValueArray\)NULL\,\ rtx-count\=\(uint\)0\;" Got message #3221 from element "pipeline0" (eos): no message details Got EOS from element "pipeline0". Execution ended after 0:09:10.356259000 Setting pipeline to PAUSED ... Setting pipeline to READY ... Setting pipeline to NULL ... Freeing pipeline ... If I don't attach the debugger or attach it for very short time the pipeline remains hanged forever.
This log report may be more meaningful https://pub.radiokit.org/gstbug764905/log6-2.txt.xz The last message from level is at line 3420081 so probably interesting stuff happens afterwards.
As far as I can understand the logs it blocks on select call in udpsrc. This is the last call after which the only messages in the log come from sink's ringbuffer. 0:05:06.860973000 57676 0x7fd54b12a400 LOG udpsrc gstudpsrc.c:538:gst_udpsrc_create:<udpsrc1> doing select, timeout -1 0:05:06.868756000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 0 (real 30520) @0x7fd54b840c00 0:05:06.868806000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1931:gst_audio_ring_buffer_clear:<osxaudioringbuffer0> clear segment 0 @0x7fd54b840c00 0:05:06.868823000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 1 (real 30521) @0x7fd54b841380 0:05:06.879379000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 1 (real 30521) @0x7fd54b841380 0:05:06.879450000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1931:gst_audio_ring_buffer_clear:<osxaudioringbuffer0> clear segment 1 @0x7fd54b841380 0:05:06.879479000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 2 (real 30522) @0x7fd54b841b00 0:05:06.890052000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 2 (real 30522) @0x7fd54b841b00 0:05:06.890102000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1931:gst_audio_ring_buffer_clear:<osxaudioringbuffer0> clear segment 2 @0x7fd54b841b00 0:05:06.890126000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 3 (real 30523) @0x7fd54b842280 0:05:06.900691000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 3 (real 30523) @0x7fd54b842280 0:05:06.900741000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1931:gst_audio_ring_buffer_clear:<osxaudioringbuffer0> clear segment 3 @0x7fd54b842280 0:05:06.900769000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 4 (real 30524) @0x7fd54b842a00 0:05:06.911386000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 4 (real 30524) @0x7fd54b842a00 0:05:06.911534000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1931:gst_audio_ring_buffer_clear:<osxaudioringbuffer0> clear segment 4 @0x7fd54b842a00 0:05:06.911590000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 5 (real 30525) @0x7fd54b843180 0:05:06.922052000 57676 0x7fd54ad33a70 LOG ringbuffer gstaudioringbuffer.c:1862:gst_audio_ring_buffer_prepare_read:<osxaudioringbuffer0> prepare read from segment 5 (real 30525) @0x7fd54b843180
Created attachment 325812 [details] Network dump
I have managed to capture network traffic with wireshark, the log is attached. It seems that UDP frames stop flowing at some point, and then RTCP ping-pong starts to happen. So there are actually two questions: why RTSP server stops sending UDP and why receiver does not post EOS.
Created attachment 325813 [details] Network dump
I have abandoned RTSP for that purpose so I am unable to contribute any more to this bug. I also provided all information I could. I think NEEDINFO is misleading.