Bug #3223
openSATIP client - "Subscription" going into "Bad" state
0%
Description
Hi,
I'm using TVHeadend version 4.1-780~g1ec6696 on Debian Linux with a SAT>IP box Megasat SATIP Server 2 (Firmware 1.07).
Tuners 1 & 2 are connected to the Satellite Dish, 3&4 are empty. In TVH correspondingly tuners 3 & 4 are disabled.
Settings for DVB Inputs are:
Default values, checkboxes "addpids/delpids supported", "PIDs in setup", "Force pilot for DVBS2" and "Disable device specific workarounds" checked.
On each active tuner:
"Over the air EPG", "Initial Scan" and "Send Full play command" checked,
Next tune delay set to 2000ms.
I'm having issues with the tuners (called subscriptions in TVH) going into a "Bad" state and becoming unusable:
Once the EPG scan kicks in, both tuners eventually go into "Bad" state. This happens more or less immediately while with EPG scan disabled I can view two programmes on two devices (Kodi and Ipad app) in parallel an zap between channels without having the issue. This also happens if the EPG scan is only activated for one of the tuners.
Once a "subscription" has a "Bad" state, it won't return to normal operation. Thus, if both tuners are "bad" it is not possible to view a TV channel. If the first tuner only is bad, then switching channels takes a very long time.
However, in this situation it is perfectly possible to connect to the SAT>IP box directly using the Elgato iOS app or DVBViewer Lite on Windows and to watch a programme.
From a debugging perspective, I can identify two scenarios in which the "Bad" state is raised:
1) The satip subsystem raises "RTSP error 5" after a "PLAY" command was sent to the box. /Ausgabefehler) [8-200]
2288 2015-10-29 19:29:03.646 [ TRACE]:httpc: 50 4C 41 59 20 72 74 73 70 3A 2F 2F 31 39 32 2E PLAY rtsp://192.
2289 2015-10-29 19:29:03.646 [ TRACE]:httpc: 31 36 38 2E 31 37 38 2E 34 32 2F 73 74 72 65 61 168.178.42/strea
2290 2015-10-29 19:29:03.646 [ TRACE]:httpc: 6D 3D 38 33 3F 70 69 64 73 3D 30 2C 31 2C 31 36 m=83?pids=0,1,16
2291 2015-10-29 19:29:03.646 [ TRACE]:httpc: 2C 31 37 2C 31 38 20 52 54 53 50 2F 31 2E 30 0D ,17,18 RTSP/1.0.
2292 2015-10-29 19:29:03.646 [ TRACE]:httpc: 0A 53 65 73 73 69 6F 6E 3A 20 31 62 66 35 37 37 .Session: 1bf577
2293 2015-10-29 19:29:03.646 [ TRACE]:httpc: 61 66 33 30 35 63 64 38 39 66 0D 0A 43 53 65 71 af305cd89f..CSeq
2294 2015-10-29 19:29:03.646 [ TRACE]:httpc: 3A 20 32 0D 0A 0D 0A : 2....
2295 2015-10-29 19:29:03.646 [ TRACE]:httpc: 0005: client flush -5
2296 2015-10-29 19:29:03.646 [ ERROR]:satip: SAT>IP DVB-S Tuner #2 (192.168.178.42) - RTSP error -5 (Eingabe
2297 2015-10-29 19:29:03.646 [ TRACE]:satip: /stream=83 - bad teardown
2298 2015-10-29 19:29:03.646 [ TRACE]:httpc: 0005: client flush 0
2299 2015-10-29 19:29:03.646 [ TRACE]:httpc: 0005: Closed
2300 2015-10-29 19:29:36.000 [ INFO]:subscription: 000F: "epggrab" unsubscribing
2301 2015-10-29 19:29:36.000 [ DEBUG]:satip: SAT>IP DVB-S Tuner #1 (192.168.178.42) - stopping 10832.25H in Astra 19,2
2302 2015-10-29 19:29:36.003 [ TRACE]:satip: SAT>IP DVB-S Tuner #1 (192.168.178.42) - input thread received mux close
2) It looks like the 503 response from the SATIP box isn't handled properly (or at all)?
8448 2015-10-29 20:50:15.001 [ TRACE]:httpc: 53 45 54 55 50 20 72 74 73 70 3A 2F 2F 31 39 32 SETUP rtsp://192
8449 2015-10-29 20:50:15.001 [ TRACE]:httpc: 2E 31 36 38 2E 31 37 38 2E 34 32 2F 3F 73 72 63 .168.178.42/?src
8450 2015-10-29 20:50:15.001 [ TRACE]:httpc: 3D 31 26 66 65 3D 31 26 66 72 65 71 3D 31 31 35 =1&fe=1&freq=115
8451 2015-10-29 20:50:15.001 [ TRACE]:httpc: 38 32 2E 32 35 26 73 72 3D 32 32 30 30 30 26 6D 82.25&sr=22000&m
8452 2015-10-29 20:50:15.001 [ TRACE]:httpc: 73 79 73 3D 64 76 62 73 32 26 6D 74 79 70 65 3D sys=dvbs2&mtype=
8453 2015-10-29 20:50:15.001 [ TRACE]:httpc: 38 70 73 6B 26 70 6F 6C 3D 68 26 66 65 63 3D 32 8psk&pol=h&fec=2
8454 2015-10-29 20:50:15.001 [ TRACE]:httpc: 33 26 72 6F 3D 30 2E 33 35 26 70 6C 74 73 3D 6F 3&ro=0.35&plts=o
8455 2015-10-29 20:50:15.001 [ TRACE]:httpc: 6E 26 70 69 64 73 3D 30 20 52 54 53 50 2F 31 2E n&pids=0 RTSP/1.
8456 2015-10-29 20:50:15.001 [ TRACE]:httpc: 30 0D 0A 54 72 61 6E 73 70 6F 72 74 3A 20 52 54 0..Transport: RT
8457 2015-10-29 20:50:15.001 [ TRACE]:httpc: 50 2F 41 56 50 3B 75 6E 69 63 61 73 74 3B 63 6C P/AVP;unicast;cl
8458 2015-10-29 20:50:15.001 [ TRACE]:httpc: 69 65 6E 74 5F 70 6F 72 74 3D 33 35 31 39 32 2D ient_port=35192-
8459 2015-10-29 20:50:15.001 [ TRACE]:httpc: 33 35 31 39 33 0D 0A 43 53 65 71 3A 20 31 0D 0A 35193..CSeq: 1..
8460 2015-10-29 20:50:15.001 [ TRACE]:httpc: 0D 0A ..
8461 2015-10-29 20:50:15.001 [ INFO]:subscription: 0009: "epggrab" subscribing to mux "11582.25H", weight: 4, adapter: "SAT>IP DVB-S Tuner #1 (192.168.178.42)", network: "Astra 19,2", service: "Raw PID Subscription"
8462 2015-10-29 20:50:15.010 [ TRACE]:httpc: 0006: received RTSP/1.0 answer (len = 82)
8463 2015-10-29 20:50:15.010 [ TRACE]:httpc: 52 54 53 50 2F 31 2E 30 20 35 30 33 20 53 65 72 RTSP/1.0 503 Ser
8464 2015-10-29 20:50:15.010 [ TRACE]:httpc: 76 69 63 65 20 55 6E 61 76 61 69 6C 61 62 6C 65 vice Unavailable
8465 2015-10-29 20:50:15.010 [ TRACE]:httpc: 0D 0A 43 53 65 71 3A 31 0D 0A 43 6F 6E 74 65 6E ..CSeq:1..Conten
8466 2015-10-29 20:50:15.010 [ TRACE]:httpc: 74 2D 4C 65 6E 67 74 68 3A 31 37 0D 0A 4E 6F 2D t-Length:17..No-
8467 2015-10-29 20:50:15.010 [ TRACE]:httpc: 0006: client flush 0
8468 2015-10-29 20:50:15.010 [ TRACE]:httpc: 0006: RTSP/1.0 answer 'RTSP/1.0 503 Service Unavailable' (rcseq: 1)
8469 2015-10-29 20:50:15.010 [ TRACE]:httpc: 52 54 53 50 2F 31 2E 30 20 35 30 33 20 53 65 72 RTSP/1.0 503 Ser
8470 2015-10-29 20:50:15.010 [ TRACE]:httpc: 76 69 63 65 20 55 6E 61 76 61 69 6C 61 62 6C 65 vice Unavailable
8471 2015-10-29 20:50:15.010 [ TRACE]:httpc: 00 0A 43 53 65 71 3A 31 0D 0A 43 6F 6E 74 65 6E ..CSeq:1..Conten
8472 2015-10-29 20:50:15.010 [ TRACE]:httpc: 74 2D 4C 65 6E 67 74 68 3A 31 37 0D 0A 4E 6F 2D t-Length:17..No-
8473 2015-10-29 20:50:15.010 [ TRACE]:httpc: 4D 6F 72 65 3A 66 72 6F 6E 74 65 6E 64 73 00 0A More:frontends..
8474 2015-10-29 20:50:15.010 [ TRACE]:httpc: 0D 0A
[...]
8697 2015-10-29 20:50:55.000 [ INFO]:subscription: 0009: "epggrab" unsubscribing
8698 2015-10-29 20:50:55.000 [ DEBUG]:satip: SAT>IP DVB-S Tuner #1 (192.168.178.42) - stopping 11582.25H in Astra 19,2
8699 2015-10-29 20:50:55.001 [ TRACE]:satip: SAT>IP DVB-S Tuner #1 (192.168.178.42) - input thread received mux close
I'd think that the 'RTSP/1.0 503 Service Unavailable' response would forcefully end subscription 0009. However, it sits in "Bad" state for about a minute, then being stopped and closed with no obvious cleanup in terms of communication with the box.
Please find the trace file attached. I also included a Wireshark trace from the Windows machine which connected and played back a TV stream happily while TVH would refuse to do anything due to both tuners being "Bad".
I hope we can sort this out and add the Megasat box as "works with TV Headend". Happy to test and provide more details!
Kind regards,
Timo
Files