Jump to content

RS slow to respond to RTSP SETUP command


Recommended Posts

I'm trying to get TVHeadend to access the tuners managed by RS using RTSP but it times out as it tries to set up the connection. Running a Wireshark trace I can see that RS takes between 6 and 8 seconds to respond to the RTSP SETUP... command - it then responds with RTSP/1.0 200 OK but by then TVHeadend has timed out and dropped the connection.

 

I get the same delay using VLC as the client, and have done some traces. Wireshark shows:

 

No.     Time                       Source                Destination           Protocol Length Info
      7 2017-05-01 14:27:06.905324 192.168.1.199         192.168.1.201         RTSP     323    OPTIONS rtsp://192.168.1.201:554/?freq=546&msys=dvbt2&bw=8&tnr=2,546000,0,0,0,2,0,0,6602,6601,6600,17540,4,0,24,0,16516,9018,-1,5000&pids=0,16,17,18,20,6600,6601,6602,6606 RTSP/1.0
      8 2017-05-01 14:27:06.905679 192.168.1.201         192.168.1.199         RTSP     196    Reply: RTSP/1.0 200 OK
     10 2017-05-01 14:27:06.905831 192.168.1.199         192.168.1.201         RTSP     349    DESCRIBE rtsp://192.168.1.201:554/?freq=546&msys=dvbt2&bw=8&tnr=2,546000,0,0,0,2,0,0,6602,6601,6600,17540,4,0,24,0,16516,9018,-1,5000&pids=0,16,17,18,20,6600,6601,6602,6606 RTSP/1.0
     11 2017-05-01 14:27:06.906168 192.168.1.201         192.168.1.199         RTSP/SDP 508    Reply: RTSP/1.0 200 OK, with session description
     12 2017-05-01 14:27:06.906580 192.168.1.199         192.168.1.201         RTSP     244    SETUP rtsp://192.168.1.201:554/stream=6/ RTSP/1.0
     20 2017-05-01 14:27:15.146165 192.168.1.201         192.168.1.199         RTSP     336    Reply: RTSP/1.0 200 OK
     25 2017-05-01 14:27:15.146499 192.168.1.199         192.168.1.201         RTSP     224    PLAY rtsp://192.168.1.201:554/stream=6 RTSP/1.0
     26 2017-05-01 14:27:15.148718 192.168.1.201         192.168.1.199         RTSP     264    Reply: RTSP/1.0 200 OK
     44 2017-05-01 14:27:15.166018 192.168.1.199         192.168.1.201         RTSP     214    GET_PARAMETER rtsp://192.168.1.201:554/stream=6 RTSP/1.0
     45 2017-05-01 14:27:15.166223 192.168.1.201         192.168.1.199         RTSP     194    Reply: RTSP/1.0 200 OK
  12881 2017-05-01 14:27:33.153958 192.168.1.199         192.168.1.201         RTSP     214    GET_PARAMETER rtsp://192.168.1.201:554/stream=6 RTSP/1.0
  12882 2017-05-01 14:27:33.154189 192.168.1.201         192.168.1.199         RTSP     194    Reply: RTSP/1.0 200 OK
  19779 2017-05-01 14:27:51.151781 192.168.1.199         192.168.1.201         RTSP     214    GET_PARAMETER rtsp://192.168.1.201:554/stream=6 RTSP/1.0
  19780 2017-05-01 14:27:51.152019 192.168.1.201         192.168.1.199         RTSP     194    Reply: RTSP/1.0 200 OK
  27441 2017-05-01 14:28:09.149429 192.168.1.199         192.168.1.201         RTSP     214    GET_PARAMETER rtsp://192.168.1.201:554/stream=6 RTSP/1.0
  27442 2017-05-01 14:28:09.149676 192.168.1.201         192.168.1.199         RTSP     194    Reply: RTSP/1.0 200 OK

As you can see, RS responds very quickly to the initial OPTIONS and DESCRIBE command, but takes 8 seconds to respond to the SETUP command.

 

Looking at the RS svcdebug log, I see:

 

01.05.17 14:27:11.824 SetStandbyBlock      RTSP-Client 192.168.1.199
01.05.17 14:27:11.824 TRecordingEngine     AddReference     RTSP-Client 192.168.1.199: 1
01.05.17 14:27:11.824 TRTSPUDPClient       SendBufSizeUDP   13280000
01.05.17 14:27:11.824 TRTSPUDPClient       Pids             0,16,17,18,20,6600,6601,6602,6606
01.05.17 14:27:11.824 TRTSPUDPClient       SetTuner         TType: 2, Freq: 546000, Symrate: 0, LOF: 0, Tone: 0, Pol: 2, DiseqC: 0, FEC: 0, APID: 6602, VPID: 6601, PMT: 6600, SID: 17540, TID: 16516, NID: 9018, SatMod: 4, DiseqCVal: 0, Flags: 24
01.05.17 14:27:12.109 TBDA_TBS             OpenDevice       bvTurbosightNew
01.05.17 14:27:12.109 TRTSPUDPClient       AllocateHardware TBS 6280 DVBT/T2 Tuner A (1)
01.05.17 14:27:12.109 TRTSPUDPClient       SetTuner         Got new hardware
01.05.17 14:27:12.109 TBDA_TBS             SetTuner         TType: 2, Freq: 546000, Symrate: 0, LOF: 0, Tone: 0, Pol: 2, DiseqC: 0, FEC: 0, APID: 6602, VPID: 6601, PMT: 6600, SID: 17540, TID: 16516, NID: 9018, SatMod: 4, DiseqCVal: 0, Flags: 24
01.05.17 14:27:15.159 TRTSPUDPClient       SetTuner         Tuner set
01.05.17 14:27:15.163 TUPnPAnnounce        InitWsocket      192.168.1.201

Although there isn't any major problem, it does seem to be calling SetTuner twice, which does slow it down  - could this be the cause, as the second call is taking 3 seconds?

 

Attached is a support.zip

 

 

support.zip

Edited by renzz
spelling
Link to comment
On 1.5.2017 at 3:46 PM, renzz said:

it does seem to be calling SetTuner twice

 

No, it doesn't. The first log entry originates from the server receiving the tune command (TRTSPUDPClient, an object representing the client within the server), the second log entry originates from the code dealing with the TBS device (TBDA_TBS). It takes 3 seconds until the tuning call returns. Dunno what causes the additional delay... I'll check the code later.

Link to comment

Not really ;) Too many other things to do.

 

However, at a second glance and after comparing the time stamps in your logs, it looks like the main delay happens before the RS starts to process the SETUP command:

 

12 2017-05-01 14:27:06.906580 192.168.1.199         192.168.1.201         RTSP     244    SETUP rtsp://192.168.1.201:554/stream=6/ RTSP/1.0
01.05.17 14:27:11.824 SetStandbyBlock      RTSP-Client 192.168.1.199

The second entry originates from the OnConnect handler that is executed right after the client request has been received. Since the RS log is not complete I cannot see what happened before. But it rather looks like a delay outside the RS code caused by your network.

 

Link to comment
×
×
  • Create New...