Ringbuffer audio problem

[Alessio]

  Hi all

sorry for my bad english

     since I am writing a rtsp player that should be portable on linux,
mac and windows and the gstreamer rtspsrc module in windows doesn't
support rtscp tcp interleaved mode, I implemented my own rtsp plugin
based on live555 library.

I based my work on how both vlc and mplayer live555 based modules are made.

I've a src plugin that manages the network connection and reads the
frames one by one, and a demuxer plugin that receives that frames and
creates a src pad for each subsession, based on the standard behaviour
of gstreamer demuxers.

In the application I set up a basic pipeline based like that:

gst-launch livertsp uri=rtsp://127.0.0.1:8554/bighic320x240.avi !
livedemuxer name=demux  demux.audio_00 ! queue ! decodebin  !
audioconvert ! audioresample ! autoaudiosink   demux.video_00 ! queue !
decodebin ! ffmpegcolorspace ! videoscale ! autovideosink
--gst-debug=ringbuffer:5,basesink:5,baseaudiosink:5,audiosink:5

but only the video is played, not the audio.

Debugging the program it seems that the problem is in the ringbuffer
used by the audio sink:

The writer thread (default_commit function) starts to write a few
segments (three) in the buffer, than the reader thread
(audioringbuffer_thread_func thread)takes control of the buffer and
starts to read and play segment, but does not stop at the third segment
but goes on, until segment number seven, updating the segdone variable
at seven.

Than the writer founds that the segment to be wrote is the fourth and
the last read is the seventh, and checking that this difference is
negative (4 - 7), skip those segments.

Afterwards, the segdone variable is always bigger than the last written
segment, so each segment is dropped and nothing is played, except a
little chunk of audio at the very beginning of the stream (the first
three segments).

This happens exactly in the same way with the alsasink and pulsesink on
linux and with the directsoundsink on windows.

What can cause this?

This is an extract from the debug output.

................
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1322:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
time 0:00:00.000000000, offset 18446744073709551615, start
0:00:00.000000000, samples 1152
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1361:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
sync-offset 0, render-delay 0:00:00.000000000, ts-offset 0
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1423:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
running: start 0:00:00.000000000 - stop 0:00:00.026122448
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1437:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
compensating for sync-offset 0:00:00.000000000
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1442:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
adding base_time 0:00:00.000022014
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1450:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
after compensation: start 0:00:00.000022014 - stop 0:00:00.026144462
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:514:gst_base_audio_sink_get_time:<autoaudiosink0-actual-sink-directsound>
processed samples: raw 0, delay 0, real 0, time 0:00:00.000000000
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1004:gst_base_audio_sink_skew_slaving:<autoaudiosink0-actual-sink-directsound>
internal 0:00:00.000000000 external 0:00:00.172671612 cinternal
0:00:00.000000000 cexternal 0:00:00.167754169
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1024:gst_base_audio_sink_skew_slaving:<autoaudiosink0-actual-sink-directsound>
internal 0:00:00.000000000 external 0:00:00.004917443 skew -4917443 avg
-4917443
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1465:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
final timestamps: start 0:00:00.000000000 - stop 0:00:00.000000000
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1472:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
time offset 0:00:00.000000000
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1511:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
no align possible: no previous sample position known
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1562:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
rendering at 0 1152/1152
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 0, write to 0-0, diff 0,
segtotal 20, segsize 1764, base 0
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E01F30 seg 0, sps 441, off 0, avail 1764
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 1764 bytes
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 0, write to 1-0, diff 1,
segtotal 20, segsize 1764, base 0
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E02614 seg 1, sps 441, off 0, avail 1764
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 1764 bytes
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 0, write to 2-0, diff 2,
segtotal 20, segsize 1764, base 0
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E02CF8 seg 2, sps 441, off 0, avail 1080
0:00:02.154803000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 1080 bytes
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1572:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
wrote 1152 of 1152
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1603:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
next sample expected at 1152
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1322:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
time 0:00:00.026119448, offset 18446744073709551615, start
0:00:00.000000000, samples 1152
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1361:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
sync-offset 0, render-delay 0:00:00.000000000, ts-offset 0
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1423:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
running: start 0:00:00.026119448 - stop 0:00:00.052241896
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1437:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
compensating for sync-offset 0:00:00.000000000
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1442:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
adding base_time 0:00:00.000022014
0:00:02.154803000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1450:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
after compensation: start 0:00:00.026141462 - stop 0:00:00.052263910
0:00:02.189404000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 0
0:00:02.189404000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 0 @08E01F30
0:00:02.190404000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 1 (real 1) @08E02614
0:00:02.190404000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 1
0:00:02.190404000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 1 @08E02614
0:00:02.190404000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 2 (real 2) @08E02CF8
0:00:02.189404000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:514:gst_base_audio_sink_get_time:<autoaudiosink0-actual-sink-directsound>
processed samples: raw 0, delay 441, real 0, time 0:00:00.000000000
0:00:02.191405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 2
0:00:02.191405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1004:gst_base_audio_sink_skew_slaving:<autoaudiosink0-actual-sink-directsound>
internal 0:00:00.000000000 external 0:00:00.180209814 cinternal
0:00:00.000000000 cexternal 0:00:00.167754169
0:00:02.191405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 2 @08E02CF8
0:00:02.191405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1024:gst_base_audio_sink_skew_slaving:<autoaudiosink0-actual-sink-directsound>
internal 0:00:00.000000000 external 0:00:00.012455645 skew -12455645 avg
-5153011
0:00:02.191405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 3 (real 3) @08E033DC
0:00:02.192405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 3
0:00:02.192405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 3 @08E033DC
0:00:02.194405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 4 (real 4) @08E03AC0
0:00:02.192405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1465:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
final timestamps: start 0:00:00.000000000 - stop 0:00:00.000000000
0:00:02.195405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 4
0:00:02.195405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 4 @08E03AC0
0:00:02.196405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 5 (real 5) @08E041A4
0:00:02.195405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1472:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
time offset 0:00:00.000000000
0:00:02.196405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 5
0:00:02.197405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 5 @08E041A4
0:00:02.197405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 6 (real 6) @08E04888
0:00:02.196405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1531:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
align with prev sample, ABS (1152) < 1764
0:00:02.197405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 6
0:00:02.197405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 6 @08E04888
0:00:02.198405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 7 (real 7) @08E04F6C
0:00:02.197405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1562:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
rendering at 1152 1152/1152
0:00:02.198405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 7, write to 2-1080, diff
-5, segtotal 20, segsize 1764, base 0
0:00:02.198405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 7
0:00:02.199405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 7 @08E04F6C
0:00:02.198405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E02CF8 seg 2, sps 441, off 1080, avail 684
0:00:02.199405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 684 bytes
0:00:02.199405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 8, write to 3-0, diff
-5, segtotal 20, segsize 1764, base 0
0:00:02.199405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:1984:gst_ring_buffer_prepare_read: prepare read from
segment 8 (real 8) @08E05650
0:00:02.199405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E033DC seg 3, sps 441, off 0, avail 1764
0:00:02.200405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 1764 bytes
0:00:02.200405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 8, write to 4-0, diff
-4, segtotal 20, segsize 1764, base 0
0:00:02.200405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E03AC0 seg 4, sps 441, off 0, avail 1764
0:00:02.201405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 1764 bytes
0:00:02.201405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1677:default_commit: pointer at 8, write to 5-0, diff
-3, segtotal 20, segsize 1764, base 0
0:00:02.201405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1708:default_commit:<audiosinkringbuffer0> write
@08E041A4 seg 5, sps 441, off 0, avail 396
0:00:02.201405000  3696   023A3D50 DEBUG             ringbuffer
gstringbuffer.c:1712:default_commit: copy 396 bytes
0:00:02.201405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1572:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
wrote 1152 of 1152
0:00:02.202405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1603:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
next sample expected at 2304
0:00:02.202405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1322:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
time 0:00:00.052241896, offset 18446744073709551615, start
0:00:00.000000000, samples 1152
0:00:02.202405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1361:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
sync-offset 0, render-delay 0:00:00.000000000, ts-offset 0
0:00:02.202405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1423:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
running: start 0:00:00.052241896 - stop 0:00:00.078364344
0:00:02.203405000  3696   023A3D50 DEBUG          baseaudiosink
gstbaseaudiosink.c:1437:gst_base_audio_sink_render:<autoaudiosink0-actual-sink-directsound>
compensating for sync-offset 0:00:00.000000000
0:00:02.200405000  3696   0249E110 LOG                audiosink
gstaudiosink.c:246:audioringbuffer_thread_func:<autoaudiosink0-actual-sink-directsound>
transfered 1764 bytes of 1764 from segment 8
0:00:02.203405000  3696   0249E110 LOG               ringbuffer
gstringbuffer.c:2053:gst_ring_buffer_clear: clear segment 8 @08E05650
..................

Thank you in advance, Alessio.




------------------------------------------------------------------------------
This SF.net Dev2Dev email is sponsored by:

Show off your parallel programming skills.
Enter the Intel(R) Threading Challenge 2010.
http://p.sf.net/sfu/intel-thread-sfd
_______________________________________________
gstreamer-devel mailing list
[hidden email]
https://lists.sourceforge.net/lists/listinfo/gstreamer-devel