[Bug 796361] New: Answer of RTSP server is (very) often not sent out
GStreamer (GNOME Bugzilla)
bugzilla at gnome.org
Wed May 23 16:50:21 UTC 2018
https://bugzilla.gnome.org/show_bug.cgi?id=796361
Bug ID: 796361
Summary: Answer of RTSP server is (very) often not sent out
Classification: Platform
Product: GStreamer
Version: 1.14.0
OS: Linux
Status: NEW
Severity: normal
Priority: Normal
Component: gst-rtsp-server
Assignee: gstreamer-bugs at lists.freedesktop.org
Reporter: meinemailingliste2 at online.de
QA Contact: gstreamer-bugs at lists.freedesktop.org
GNOME version: ---
There seems to be some error, which happens with the RTSP server on our i.MX6
platform.
I receive an RTSP OPTIONS and/or RTSP DESCRIBE message (which is sent by VLC
from my PC), see partly at least an answer in GStreamer logfile, like
0:00:45.223877672 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00m
rtspclient rtsp-client.c:3460:handle_request: [00m client 0x2a098a0: received a
request OPTIONS rtsp://10.5.122.41:8554/live 1.0
0:00:45.224764339 [334m 1023 [00m 0x2cf7e60 [33;01mLOG [00m [00m
rtspclient
rtsp-client.c:1147:default_pre_signal_handler:<GstRTSPClient at 0x2a098a0> [00m
returning GST_RTSP_STS_OK
0:00:45.226936672 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1143:gst_v4l2_buffer_pool_dqbuf:<RecorderStreamerH264Encoder:pool:src>
[00m dequeueing a buffer
0:00:45.227309005 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:1312:gst_v4l2_allocator_dqbuf:<RecorderStreamerH264Encoder:pool:src:allocator>
[00m dequeued buffer 2 (flags 0x4011)
0:00:45.227481672 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:1341:gst_v4l2_allocator_dqbuf:<RecorderStreamerH264Encoder:pool:src:allocator>
[00m Dequeued capture buffer, length: 2097152 bytesused: 54167 data_offset: 0
0:00:45.227712339 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1176:gst_v4l2_buffer_pool_dqbuf:<RecorderStreamerH264Encoder:pool:src>
[00m dequeued buffer 0x6e1a02b0 seq:418 (ix=2), mem 0x6e38b068 used 54167,
plane=0, flags 00004011, ts 0:00:20.081505000, pool-queued=3, buffer=0x6e1a02b0
0:00:45.228077672 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:116:gst_v4l2_buffer_pool_copy_buffer:<RecorderStreamerH264Encoder:pool:src>
[00m copying buffer
0:00:45.228248005 [334m 1023 [00m 0x3afbc980 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:141:gst_v4l2_buffer_pool_copy_buffer:<RecorderStreamerH264Encoder:pool:src>
[00m copy raw bytes
0:00:45.230225672 [334m 1023 [00m 0x3afbc980 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1380:gst_v4l2_buffer_pool_release_buffer:<RecorderStreamerH264Encoder:pool:src>
[00m release buffer 0x6e1a02b0
0:00:45.230486672 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1069:gst_v4l2_buffer_pool_qbuf:<RecorderStreamerH264Encoder:pool:src>
[00m queuing buffer 2
0:00:45.230670005 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:1265:gst_v4l2_allocator_qbuf:<RecorderStreamerH264Encoder:pool:src:allocator>
[00m queued buffer 2 (flags 0x4003)
0:00:45.230801672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:1265:gst_v4l2_allocator_qbuf:<LiveVideov4l2sink:pool:sink:allocator>
[00m queued buffer 1 (flags 0x2002)
0:00:45.230809339 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2videoenc
gstv4l2videoenc.c:628:gst_v4l2_video_enc_get_oldest_frame:<RecorderStreamerH264Encoder>
[00m Oldest frame is 418 0:00:20.081505530 and 0 frames left
0:00:45.230990005 [334m 1023 [00m 0x6e123d50 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1380:gst_v4l2_buffer_pool_release_buffer:<LiveVideov4l2sink:pool:sink>
[00m release buffer 0x6c528200
0:00:45.231132672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1463:gst_v4l2_buffer_pool_release_buffer:<LiveVideov4l2sink:pool:sink>
[00m buffer 1 is queued
0:00:45.231212005 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1009:gst_v4l2_buffer_pool_poll:<LiveVideov4l2sink:pool:sink>
[00m polling device
0:00:45.231294005 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1143:gst_v4l2_buffer_pool_dqbuf:<LiveVideov4l2sink:pool:sink>
[00m dequeueing a buffer
0:00:45.232014339 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2videoenc
gstv4l2videoenc.c:645:gst_v4l2_video_enc_loop:<RecorderStreamerH264Encoder>
[00m Allocate output buffer
0:00:45.232141005 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00m
rtspclient rtsp-client.c:3460:handle_request: [00m client 0x2a098a0: received a
request DESCRIBE rtsp://10.5.122.41:8554/live 1.0
0:00:45.232184672 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2videoenc
gstv4l2videoenc.c:658:gst_v4l2_video_enc_loop:<RecorderStreamerH264Encoder>
[00m Process output buffer
0:00:45.232306005 [334m 1023 [00m 0x2cf7e60 [33;01mLOG [00m [00m
rtspclient
rtsp-client.c:1147:default_pre_signal_handler:<GstRTSPClient at 0x2a098a0> [00m
returning GST_RTSP_STS_OK
0:00:45.232329339 [334m 1023 [00m 0x3afbc980 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1705:gst_v4l2_buffer_pool_process:<RecorderStreamerH264Encoder:pool:src>
[00m process buffer 0x2b7fcce4
0:00:45.232444005 [334m 1023 [00m 0x3afbc980 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1009:gst_v4l2_buffer_pool_poll:<RecorderStreamerH264Encoder:pool:src>
[00m polling device
0:00:45.232458339 [334m 1023 [00m 0x2cf7e60 [33;01mLOG [00m [00m
rtspmountpoints rtsp-mount-points.c:251:gst_rtsp_mount_points_match: [00m
Looking for mount point path /live
0:00:45.232784672 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00m
rtspmountpoints rtsp-mount-points.c:300:gst_rtsp_mount_points_match: [00m found
media factory 0x53b02e68 for path /live
0:00:45.232978672 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00;01;37;41m
GST_PIPELINE gstparse.c:337:gst_parse_launch_full: [00m parsing pipeline
description ' ( appsrc name=StreamingSrc min-latency=200000000 is-live=true
do-timestamp=true format=3 ! queue ! rtph264pay name=pay0 config-interval=0
pt=96 ) '
0:00:45.233100005 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00;01;37;41m
GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: [00m
creating element "appsrc"
0:00:45.234180005 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00;01;37;41m
GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstBaseSrc at 0x2da321a0>
[00m adding pad 'src'
0:00:45.234934672 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00;01;37;41m
GST_ELEMENT_FACTORY gstelementfactory.c:361:gst_element_factory_create: [00m
creating element "queue"
0:00:45.235195672 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00;01;37;41m
GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstQueue at 0x6e3aefa0>
[00m adding pad 'sink'
0:00:45.235397005 [334m 1023 [00m 0x2cf7e60 [36mINFO [00m [00;01;37;41m
GST_ELEMENT_PADS gstelement.c:670:gst_element_add_pad:<GstQueue at 0x6e3aefa0>
[00m adding pad 'src'
0:00:45.245540339 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:1312:gst_v4l2_allocator_dqbuf:<LiveVideov4l2sink:pool:sink:allocator>
[00m dequeued buffer 2 (flags 0x2000)
0:00:45.245762339 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1176:gst_v4l2_buffer_pool_dqbuf:<LiveVideov4l2sink:pool:sink>
[00m dequeued buffer 0x6c5280c0 seq:0 (ix=2), mem 0x55def1e8 used 2073600,
plane=0, flags 00002000, ts 0:00:00.000000000, pool-queued=2, buffer=0x6c5280c0
0:00:45.245886005 [334m 1023 [00m 0x6e123d50 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1380:gst_v4l2_buffer_pool_release_buffer:<LiveVideov4l2sink:pool:sink>
[00m release buffer 0x6c5280c0
0:00:45.245960339 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1448:gst_v4l2_buffer_pool_release_buffer:<LiveVideov4l2sink:pool:sink>
[00m buffer 2 not queued, putting on free list
0:00:45.246031672 [334m 1023 [00m 0x6e123d50 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1380:gst_v4l2_buffer_pool_release_buffer:<LeftCamerav4l2src:pool:src>
[00m release buffer 0x6e174b50
0:00:45.246101672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1069:gst_v4l2_buffer_pool_qbuf:<LeftCamerav4l2src:pool:src>
[00m queuing buffer 5
0:00:45.246196672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:1265:gst_v4l2_allocator_qbuf:<LeftCamerav4l2src:pool:src:allocator>
[00m queued buffer 5 (flags 0x2003)
0:00:45.246278672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:937:gst_v4l2_allocator_clear_dmabufin:<LiveVideov4l2sink:pool:sink:allocator>
[00m clearing DMABUF import, fd 134 plane 0
0:00:45.246351672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
bufferpool
gstbufferpool.c:1284:default_release_buffer:<LiveVideov4l2sink:pool:sink> [00m
released buffer 0x6c5280c0 0
0:00:45.246420672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
bufferpool gstbufferpool.c:388:do_free_buffer:<LiveVideov4l2sink:pool:sink>
[00m freeing buffer 0x6c5280c0 (2 left)
0:00:45.246497339 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:356:gst_v4l2_allocator_release:<LiveVideov4l2sink:pool:sink:allocator>
[00m plane 0 of buffer 2 released
0:00:45.246562339 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:372:gst_v4l2_allocator_release:<LiveVideov4l2sink:pool:sink:allocator>
[00m buffer 2 released
0:00:45.246950339 [334m 1023 [00m 0x6e123d50 [37mDEBUG [00m [00m
v4l2sink gstv4l2sink.c:492:gst_v4l2sink_show_frame:<LiveVideov4l2sink> [00m
render buffer: 0x6e174c90
0:00:45.247050005 [334m 1023 [00m 0x6e123c90 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1302:gst_v4l2_buffer_pool_acquire_buffer:<LeftCamerav4l2src:pool:src>
[00m acquire
0:00:45.247056672 [334m 1023 [00m 0x6e123d50 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1705:gst_v4l2_buffer_pool_process:<LiveVideov4l2sink:pool:sink>
[00m process buffer 0x2ebfc96c
0:00:45.247152005 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1883:gst_v4l2_buffer_pool_process:<LiveVideov4l2sink:pool:sink>
[00m alloc buffer from our pool
0:00:45.247150339 [334m 1023 [00m 0x55debef0 [37mDEBUG [00m [00m
v4l2videoenc
gstv4l2videoenc.c:714:gst_v4l2_video_enc_handle_frame:<RecorderStreamerH264Encoder>
[00m Handling frame 419
0:00:45.247219672 [334m 1023 [00m 0x6e123d50 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1302:gst_v4l2_buffer_pool_acquire_buffer:<LiveVideov4l2sink:pool:sink>
[00m acquire
0:00:45.247301672 [334m 1023 [00m 0x55debef0 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1705:gst_v4l2_buffer_pool_process:<RecorderStreamerH264Encoder:pool:sink>
[00m process buffer 0x6e3a776c
0:00:45.247168672 [334m 1023 [00m 0x6e123c90 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1009:gst_v4l2_buffer_pool_poll:<LeftCamerav4l2src:pool:src>
[00m polling device
0:00:45.247425672 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
bufferpool
gstbufferpool.c:1133:default_acquire_buffer:<LiveVideov4l2sink:pool:sink> [00m
no buffer, trying to allocate
0:00:45.247433339 [334m 1023 [00m 0x55debef0 [33;01mLOG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1883:gst_v4l2_buffer_pool_process:<RecorderStreamerH264Encoder:pool:sink>
[00m alloc buffer from our pool
0:00:45.247592339 [334m 1023 [00m 0x6e123d50 [33;01mLOG [00m [00m
v4l2allocator
gstv4l2allocator.c:975:gst_v4l2_allocator_alloc_dmabufin:<LiveVideov4l2sink:pool:sink:allocator>
[00m allocating empty DMABUF import group
0:00:45.247660339 [334m 1023 [00m 0x55debef0 [37mDEBUG [00m [00m
v4l2bufferpool
gstv4l2bufferpool.c:1302:gst_v4l2_buffer_pool_acquire_buffer:<RecorderStreamerH264Encoder:pool:sink>
[00m acquire
On console I see the content of the packets:
2018-05-23 18:19:42.302 Streamer.cpp(167): client_connected_cb
client_connected_cb 1846863448
2018-05-23 18:19:42.302 Streamer.cpp(816): clientHasConnected user_data
1846863448
2018-05-23 18:19:42.303 Streamer.cpp(825): clientHasConnected setting
m_connectedClientsCount to 1
-> One packet is received:
RTSP request message 0x2a0bc40
request line:
method: 'OPTIONS'
uri: 'rtsp://10.5.122.41:8554/live'
version: '1.0'
headers:
key: 'CSeq', value: '2'
key: 'User-Agent', value: 'LibVLC/3.0.2 (LIVE555 Streaming Media
v2016.11.28)'
body:
-> Answer is sent via send_message (MMMM is my own debug output):
MMMM I am inside RTSP: send_message loglevel=9
RTSP response message 0x29e08c0c
status line:
code: '200'
reason: 'OK'
version: '1.0'
headers:
key: 'CSeq', value: '2'
key: 'Public', value: 'OPTIONS, DESCRIBE, ANNOUNCE, GET_PARAMETER, PAUSE,
PLAY, RECORD, SETUP, SET_PARAMETER, TEARDOWN'
key: 'Server', value: 'GStreamer RTSP server'
body: length 0
-> Second incoming message, which is a DESCRIBE:
RTSP request message 0x2a0bc40
request line:
method: 'DESCRIBE'
2018-05-23 18:19:42.319 Streamer.cpp(241): sampleCallback uri:
'rtsp://10.5.122.41:8554/live'
appSrc == 0
version: '1.0'
headers:
key: 'CSeq', value: '3'
key: 'User-Agent', value: 'LibVLC/3.0.2 (LIVE555 Streaming Media
v2016.11.28)'
key: 'Accept', value: 'application/sdp'
body:
-> Here the answer is missing!!! send_message is not called!!!
2018-05-23 18:19:42.374 Streamer.cpp(180): media_configure_cb client conrequest
received 1846863448
-> After 5 seconds VLC tries to reconnect because previous connection was
unsuccessful
-> but this is prohibited by our implementation. So in 5 seconds no call to
send_message.
2018-05-23 18:19:47.302 Streamer.cpp(167): client_connected_cb
client_connected_cb 1846863448
2018-05-23 18:19:47.303 Streamer.cpp(834): clientHasConnected second client
attempted to connect
-> What is this? This is not the RTSP SETUP, but seems to be an answer? Our
last answer?
-> but it was ok. Answer for second connection? But request was not yet
traced...
MMMM I am inside RTSP: send_generic_response
MMMM I am inside RTSP: send_message loglevel=9
RTSP response message 0x29e08c0c
status line:
code: '503'
reason: 'Service Unavailable'
version: '1.0'
headers:
key: 'CSeq', value: '3'
key: 'Server', value: 'GStreamer RTSP server'
body: length 0
2018-05-23 18:20:02.449 Streamer.cpp(154): client_closed_cb client_closed_cb
1846863448
2018-05-23 18:20:02.450 Streamer.cpp(846): clientHasDisconnected setting
m_connectedClientsCount to 0
-> Now client has disconnected, RTSP SETUP is dumped?
RTSP request message 0x2d85678
request line:
method: 'SETUP'
uri: 'rtsp://10.5.122.41:8554/live'
version: '1.0'
headers:
key: 'CSeq', value: '0'
key: 'Transport', value: 'RTP/AVP;unicast;client_port=9416-9417'
body:
2018-05-23 18:20:02.461 Streamer.cpp(180): media_configure_cb client conrequest
received 1846863448
MMMM I am inside RTSP: send_generic_response
MMMM I am inside RTSP: send_message loglevel=9
RTSP response message 0x29e08c0c
status line:
code: '503'
reason: 'Service Unavailable'
version: '1.0'
headers:
key: 'CSeq', value: '0'
key: 'Server', value: 'GStreamer RTSP server'
body: length 0
Very mysterious...
--
You are receiving this mail because:
You are the QA Contact for the bug.
You are the assignee for the bug.
More information about the gstreamer-bugs
mailing list