Bug #2640
"HTS Tvheadend: disconnected" problem after upgrading to 3.9.2413
0%
Description
This issue is observed in Openelec5.0 where new Tvheadend addon (4.3.7) was introduced some days ago. This addon contains Tvheadend 3.9.2413. The previous addon was based on 3.9.2182. The described fault is not present there.
Hardware: AM1H-ITX, 5150, Tevii s471 PCIe DVB-S2 tuner card with a 4/1 diseqc switch.
Symptom:
- New addon works fine after the upgrade. Seems stable and fast.
- When I stop the TV reception, it cannon be started again ever. After selecting any channel the "HTS Tvheadend: disconnected" message appears. Meanwhile the TVH GUI is not accessible or extremly slow.
Recovery:
Practically nothing. Neither the restart of the addon nor the restart of the complete PC solves the problem (except rare cases) The error message re-appears again as soon as I start to tune any channel.
The only recovery is to roll-back to the old addon.
After downgrade to 3.9.2182 then upgrade to 3.9.2413, the system works again until stopping the reception or restart the system.
Logs:
This log was collected after system restart with "linuxdvb" trace and debug switched on. The log stopped at the fault happened.
2015-01-26 17:15:21.711 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - checking FE status (ready)
2015-01-26 17:15:21.711 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - status 4 (0000)
2015-01-26 17:15:21.761 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - checking FE status (ready)
2015-01-26 17:15:21.762 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - status 4 (0000)
2015-01-26 17:15:21.812 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - checking FE status (ready)
2015-01-26 17:15:21.813 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - status 4 (0000)
2015-01-26 17:15:21.863 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - checking FE status (ready)
2015-01-26 17:15:21.863 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - status 4 (0000)
2015-01-26 17:15:21.913 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - checking FE status (ready)
2015-01-26 17:15:21.914 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - status 4 (0000)
2015-01-26 17:15:21.964 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - checking FE status (ready)
2015-01-26 17:15:21.965 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - status 4 (0000)
2015-01-26 17:15:22.000 [ INFO]:mpegts: 11778V in Astra 19.2E - scan no data, failed
2015-01-26 17:15:22.000 [ INFO]:subscription: 000A: "scan" unsubscribing
2015-01-26 17:15:22.000 [ DEBUG]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - stopping 11778V in Astra 19.2E
2015-01-26 17:15:23.000 [ INFO]:mpegts: 11778V in Astra 19.2E - tuning on Montage Technology DS3000 : DVB-S #0
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: tuner Montage Technology DS3000 : DVB-S #0 tunning to DVBS pos 19.2E freq 11778000 V sym 27500000 fec 3/4 mod QPSK roff 35 (freq 1178000)
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 17 => 5
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 03 => 1178000
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 06 => 2
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 08 => 27500000
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 09 => 3
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 12 => 2
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 04 => 0
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 13 => 0
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 01 => 0
2015-01-26 17:15:23.000 [ DEBUG]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - starting 11778V in Astra 19.2E
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: Montage Technology DS3000 : DVB-S #0 - tuning
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: tuner Montage Technology DS3000 : DVB-S #0 tunning to DVBS pos 19.2E freq 11778000 V sym 27500000 fec 3/4 mod QPSK roff 35 (freq 1178000)
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 17 => 5
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 03 => 1178000
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 06 => 2
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 08 => 27500000
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 09 => 3
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 12 => 2
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 04 => 0
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 13 => 0
2015-01-26 17:15:23.000 [ TRACE]:linuxdvb: S2CMD 01 => 0
The following log from Kodi shows that Tvheadend got unresponsive at subscribing to a channel. (Before that the Channel and EPG infomration was successfully transferred.)
13:17:42 T:139891698554624 DEBUG: PVRManager - OpenLiveStream - opening live stream on channel 'Discovery HD Showcase'
13:17:42 T:139891698554624 DEBUG: opening live stream for channel 'Discovery HD Showcase'
13:17:42 T:139891698554624 INFO: AddOnLog: Tvheadend HTSP Client: SendSubscribe - subscribe to channel '1349997740', subscription 1
13:17:43 T:139891698554624 ERROR: AddOnLog: Tvheadend HTSP Client: ReadResult - 'subscribe to channel' failed - request timed out after 1 seconds
13:17:43 T:139891698554624 ERROR: AddOnLog: Tvheadend HTSP Client: SendSubscribe - failed to subscribe to channel 1349997740, consider the connection dropped
13:17:43 T:139891698554624 DEBUG: AddOnLog: Tvheadend HTSP Client: reconnect triggered
13:17:43 T:139891698554624 ERROR: CDVDPlayer::OpenInputStream - error opening [pvr://channels/tv/Minden csatorna/12.pvr]
13:17:43 T:139891698554624 NOTICE: CDVDPlayer::OnExit()
13:17:43 T:139891698554624 DEBUG: CDVDInputStreamPVRManager::Close - stream closed
13:17:43 T:139891698554624 DEBUG: OnPlayBackStopped: play state was 1, starting 1
13:17:43 T:139891698554624 DEBUG: Thread DVDPlayer 139891698554624 terminating
13:17:43 T:139891681769216 ERROR: AddOnLog: Tvheadend HTSP Client: connection dropped, trying to restore
13:17:43 T:139891681769216 ERROR: AddOnLog: Tvheadend HTSP Client: ReadMessage - not connected
13:17:43 T:139894163797888 DEBUG: OnPlayBackStopped: play state was 3, starting 0
13:17:43 T:139894163797888 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
13:17:43 T:139894163797888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
13:17:43 T:139893158164224 NOTICE: PVRManager - StartPlayback - started playback on channel 'Discovery HD Showcase'
13:17:43 T:139891698554624 DEBUG: POParser: loaded 15 strings from file /usr/share/kodi/addons/pvr.hts/resources/language/Hungarian/strings.po
13:17:43 T:139891698554624 DEBUG: POParser: loaded 0 strings from file /usr/share/kodi/addons/pvr.hts/resources/language/English/strings.po
13:17:43 T:139891698554624 DEBUG: CAddonCallbacksAddon - QueueNotification - Tvheadend HTSP Client - Error Message : ''HTS Tvheadend': Kapcsolat bontva'
13:17:43 T:139891698554624 DEBUG: AddOnLog: Tvheadend HTSP Client: OpenSocket - connecting to '127.0.0.1', port '9982'
13:17:43 T:139891698554624 DEBUG: AddOnLog: Tvheadend HTSP Client: OpenSocket - connected to '127.0.0.1', port '9982'
13:17:45 T:139891698554624 ERROR: AddOnLog: Tvheadend HTSP Client: CHTSPConnection - SendGreeting - failed get a reply after the greeting
13:17:45 T:139891698554624 ERROR: AddOnLog: Tvheadend HTSP Client: Connect - failed to read greeting from the backend
13:17:45 T:139891698554624 DEBUG: AddOnLog: Tvheadend HTSP Client: OpenSocket - connecting to '127.0.0.1', port '9982'
13:17:45 T:139891698554624 DEBUG: AddOnLog: Tvheadend HTSP Client: OpenSocket - connected to '127.0.0.1', port '9982'
13:17:47 T:139894163797888 DEBUG: ------ Window Deinit (DialogKaiToast.xml) ------
13:17:47 T:139891698554624 ERROR: AddOnLog: Tvheadend HTSP Client: CHTSPConnection - SendGreeting - failed get a reply after the greeting
13:17:47 T:139891698554624 ERROR: AddOnLog: Tvheadend HTSP Client: Connect - failed to read greeting from the backend
No connection anymore...
Complete logs are attached. (Sorry, the different logs were collected at different time, but the fault was the same)
Hint:
Files
History
Updated by Jaroslav Kysela almost 10 years ago
Updated by Have you tried to enable 'Full DiseqC' in the tuner / satellite configuration settings ?
Updated by Akos Sz almost 10 years ago
Updated by Today the Openelec addon was upgraded to 4.3.8 (Tvheadend 3.9.2427) The behavior is the same.
According to the suggestion I enabled "Full Diseqc" and it seems working so far. I was unable to reproduce the fault with this settings.
So, this is a good workaround. Thanks for it.
I do not know what this checkbox actually does, however I think the system should be stable even when it is disabled.
Updated by Jaroslav Kysela almost 10 years ago
- Status changed from New to Fixed
I made the 'Full DiseqC' option enabled by default. v3.9-2438-g5a063fe
Anyway, if it does not work - it's the driver fault.. Look to help for the description.
Updated by Andrei B over 9 years ago
Updated by Yea, it seems 'Full DiseqC' escaped me either - I was almost frustrated after upgrade..
By the way - does 'Full DiseqC' option enables when migrating from Tvh 3.4? It was 'off' after Openelec upgrade, and I've had no idea that it can be so important to enable it..
Updated by Andrei B over 9 years ago
These troubles hits me when the PC tries tune channel first time after waking up after suspend. Then, 'Full DiseqC' option helps. Then, it will tune properly without this option enabled - until the next suspend/wakeup cycle.
Updated by Jaroslav Kysela over 9 years ago
Andrei B wrote:
Yea, it seems 'Full DiseqC' escaped me either - I was almost frustrated after upgrade..
By the way - does 'Full DiseqC' option enables when migrating from Tvh 3.4? It was 'off' after Openelec upgrade, and I've had no idea that it can be so important to enable it..
Yes, it should be enabled after upgrade. The only case when it's not enabled is to use the tvh 3.9 versions between this option was introduced (v3.9-2240-g5ba47ff) and the change to enable this by default (v3.9-2438-g5a063fe). TVH can save the "off" state which was default for these versions in this case.
Updated by Andrei B over 9 years ago
Well, probably it was my case
I just think about many other Openelec users, who were caught into this trap..