Video suddenly freezes, buffers and then crashes

Hunduster · January 7, 2024 at 10:43 AM

Hello everyone,

Unfortunately, I have been having sporadic problems playing videos for a few months now.

During playback, the playback suddenly freezes. Kodi briefly shows buffering, but it stops and does not continue. Picture and sound are frozen and after a short time the playback is stopped and you end up back in the selection menu of the movies/series you were watching.

It doesn't matter whether the content is SD, HD or 4k.
Sometimes it runs flawlessly for hours until the error mentioned above occurs.

As of today, I use an RPi4 4GB in an Argon One housing. The content is retrieved from a NAS via NFS.

A lot has changed since the error occurred. The RPi4 has moved from the official Kodi case and SD card to an Argon One with SSD. The network switch has also been replaced in the meantime. Only the NAS is still the same. The error persists.

In the meantime, I activated the debug log once and was able to find the following lines in the log yesterday after the error occurred again at around 00:22.

Code

2024-01-05 23:30:44.057 T:993      info <general>: VideoPlayer::OpenFile: nfs://192.168.1.10/Kodi/Serien/Game of Thrones/Season 5/got-s05e06.mkv
2024-01-05 23:30:44.113 T:4712  warning <general>: OutputPicture - timeout waiting for buffer
2024-01-05 23:30:44.162 T:4706     info <general>: Creating InputStream
2024-01-05 23:30:44.205 T:4706     info <general>: Creating Demuxer
2024-01-05 23:30:44.430 T:4706     info <general>: Opening stream: 0 source: 256
2024-01-05 23:30:44.431 T:4706     info <general>: Creating video codec with codec id: 27
2024-01-05 23:30:44.431 T:4706     info <general>: CDVDVideoCodecDRMPRIME::Open - using decoder V4L2 mem2mem H.264 decoder wrapper
2024-01-05 23:30:44.490 T:4706     info <general>: Opening stream: 1 source: 256
2024-01-05 23:30:44.490 T:4706     info <general>: Finding audio codec for: 86020
2024-01-05 23:30:44.491 T:4706     info <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder dca
2024-01-05 23:30:44.491 T:4706     info <general>: Opening stream: 4 source: 256
2024-01-05 23:30:44.492 T:4713     info <general>: OpenStream: Allowing max Out-Of-Sync Value of 49 ms
2024-01-05 23:30:51.823 T:4712  warning <general>: OutputPicture - timeout waiting for buffer
2024-01-06 00:22:09.737 T:993      info <general>: Skipped 2 duplicate messages..
2024-01-06 00:22:09.737 T:993      info <general>: CVideoPlayer::CloseFile()
2024-01-06 00:22:09.737 T:993      info <general>: VideoPlayer: waiting for threads to exit
2024-01-06 00:22:09.744 T:4706     info <general>: CVideoPlayer::OnExit()
2024-01-06 00:22:09.744 T:4706     info <general>: Closing stream player 1
2024-01-06 00:22:09.744 T:4706     info <general>: Waiting for audio thread to exit
2024-01-06 00:22:09.755 T:4713     info <general>: thread end: CVideoPlayerAudio::OnExit()
2024-01-06 00:22:09.755 T:4706     info <general>: Closing audio device
2024-01-06 00:22:09.805 T:1008     info <general>: CActiveAESink::OpenSink - initialize sink
2024-01-06 00:22:09.806 T:4706     info <general>: Deleting audio codec
2024-01-06 00:22:09.807 T:4706     info <general>: Closing stream player 2
2024-01-06 00:22:09.807 T:4706     info <general>: waiting for video thread to exit
2024-01-06 00:22:09.822 T:4712  warning <general>: OutputPicture - timeout waiting for buffer
2024-01-06 00:22:09.822 T:4712     info <general>: thread end: video_thread
2024-01-06 00:22:09.823 T:4706     info <general>: deleting video codec
2024-01-06 00:22:09.828 T:4706     info <general>: Closing stream player 3
2024-01-06 00:22:09.836 T:5734     info <general>: Deleting settings information for files nfs://192.168.1.10/Kodi/Serien/Game of Thrones/Season 5/got-s05e06.mkv
2024-01-06 00:22:09.843 T:993      info <general>: VideoPlayer: finished waiting
2024-01-06 00:22:09.843 T:993      info <general>: CVideoPlayer::CloseFile()
2024-01-06 00:22:09.843 T:993      info <general>: VideoPlayer: waiting for threads to exit
2024-01-06 00:22:09.843 T:993      info <general>: VideoPlayer: finished waiting
2024-01-06 00:22:10.004 T:1008     info <general>: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=vc4hdmi0,DEV=0"
2024-01-06 00:22:10.008 T:1008     info <general>: CAESinkALSA::Initialize - Opened device "hdmi:CARD=vc4hdmi0,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
2024-01-06 00:22:10.009 T:1008     info <general>: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2024-01-06 00:22:10.009 T:1008     info <general>: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE3
2024-01-06 00:22:10.134 T:5739     info <general>: WEATHER: Downloading weather
2024-01-06 00:22:10.214 T:1029    error <general>: EXCEPTION: Kodi is not playing any file

Display More

**chewitt** · January 8, 2024 at 9:41 AM

Please provide a full debug log.

How to post a log (wiki)

1. Enable debugging in Settings>System Settings>Logging
2. Restart Kodi
3. Replicate the problem
4. Generate a log URL (do not post/upload logs to the forum)

use "Settings > LibreELEC > System > Paste system logs" or run "pastekodi" over SSH, then post the URL link

Hunduster · January 10, 2024 at 11:14 AM

https://paste.libreelec.tv/apt-shark.log

**chewitt** · January 10, 2024 at 11:27 AM

That's not a debug log, and no playback problem is demonstrated.

Hunduster · January 10, 2024 at 3:40 PM

Sorry, my mistake!

Stupid question: can I hide the debug display at the top left of the debug?

The problem is that the described error only occurs every few hours. But we have also had 3 days of silence. In the latter period, however, the error actually occurs once a day.

**Da Flex** · January 10, 2024 at 8:47 PM

Quote from Hunduster

Stupid question: can I hide the debug display at the top left of the debug?

Yes you can. Use log level 1 or 2 at advancedsettings.xml. Then disable debug mode at GUI, and reboot.

**Da Flex** · January 10, 2024 at 8:58 PM

Quote from Hunduster

As of today, I use an RPi4 4GB in an Argon One housing.

Argon One cases are known for soldering issues. Especially small connectors like microHDMI or USB-C are critical. So I suggest test sessions without that case.

Hunduster · January 10, 2024 at 10:07 PM

Quote from Da Flex

Yes you can. Use log level 1 or 2 at advancedsettings.xml. Then disable debug mode at GUI, and reboot.

Does it matter which log level I use for the current troubleshooting, 1 or 2?

Quote from Da Flex

Argon One cases are known for soldering issues. Especially small connectors like microHDMI or USB-C are critical. So I suggest test sessions without that case.

I had already read that, but it can't be that.

I have the same problem with a Raspi 4 in the original Kodi Case with SD card in the bedroom and have exactly the same problem here. It is also completely irrelevant what quality the medium has, SD, HD, 4k, the same problem everywhere.

When I started troubleshooting months ago, I tried everything. The first thing I did was to put the Raspi in the Argon One in the living room. Then I replaced the switch, installed an SSD cache in my NAS and replaced the database. At first I thought it was a release problem, but unfortunately there was no improvement with the current 20.2 either

**Da Flex** · January 11, 2024 at 12:01 AM

Log level 1 will be fine here.

Hunduster · January 12, 2024 at 8:50 PM

Hello everyone,

I was able to reproduce the error today with a movie, if the debug log was activated.

The movie stopped at 19:54. Same behavior again. Picture and sound freeze and after a few seconds playback stops and you end up back in the overview.

https://paste.libreelec.tv/settled-gelding.log

**Da Flex** · January 13, 2024 at 5:41 AM

Quote from Hunduster

The movie stopped at 19:54. Same behavior again.

Yep, that error is visible in the log:

Code

Jan 12 19:54:31.760060 Kodi-WZ connmand[597]: ntp: adjust (slew): -0.012913 sec
Jan 12 19:54:41.015071 Kodi-WZ kernel: rpivid feb10000.codec: rpivid_h265_stop
Jan 12 19:55:08.864468 Kodi-WZ kernel: rpivid feb10000.codec: rpivid_h265_start: (3840x1616)
Jan 12 19:55:08.891862 Kodi-WZ kernel: rpivid feb10000.codec: SPS changed
Jan 12 19:55:08.892280 Kodi-WZ kernel: rpivid feb10000.codec: PPS changed
Jan 12 20:00:00.289036 Kodi-WZ crond[390]: USER root pid 1340 cmd ntpd -n -p 172.22.29.1
Jan 12 20:00:05.659047 Kodi-WZ crond[1174]: ntpd: reply from 172.22.29.1: peer is unsynced
Jan 12 20:00:16.121645 Kodi-WZ crond[1249]: ntpd: reply from 172.22.29.1: peer is unsynced

Looks like an NTP error. Read here:

Thread

NTP Time Server settings

Hey all -

I have just downloaded and installed the latest build of LibreElec Kodi for my Odroid C2 and I'm having an issue with the Time. (BTW, Time was not an issue in the older build at all)

I was hoping the usual pool.ntp.org in Timeserver #1 would work for this build as it did for the other, but it doesn't seem to. I even went so far as to use all 3 Timeservers and put:

Timeserver #1 0.pool.ntp.org
Timeserver #2 1.pool.ntp.org
Timeserver #3 2.pool.ntp.org

and then

Timeserver #1 …

MultimediaGuy

September 6, 2016 at 12:17 AM

**chewitt** · January 13, 2024 at 6:39 AM

Just for testing switch the source from NFS to SMB and see if the issue repeats.

Hunduster · January 13, 2024 at 12:06 PM

Hello,

Thank you very much for your help!

I did indeed replace my firewall with an OPNsense a few months ago and had massive problems with my Raspis when interacting with NTP on the firewall. However, I would never have thought that a faulty NTP query would lead to problems with playback.

I will reconfigure the whole thing, test it and report back to you.

Thank you very much for now, I really appreciate your help!

Hunduster · January 14, 2024 at 10:32 AM

Hello, here I am again.

Yesterday I switched my Kodi systems to public NTP servers, tested them and made sure that Kodi can reach them. I thought I was safe

Unfortunately, the error occurred twice again yesterday, once on January 13 at 22:32 and then again on January 14 at 01:32:

https://paste.libreelec.tv/grand-antelope.log

What I'm reading now is that it's having a problem accessing the network. According to my NAS and my switch, there was no disconnection. However, I have now ordered a new Gbic as a precaution (I have my NAS connected via 10 GE fiber).

Apart from that, I'm at my wit's end. I will test the connection via SMB again, but I have been using Kodi via NFS for almost 10 years.

**Da Flex** · January 14, 2024 at 4:57 PM

Thanks for removing all those NTP errors from the log.

I think your NAS connection is OK, because you don't have the typical "waiting for buffer" warnings in the log.

Most of the current errors are harmless, but I'm not sure about this error:

Code

Feb 16 19:10:56.709875 LibreELEC kernel: vc4-drm gpu: [drm] *ERROR* Failed to read TMDS config: -121
Feb 16 19:10:56.709941 LibreELEC kernel: mmc1: Controller never released inhibit bit(s).
Feb 16 19:10:56.709982 LibreELEC kernel: [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 1
Feb 16 19:10:56.710017 LibreELEC kernel: printk: console [netcon0] enabled
Feb 16 19:10:56.710053 LibreELEC kernel: netconsole: network logging started
Feb 16 19:10:56.710088 LibreELEC kernel: of_cfs_init
Feb 16 19:10:56.710122 LibreELEC kernel: of_cfs_init: OK
Feb 16 19:10:56.710160 LibreELEC kernel: ALSA device list:
Feb 16 19:10:56.710202 LibreELEC kernel:   #0: vc4-hdmi-0
Feb 16 19:10:56.710237 LibreELEC kernel:   #1: vc4-hdmi-1
Feb 16 19:10:56.710271 LibreELEC kernel: mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
Feb 16 19:10:56.710632 LibreELEC kernel: vc4-drm gpu: [drm] *ERROR* Failed to read TMDS config: -121
Feb 16 19:10:56.710686 LibreELEC kernel: Freeing unused kernel memory: 8832K
Feb 16 19:10:56.710722 LibreELEC kernel: Run /init as init process
Feb 16 19:10:56.710757 LibreELEC kernel:   with arguments:
Feb 16 19:10:56.710792 LibreELEC kernel:     /init
Feb 16 19:10:56.710828 LibreELEC kernel:   with environment:
Feb 16 19:10:56.710862 LibreELEC kernel:     HOME=/
Feb 16 19:10:56.710897 LibreELEC kernel:     TERM=linux
Feb 16 19:10:56.710932 LibreELEC kernel:     boot=UUID=1803-0729
Feb 16 19:10:56.710967 LibreELEC kernel:     disk=UUID=d34cd6c2-1dbd-4333-8d42-a1c2a6506acf

Display More

**Da Flex** · January 14, 2024 at 5:22 PM

There is a warning about the <videodatabase> tag at advancedsettings.xml:

Code

2024-01-14 11:26:10.956 T:994      info <general>: Contents of special://profile/advancedsettings.xml are...
                                                   <advancedsettings>
                                                     <loglevel>1</loglevel>
                                                     <videodatabase>
                                                       <type>mysql</type>
                                                       <host>172.22.29.12</host>
                                                       <port>3306</port>
                                                       <user>xbmc</user>
                                                       <pass>*****</pass>
                                                       <name>xbmc_video</name>
                                                     </videodatabase>
                                                     <musicdatabase>
                                                       <type>mysql</type>
                                                       <host>172.22.29.12</host>
                                                       <port>3306</port>
                                                       <user>xbmc</user>
                                                       <pass>*****</pass>
                                                       <name>xbmc_music</name>
                                                     </musicdatabase>
                                                   </advancedsettings>
                                                   
2024-01-14 11:26:10.956 T:994   warning <general>: VIDEO database configuration is experimental.

Display More

Can you do a test run without <videodatabase> content?

Hunduster · January 15, 2024 at 7:34 AM

Do you mean the note with "warning <general>: VIDEO database configuration is experimental"?

As far as I know, this notice has always been in the logs. The background to this is that my entire database is stored centrally on a MySQL server, and has been for a good 10 years.

**Da Flex** · January 15, 2024 at 8:17 AM

Quote from Hunduster

Do you mean the note with "warning <general>: VIDEO database configuration is experimental"?

Yes, but since you have it for such a long time, it's surely not the cause.

Try SMB. I'm running out of ideas.