Bug #3223
SATIP 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
History
Updated by Jaroslav Kysela about 9 years ago
The error -5 means EIO - the TCP connection was closed by the server. That's the reason why the session is NOT terminated correctly (shutdown command). The 503 error - what we can do with it ? It's fatal error and it should not occur when you don't share tuners with something else. Yes, we can close the mux reception early, but it's all we can do.
The server is broken (firmware). I can reproduce these errors with the original firmware on Inverto boxes (Grundig gssbox, Telestar Digibit R1, Invert IDL-400s). Perhaps, the megasat firmware is based on this. But it's bug in the firmware (connection with the client is terminated early or server crashes so everything is lost).
I would report this to the hardware vendor to fix their firmware. Note that SETUP+PLAY causes socket close on the server side.. Then the "tuner" is busy so server returns 503 until RTSP timeout is reached. Really firmware bug.
Updated by Jaroslav Kysela about 9 years ago
Just note that based on the bad experience with Inverto firmwares - I started https://github.com/perexg/satip-axe to eliminate server bugs using the light minisatip server - rock solid solution for me now.
Updated by Timo Biesenbach about 9 years ago
I would like to agree if it wasn't possible to connect to the SATIP box using SATIP clients on both the iPad and the Windows machine while TVH refuses to move on. And usually this condition can be resolved by "service tvheadend restart".
That being said, I think it's a bit early to lean back and fingerpoint at the hardware vendor.
Sure, the server boxes firmware might be implemented in a certain way which makes it harder to TVH to interface with it given the fact that the SATIP Spec only details out the positive scenarios while theres no to little guidance on how to handle error conditions.
However I wouldn't consider it an option to reprogram the boxes firmwares with minisatip for the average user.
Keep in mind, the boxes that are in the market have passed the SATIP certification and they do work with the above mentioned client apps, so it might be very difficult to get the vendors to change things as long as the issues cannot be shown using certified hardware and apps.
Coming to what we can do:
In my opinion, both scenarios should be handled by TVH in a reasonable way in terms of internal cleanup which might involve disposing and recreating / restarting the associated "Subscription" object that is in a bad state.
I have observed a condition in which the RTSP -5 error occured but wasn't handled at all, the underlying process just sits around complaining about "no input detected". While this might make sense for integrated DVB hardware cards where communication errors are very unlikely to happen, I think the situation for network attached tuners is quite different. Communication errors / breakdowns should be expected and handled maybe by retrying the communication sequence.
Also, in both scenarios I'm not seeing any further RTSP communication while the "Subscriptions" are in bad state. If trying to access a channel, the subscriptions first enter "Testing" for a while, then "Bad", but no "SETUP" / "PLAY" on the communication end.
Updated by Jaroslav Kysela about 9 years ago
If this error occurs, it's really serious one. I don't say that I'm against to include some hacks to improve the latencies, but the problem is that the server is in some "dead" state for a while (at least Inverto firmwares behaves in that way). Nothing helps - there is already a TEARDOWN hack, but it works only in some use cases. Basically, TVH really pushes the server implementation hardly, and it's really amazing how bad the firmwares are. So - if you like to do some hacks - go ahead. I'll include them.
And I think that your argumentation that preliminary connection close on networks are very likely to happen - no, it's false argumentation. We are in realtime world. If this error happen, it's serious. The RTSP client just doesn't know what the server does in this case (the RTSP session state is lost), so it's better to wait for recovery like the current implementation does before pushing new requests.
Again - the server is failing, any recovery process is bad and unpredictable.
Updated by Jaroslav Kysela about 9 years ago
Note that TVH has already configuration options to run OTA EPG grabbers to night hours and you can force to use only one tuner to keep things consistent for "streaming hours".
Updated by Raymond Paulsen about 9 years ago
I have to agree with jaroslav, i dont think implementing hacks for sat>ip in tvhis the way to go, its not the job of tvh to handle bad firmware on tuners.
satip-axe with digibit r1 has been rock solid with me, use this tuner and fw with tvh for best result is my advice.
Updated by Timo Biesenbach about 9 years ago
Thanks guys, I'll do some more investigation re. the above scenarios and let you know if I come across something helpful. I agree that the hacking beyond the specification is not the right thing todo. All I'm saying is that in the outlined scenarios, I was able to access the device using other apps while TVH considered the tuners as being in a "bad" state and wouldn't recover.
Re. the RTSP error 5: From a quick read of the spec, I would assume that following a SETUP which returned a session id, a TEARDOWN would be expected to close the session and free up resources in the server, even if a PLAY command inbetween failed. I'm not seeing that in the trace and I wonder whether it is correct or not since the spec leaves room for interpretation.
I'll try to limit the EPG grabbers to off hours - thanks for the hint!
Updated by Timo Biesenbach about 9 years ago
I did some more testing involving a second setup which replaced TVH with "DVBViewer Recording Service" on a Windows machine, which is a SW package with roughly the same features as TVH. I decided to give it a try because DVBViewer is "SATIP certified" and I wanted to see if I could replicate the errors with that setup. While there were no obvious lockups, it became clear that the Megasat device is not designed to handle multiple SATIP sessions from the same consuming device: When accessed from two Kodi instances via DVBViewer RS, it was not possible to tune into two different channels simultaneously. Always one Kodi instance stopped replay when a channel was selected on the other one.
When doing the same test using native SATIP client apps on different devices, it was no problem to view and zap through different channels one each of the devices.
Interestingly, the Megasat manual always stresses that it is up to four individual devices to which the box can stream a Satellite programme, so it seems that it was not designed for the use-case of one device with one IP address consuming each of the streams. I wonder if this is covered somewhere in the SATIP spec or part of the certification test cases.
Is there a compatibility list somewhere showing which boxes do work with TVH? I'd be more than happy to share my results for when other users make their buying decision.
On another note: The Unicable feature of the box is flawed as well which is why I'll be returning mine and have it exchanged for one of the Inverto 400s clones.
Please feel free to close this issue.
Updated by Jaroslav Kysela about 9 years ago
You can use multiple IP addresses - TVH allows the IP address configuration per tuner. Just add the extra addresses to your system's network config.
Updated by Janosch Machowinski almost 9 years ago
Hi,
I got the same SatIp Tuner, and ran into similar Problems as Timo.
It looks like, the SatIp server closes the http connection after
every rtsp request. Also one speciality of this box, the Session
is malformed, it contains a space in the beginning of the id.
Updated by Janosch Machowinski almost 9 years ago
I had a look into the source code and the network trace.
What happens ist the following :
tvh : RTSP Setup
ms : RTSP Ok
ms : Fin/Ack
tvh : RTSP Play on the closed connection
Hm, after a couple of retries, the server is now okay with reusing the connection,
and is working as expected. I'll try to debug it tomorrow a bit more.
Updated by Janosch Machowinski almost 9 years ago
Just a note here, the behaviour of the firmware is valid in respect to the SatIp Spec 1.2.2
"An RTSP session generally spans multiple TCP connections (e.g. one TCP connection per request - response)."
The correct fix seems to be, to open a new connection for every request, or at least include an
option for firmwares, that need these.
Updated by Jaroslav Kysela almost 9 years ago
Server must not close the connection before timeout. Yes, client may do multiple TCP connections for one session.
Updated by Jaroslav Kysela almost 9 years ago
Anyway, it appears the this server does not like multiple sessions from same IP - see comments 8 and 9. Try one tuner and then try to add other tuners using different IPs.
Updated by Janosch Machowinski almost 9 years ago
I'm only using one tuner for now and have these issues