TVH live streaming buggy

Sal0kyn · April 20, 2023 at 8:34 AM

Hi,

I migrated from LE 9 to LE 11 (it's about time) on my Raspberry Pi 4.

Everything is working fine except TV.

I got a Hauppauge soloHD DVB USB dongle and use TVHeadEnd plugin.

When I play a TV channel, sound plays but I get no image.

In kodi.log this line appears several times : error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
When playing a recording or timeshifting, it works Only live TV sucks
When deactivating DRM PRIME HW decoding, it works (but I must reactivate it to play 4K movies )
It worked on LE 9

Any idea how I could watch live TV without deactivating HW decoding ?

petediscrete · April 20, 2023 at 11:22 AM

Post full logs. It’s impossible to assess what’s happening without them.

Sal0kyn · April 20, 2023 at 3:04 PM

Without HW acceleration (working) :

Code

2023-04-20 15:59:54.450 T:1387     info <general>: VideoPlayer::OpenFile: pvr://channels/tv/Toutes%20les%20cha%c3%aenes/1@pvr.hts_976016704.pvr
2023-04-20 15:59:54.480 T:12450    info <general>: Creating InputStream
2023-04-20 15:59:54.505 T:12450    info <general>: Creating Demuxer
2023-04-20 15:59:55.979 T:12450    info <general>: Opening stream: 1001 source: 256
2023-04-20 15:59:55.985 T:12450    info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 25.000, 3D: false
2023-04-20 15:59:55.998 T:12450    info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: -nan)
2023-04-20 15:59:56.004 T:12450 warning <general>: OpenStream - Unsupported stream 1001. Stream disabled.
2023-04-20 15:59:56.004 T:12450    info <general>: Opening stream: 1002 source: 256
2023-04-20 15:59:56.004 T:12450    info <general>: Finding audio codec for: 86056
2023-04-20 15:59:56.097 T:12450    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder eac3
2023-04-20 15:59:56.097 T:12450    info <general>: Creating audio thread
2023-04-20 15:59:56.097 T:12461    info <general>: running thread: CVideoPlayerAudio::Process()
2023-04-20 15:59:56.098 T:12450    info <general>: Opening stream: 1005 source: 256
2023-04-20 15:59:56.213 T:12450    info <general>: Opening stream: 1001 source: 256
2023-04-20 15:59:56.213 T:12450    info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 25.000, 3D: false
2023-04-20 15:59:56.213 T:12450    info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: -nan)
2023-04-20 15:59:56.227 T:12450    info <general>: Creating video codec with codec id: 27
2023-04-20 15:59:56.227 T:12450    info <general>: CDVDVideoCodecDRMPRIME::Open - using decoder H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2023-04-20 15:59:56.285 T:12450    info <general>: Creating video thread
2023-04-20 15:59:56.285 T:12450    info <general>: Opening stream: 1002 source: 256
2023-04-20 15:59:56.285 T:12450    info <general>: Finding audio codec for: 86056
2023-04-20 15:59:56.286 T:12450    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder eac3
2023-04-20 15:59:56.286 T:12470    info <general>: running thread: video_thread
2023-04-20 15:59:56.286 T:12450    info <general>: Opening stream: 1005 source: 256
2023-04-20 15:59:56.325 T:12461    info <general>: Creating audio stream (codec id: 86056, channels: 2, sample rate: 48000, no pass-through)
2023-04-20 15:59:56.325 T:1518     info <general>: CActiveAE::ApplySettings - Forcing samplerate to 48000
2023-04-20 15:59:56.877 T:1519     info <general>: CActiveAESink::OpenSink - initialize sink
2023-04-20 15:59:56.877 T:1519     info <general>: CAESinkALSA::Initialize - Attempting to open device "sysdefault:CARD=sndrpihifiberry"
2023-04-20 15:59:56.886 T:1387     info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 50.000, 3D: false
2023-04-20 15:59:56.886 T:1387     info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: 0.000)
2023-04-20 15:59:56.919 T:1519     info <general>: CAESinkALSA::Initialize - Opened device "sysdefault:CARD=sndrpihifiberry"
2023-04-20 15:59:56.919 T:1519     info <general>: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2023-04-20 15:59:56.919 T:1519     info <general>: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE4
2023-04-20 15:59:57.383 T:12470 warning <general>: OutputPicture - timeout waiting for buffer
2023-04-20 16:00:03.264 T:1387     info <general>: Skipped 2 duplicate messages..
2023-04-20 16:00:03.264 T:1387     info <general>: CVideoPlayer::CloseFile()
2023-04-20 16:00:03.264 T:1387     info <general>: VideoPlayer: waiting for threads to exit
2023-04-20 16:00:03.328 T:12450    info <general>: CVideoPlayer::OnExit()
2023-04-20 16:00:03.328 T:12450    info <general>: Closing stream player 1
2023-04-20 16:00:03.328 T:12450    info <general>: Waiting for audio thread to exit
2023-04-20 16:00:03.346 T:12461    info <general>: thread end: CVideoPlayerAudio::OnExit()
2023-04-20 16:00:03.346 T:12450    info <general>: Closing audio device
2023-04-20 16:00:03.396 T:12450    info <general>: Deleting audio codec
2023-04-20 16:00:03.396 T:12450    info <general>: Closing stream player 2
2023-04-20 16:00:03.396 T:12450    info <general>: waiting for video thread to exit
2023-04-20 16:00:03.397 T:1518     info <general>: CActiveAE::ApplySettings - Forcing samplerate to 48000
2023-04-20 16:00:03.445 T:12470 warning <general>: OutputPicture - timeout waiting for buffer
2023-04-20 16:00:03.445 T:12470    info <general>: thread end: video_thread
2023-04-20 16:00:03.446 T:12450    info <general>: deleting video codec
2023-04-20 16:00:03.450 T:12450    info <general>: Closing stream player 3
2023-04-20 16:00:03.454 T:1387     info <general>: VideoPlayer: finished waiting
2023-04-20 16:00:03.454 T:1387     info <general>: CVideoPlayer::CloseFile()
2023-04-20 16:00:03.454 T:1387     info <general>: VideoPlayer: waiting for threads to exit
2023-04-20 16:00:03.454 T:1387     info <general>: VideoPlayer: finished waiting

Display More

With HW acceleration (not working) :

Code

2023-04-20 16:00:33.066 T:1387     info <general>: VideoPlayer::OpenFile: pvr://channels/tv/Toutes%20les%20cha%c3%aenes/1@pvr.hts_976016704.pvr
2023-04-20 16:00:33.068 T:12521    info <general>: Creating InputStream
2023-04-20 16:00:33.069 T:12521    info <general>: Creating Demuxer
2023-04-20 16:00:33.783 T:12521    info <general>: Opening stream: 1001 source: 256
2023-04-20 16:00:33.784 T:12521    info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 25.000, 3D: false
2023-04-20 16:00:33.784 T:12521    info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: -nan)
2023-04-20 16:00:33.785 T:12521 warning <general>: OpenStream - Unsupported stream 1001. Stream disabled.
2023-04-20 16:00:33.785 T:12521    info <general>: Opening stream: 1002 source: 256
2023-04-20 16:00:33.785 T:12521    info <general>: Finding audio codec for: 86056
2023-04-20 16:00:33.785 T:12521    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder eac3
2023-04-20 16:00:33.785 T:12521    info <general>: Creating audio thread
2023-04-20 16:00:33.786 T:12531    info <general>: running thread: CVideoPlayerAudio::Process()
2023-04-20 16:00:33.786 T:12521    info <general>: Opening stream: 1005 source: 256
2023-04-20 16:00:33.876 T:12521    info <general>: Opening stream: 1001 source: 256
2023-04-20 16:00:33.876 T:12521    info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 25.000, 3D: false
2023-04-20 16:00:33.876 T:12521    info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: -nan)
2023-04-20 16:00:33.884 T:12521    info <general>: Creating video codec with codec id: 27
2023-04-20 16:00:33.884 T:12521    info <general>: CDVDVideoCodecDRMPRIME::Open - using decoder V4L2 mem2mem H.264 decoder wrapper
2023-04-20 16:00:33.910 T:12521    info <general>: Creating video thread
2023-04-20 16:00:33.910 T:12536    info <general>: running thread: video_thread
2023-04-20 16:00:33.911 T:12521    info <general>: Opening stream: 1002 source: 256
2023-04-20 16:00:33.911 T:12521    info <general>: Finding audio codec for: 86056
2023-04-20 16:00:33.912 T:12521    info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder eac3
2023-04-20 16:00:33.912 T:12521    info <general>: Opening stream: 1005 source: 256
2023-04-20 16:00:36.031 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:00:36.235 T:12531    info <general>: Skipped 14 duplicate messages..
2023-04-20 16:00:36.235 T:12531    info <general>: Creating audio stream (codec id: 86056, channels: 2, sample rate: 48000, no pass-through)
2023-04-20 16:00:36.235 T:1518     info <general>: CActiveAE::ApplySettings - Forcing samplerate to 48000
2023-04-20 16:00:36.270 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:00:36.445 T:1387     info <general>: Skipped 11 duplicate messages..
2023-04-20 16:00:36.445 T:1387     info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 25.000, 3D: false
2023-04-20 16:00:36.446 T:1387     info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: 0.000)
2023-04-20 16:00:36.454 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:00:46.536 T:12536    info <general>: Skipped 271 duplicate messages..
2023-04-20 16:00:46.536 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:00:56.537 T:12536    info <general>: Skipped 249 duplicate messages..
2023-04-20 16:00:56.537 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:01:06.546 T:12536    info <general>: Skipped 250 duplicate messages..
2023-04-20 16:01:06.546 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:01:16.780 T:12536    info <general>: Skipped 251 duplicate messages..
2023-04-20 16:01:16.780 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:01:26.805 T:12536    info <general>: Skipped 254 duplicate messages..
2023-04-20 16:01:26.805 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:01:36.830 T:12536    info <general>: Skipped 248 duplicate messages..
2023-04-20 16:01:36.830 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:01:46.840 T:12536    info <general>: Skipped 254 duplicate messages..
2023-04-20 16:01:46.840 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:01:56.865 T:12536    info <general>: Skipped 247 duplicate messages..
2023-04-20 16:01:56.865 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:02:06.971 T:12536    info <general>: Skipped 250 duplicate messages..
2023-04-20 16:02:06.971 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:02:17.004 T:12536    info <general>: Skipped 246 duplicate messages..
2023-04-20 16:02:17.004 T:12536   error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-20 16:02:25.914 T:1387     info <general>: Skipped 225 duplicate messages..
2023-04-20 16:02:25.914 T:1387     info <general>: CVideoPlayer::CloseFile()
2023-04-20 16:02:25.914 T:1387     info <general>: VideoPlayer: waiting for threads to exit
2023-04-20 16:02:25.987 T:12521    info <general>: CVideoPlayer::OnExit()
2023-04-20 16:02:25.987 T:12521    info <general>: Closing stream player 1
2023-04-20 16:02:25.987 T:12521    info <general>: Waiting for audio thread to exit
2023-04-20 16:02:25.996 T:12531    info <general>: thread end: CVideoPlayerAudio::OnExit()
2023-04-20 16:02:25.996 T:12521    info <general>: Closing audio device
2023-04-20 16:02:26.045 T:12521    info <general>: Deleting audio codec
2023-04-20 16:02:26.046 T:1518     info <general>: CActiveAE::ApplySettings - Forcing samplerate to 48000
2023-04-20 16:02:26.046 T:12521    info <general>: Closing stream player 2
2023-04-20 16:02:26.046 T:12521    info <general>: waiting for video thread to exit
2023-04-20 16:02:26.046 T:12536    info <general>: thread end: video_thread
2023-04-20 16:02:26.046 T:12521    info <general>: deleting video codec
2023-04-20 16:02:26.062 T:12521    info <general>: Closing stream player 3
2023-04-20 16:02:26.065 T:1387     info <general>: VideoPlayer: finished waiting
2023-04-20 16:02:26.065 T:1387     info <general>: CVideoPlayer::CloseFile()
2023-04-20 16:02:26.065 T:1387     info <general>: VideoPlayer: waiting for threads to exit
2023-04-20 16:02:26.065 T:1387     info <general>: VideoPlayer: finished waiting

Display More

Differences begin at line 18

**chewitt** · April 21, 2023 at 3:27 AM

Please post a full debug log. Primarily because it contains other information of relevance, but also because repeated failure to provide one when asked just means all the forum staff think you're a pirate trying to hide dirty habits and we ignore the thread.

Sal0kyn · April 21, 2023 at 6:08 AM

Hi,

Sorry I did not get the point about pirates ...

I'm not sure how to get "a full debug log". Is this what you ask? http://ix.io/4tTL

(BTW the forum search give me a "unresolvable problem")

**chewitt** · April 21, 2023 at 4:22 PM

It's not a debug log .. and you don't demonstrate the problem by playing anything. So not much use for investigations.

Unrelated to the problem, I do see that the Hyperion add-on is continuously faulting in the background. It's not supported under LE10/LE11 so you might as well disable / remove it.

Sal0kyn · April 21, 2023 at 11:34 PM

Sorry, could you explain how I can obtain this debug log please?

I posted the kodi.log part where I start playing TV with and without the hw acceleration and you told me it wasnt enough.

**chewitt** · April 24, 2023 at 7:35 AM

Initiative test .. what happens when you type "LibreELEC debug log" into Google?

Sal0kyn · April 24, 2023 at 5:43 PM

Here are debug logs : https://paste.chapril.org/?da1cba3c194bc…yp6S7vuVg5VDJeH

Playing TV begins at: 2023-04-24 18:23:59.545 T:1457

I made 4 tries. The first one, video worked (I don't know why) the next 3 did not work.

twilightened · April 24, 2023 at 6:20 PM

It is highly likely that this is associated with this:

Thread

LE 10.0.3 RPi 4 TVH Video freezing whilst Audio continues

Since starting to use LE 10 on my RPi 4 with TVHeadend for live TV, I've had some intermittent issues which cause the picture to freeze but the audio keeps playing. I think it's happening when the stream has some errors which the video player on the RPi doesn't recover from. I'm guessing it's either network traffic or CPU usage on my TVH server which can cause inconsistencies in the TVH stream. I do some re-encoding on the SD streams to make them compatible with Hyperion (a bit of a hack). This…

Morphy

December 31, 2022 at 1:55 PM

Sal0kyn · April 25, 2023 at 6:15 AM

Indeed. I already faced this problem on LE10. That's why I switched back to LE9 and kept using it until now.

**chewitt** · April 25, 2023 at 10:07 AM

Code

2023-04-24 18:04:04.764 T:1428     info <general>: Found resolution 1280x720 with 1280x720 @ 60.000000 Hz
2023-04-24 18:04:04.765 T:1428     info <general>: Found resolution 1920x1080 with 1920x1080i @ 60.000000 Hz
2023-04-24 18:04:04.765 T:1428     info <general>: Found resolution 1920x1080 with 1920x1080i @ 59.940063 Hz
2023-04-24 18:04:04.765 T:1428     info <general>: Found resolution 1920x1080 with 1920x1080i @ 50.000000 Hz
2023-04-24 18:04:04.765 T:1428     info <general>: Found resolution 1280x720 with 1280x720 @ 59.940063 Hz
2023-04-24 18:04:04.765 T:1428     info <general>: Found resolution 1280x720 with 1280x720 @ 50.000000 Hz

The mode list ^ shows you haven an older "HD Ready" TV that does 720p max. Kodi only outputs progressive so we ignore the 1080 interlaced modes that are available.

Code

2023-04-24 18:24:48.646 T:3321     info <general>: [WHITELIST] Searching the whitelist for: width: 1920, height: 1080, fps: 25.000, 3D: false
...
2023-04-24 18:24:48.646 T:3321    debug <general>: [WHITELIST] Matched a desktop resolution with double the refresh rate 1280x720 @ 50.000000 Hz (22)
2023-04-24 18:24:48.646 T:3321     info <general>: Display resolution ADJUST : 1280x720 @ 50.000000 Hz (22) (weight: -nan)
2023-04-24 18:24:48.651 T:3321  warning <general>: OpenStream - Unsupported stream 1001. Stream disabled.

The 2/3/4 plays in the log follow this format; note the unsupported stream warning. The first play doesn't show the warning .. not sure why but all are trying to play 1080@25 media at 720@50 which probably isn't going to work.

In most countries channels are broadcast in 540p (PAL) or 480p (NTSC) "SD" versions and 720p or 1080p "HD" versions. As you don't have a 1080p capable TV you will need to remove/ignore the 1080p HD channels in your channel list.

Sal0kyn · April 25, 2023 at 11:04 AM

Interesting, I will give a try with a 1080p PC screen.

Anyway, as it worked once (first try) or while playing a recording, there must be another reason. Any other video file, even 4K, plays smoothly with this TV.

I'll also try to deactivate "Adjust display refresh rate" option and see if it change something.

Quote from Sal0kyn

Any other video file, even 4K, plays smoothly with this TV.

Any online video streams work perfectly as well (Youtube, Catchup TV & more, ...)

Sal0kyn · April 25, 2023 at 6:05 PM

So I tested with a 1920x1080 PC screen.

Almost the same except a frozen image instead of a black screen.

Here are the logs http://ix.io/4ugC

I made 3 plays. 1st (@18:43:29) and 2nd (@18:43:58) with "Adjust display refresh rate" = "On start". The 3rd (@18:45:10) with "Adjust display refresh rate" = "Off".

Still the same kind of errors :

Code

2023-04-25 18:45:14.392 T:3317    debug <general>: CVideoPlayer::CheckContinuity - resync forward :1, prev:960000.000000, curr:3599988.000000, diff:1775644.000000
2023-04-25 18:45:14.449 T:3317    debug <general>: CVideoPlayer::CheckContinuity - resync forward :2, prev:1784344.000000, curr:4644333.000000, diff:2819989.000000
2023-04-25 18:45:14.449 T:3324    error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-25 18:45:14.497 T:3317    debug <general>: CVideoPlayer::CheckContinuity - resync forward :2, prev:1784344.000000, curr:4664333.000000, diff:2839989.000000
2023-04-25 18:45:14.497 T:3324    error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-25 18:45:14.528 T:3317    debug <general>: CVideoPlayer::CheckContinuity - resync forward :1, prev:960000.000000, curr:3623988.000000, diff:1799644.000000
2023-04-25 18:45:14.528 T:3317    debug <general>: CVideoPlayer::CheckContinuity - resync forward :1, prev:960000.000000, curr:3647988.000000, diff:1823644.000000
2023-04-25 18:45:14.528 T:3317    debug <general>: CVideoPlayer::CheckContinuity - resync forward :1, prev:960000.000000, curr:3671988.000000, diff:1847644.000000
2023-04-25 18:45:14.528 T:3317    debug <general>: CVideoPlayer::CheckContinuity - update correction: 1847644.000000
2023-04-25 18:45:14.576 T:3324    error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-25 18:45:14.739 T:1462     info <general>: Skipped 14 duplicate messages..
2023-04-25 18:45:14.739 T:1462    debug <general>: ActiveAE::SyncStream - average error 0.896288 below threshold of 30.000000
2023-04-25 18:45:14.752 T:3324    error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)
2023-04-25 18:45:19.321 T:3317     info <general>: Skipped 226 duplicate messages..
2023-04-25 18:45:19.321 T:3317    debug <general>: CDVDClock::SetSpeedAdjust - adjusted:0.000000
2023-04-25 18:45:19.321 T:3324    error <general>: CDVDVideoCodecDRMPRIME::AddData - send packet failed: End of file (-541478725)

Display More

Sal0kyn · April 29, 2023 at 9:17 PM

Is there some way to automatically force SW prime drm decoding for tvhend video ? A blacklist or something ?

twilightened · April 29, 2023 at 11:02 PM

Now that you have the logs, i suggest you to open a bug report in official Kodi github.

Issues · xbmc/xbmc

Kodi is an award-winning free and open source home theater/media center software and entertainment hub for digital media. With its beautiful interface and…

github.com

And just on the off chance that it is not a Kodi bug but a Libreelec bug, you can also open the same bug report in here too: