Disconnecting from server when starting play back of a tv-recording
#1
Hi,

I have a NVidia Shield TV (P2571) running Kodi 19.0, with TVHeadend addon 8.3.0. I'm running Tvheadend 4.2.8-34~g24a2f59e9 on my Pi4B.
The Shield is setup to never sleep (not when changing input of the tv, nor when shutting down the tv). In the router logs I don't see anything that would indicate the Shield is disconnecting so I assume it stays connected.
Now, after watching TV for a while (or turning off the tv) and then changing input back to my NVidia Shield TV and trying to play back a recording (made with the TVHeadend backend server), I very often (perhaps always) get an error "Server not responding correctly" from TVHeadend HTSP Client.
The procedure is always the same as seen in below logs of TVHeadend: Disconnected, Got connection, Disconnected, Got connection which can take up to 8 seconds in total.
I'm not sure when this started happening.
I already rebooted the Shield, uninstalled and reinstalled Kodi, but the problem remains.

So at 18:53 I tried to play back recording "Ik vertrek", problem as described.
I have debug logging on in Kodi, here is the log: https://paste.kodi.tv/oholebuxiv.kodi

Short fragment of TVHeadend log:
Apr 20 18:53:27 raspberrypi tvheadend[16370]: htsp: Opening file /media/NDAS/Recordings/Ik vertrek: Even weg/Ik vertrek: Even weg.ts -- OK
Apr 20 18:53:32 raspberrypi tvheadend[16370]: htsp: Got connection from 192.168.2.13
Apr 20 18:53:32 raspberrypi tvheadend[16370]: htsp: 192.168.2.13: Welcomed client software: Kodi Media Center (HTSPv34)
Apr 20 18:53:32 raspberrypi tvheadend[16370]: htsp: 192.168.2.13 [ Kodi Media Center ]: Identified as user 'tvheadend'
Apr 20 18:53:32 raspberrypi tvheadend[16370]: htsp: 192.168.2.13 [ tvheadend | Kodi Media Center ]: Privileges updated
Apr 20 18:53:32 raspberrypi tvheadend[16370]: htsp: Opening file /media/NDAS/Recordings/Ik vertrek: Even weg/Ik vertrek: Even weg.ts -- OK
Apr 20 18:53:33 raspberrypi tvheadend[16370]: htsp: Closed opened file /media/NDAS/Recordings/Ik vertrek: Even weg/Ik vertrek: Even weg.ts
Apr 20 18:53:33 raspberrypi tvheadend[16370]: subscription: 01E5: "HTSP" unsubscribing, hostname="192.168.2.13", username="tvheadend", client="Kodi Media Center"
Apr 20 18:53:33 raspberrypi tvheadend[16370]: htsp: 192.168.2.13 [ tvheadend | Kodi Media Center ]: Disconnected
Apr 20 18:53:33 raspberrypi tvheadend[16370]: htsp: Got connection from 192.168.2.13
Apr 20 18:53:33 raspberrypi tvheadend[16370]: htsp: 192.168.2.13: Welcomed client software: Kodi Media Center (HTSPv34)
Apr 20 18:53:33 raspberrypi tvheadend[16370]: htsp: 192.168.2.13 [ Kodi Media Center ]: Identified as user 'tvheadend'
Apr 20 18:53:33 raspberrypi tvheadend[16370]: htsp: 192.168.2.13 [ tvheadend | Kodi Media Center ]: Privileges updated
Apr 20 18:53:34 raspberrypi tvheadend[16370]: htsp: 192.168.2.13 [ tvheadend | Kodi Media Center ]: Disconnected

I hope somebody can help me.

Wim
Reply
#2
Bump
Reply
#3
So I uninstalled Kodi 19 and installed Kodi 18
Tried playing back a recording multiple times (always same recording), a couple of times without issues, today with an issue (recording wasn't being played).
At 13.01 I tried to play recording "Droomhuis op het platteland".

This is the part of the log since:
https://paste.kodi.tv/ocijokihan.kodi

with 9x
ERROR:    AddOnLog: Tvheadend HTSP Client: pvr.hts .......

No disconnect and reconnect this time, just not playing the file. In the second attempt it was played.
Reply
#4
There's lots of this in the log.

2021-04-20 18:53:40.765 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing SPS 0 referenced in buffering period
2021-04-20 18:53:40.765 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing PPS 0 referenced
2021-04-20 18:53:40.765 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing SPS 0 referenced in buffering period
2021-04-20 18:53:40.766 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing PPS 0 referenced
2021-04-20 18:53:40.766 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] decode_slice_header error
2021-04-20 18:53:40.766 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] no frame!
2021-04-20 18:53:40.766 T:2966 INFO <general>: ffmpeg[0x2be6690040X]: [mpegts] decoding for stream 0 failed
2021-04-20 18:53:40.767 T:2966 DEBUG <general>: ffmpeg[0x2be6690040X]: [mpegts] start time for stream 5 is not set in estimate_timings_from_pts
2021-04-20 18:53:40.767 T:2966 DEBUG <general>: ffmpeg[0x2be6690040X]: [mpegts] start time for stream 6 is not set in estimate_timings_from_pts
2021-04-20 18:53:40.767 T:2966 DEBUG <general>: ffmpeg[0x2be6690040X]: [mpegts] start time for stream 7 is not set in estimate_timings_from_pts
2021-04-20 18:53:40.793 T:2966 DEBUG <general>: AddOnLog: pvr.hts: vfs read failed after 1 attempts
2021-04-20 18:53:40.795 T:2966 DEBUG <general>: Skipped 2 duplicate messages..

My gut feeling here is that the recording has a lot of data errors and is simply unplayable.

Does the recording play on the Pi? With the first LibreElec 10 beta for Pi4, I had a lot of data errors. With the second beta it's much better. Don't know if you are actually using LibreElec.

Check the TVHeadEnd web interface for data errors in the recording.
Reply
#5
(2021-04-30, 09:46)mcelliott Wrote: There's lots of this in the log.

2021-04-20 18:53:40.765 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing SPS 0 referenced in buffering period
2021-04-20 18:53:40.765 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing PPS 0 referenced
2021-04-20 18:53:40.765 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing SPS 0 referenced in buffering period
2021-04-20 18:53:40.766 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] non-existing PPS 0 referenced
2021-04-20 18:53:40.766 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] decode_slice_header error
2021-04-20 18:53:40.766 T:2966 ERROR <general>: ffmpeg[0x2be6690040X]: [h264] no frame!
2021-04-20 18:53:40.766 T:2966 INFO <general>: ffmpeg[0x2be6690040X]: [mpegts] decoding for stream 0 failed
2021-04-20 18:53:40.767 T:2966 DEBUG <general>: ffmpeg[0x2be6690040X]: [mpegts] start time for stream 5 is not set in estimate_timings_from_pts
2021-04-20 18:53:40.767 T:2966 DEBUG <general>: ffmpeg[0x2be6690040X]: [mpegts] start time for stream 6 is not set in estimate_timings_from_pts
2021-04-20 18:53:40.767 T:2966 DEBUG <general>: ffmpeg[0x2be6690040X]: [mpegts] start time for stream 7 is not set in estimate_timings_from_pts
2021-04-20 18:53:40.793 T:2966 DEBUG <general>: AddOnLog: pvr.hts: vfs read failed after 1 attempts
2021-04-20 18:53:40.795 T:2966 DEBUG <general>: Skipped 2 duplicate messages..

My gut feeling here is that the recording has a lot of data errors and is simply unplayable.

Does the recording play on the Pi? With the first LibreElec 10 beta for Pi4, I had a lot of data errors. With the second beta it's much better. Don't know if you are actually using LibreElec.

Check the TVHeadEnd web interface for data errors in the recording.
Hi and thanks for the response,

I'm not using LibreElec, I'm using the Pi (with Raspberry Pi OS) for tvheadend and Kodi on my Nvidia Shield. I deleted the recording you are referring to, so I don't know if it had those errors.
Since then, every time, I am using the same (very short) recording (Droomhuis op het platteland) which has 0 errors. With this file, yesterday's problem occurred (see post above), so that's not the problem.

Yesterday I made a cronjob in the pi which writes to the external hard drive every 10 minutes to make sure the hard disk is not going to sleep and that's the cause of the issue.
I'm checking regularly, starting that same recording, to see if the problem still exists.

Hope we can find the issue.

Wim
Reply
#6
Well, after running the cronjob for 4 days, no more errors. It seems the hard disk goes asleep causing this issue.
Sorry for the trouble and thanks.

Wim
Reply

Logout Mark Read Team Forum Stats Members Help
Disconnecting from server when starting play back of a tv-recording0