Files not playing on R-Pi

Files are not playing in OSMC on my R-Pi unless I transcribe them to MP4 via HandBrake.
It never used to have problems with MKV files.

The file starts to play, but no sound, gets slower and slower over a few seconds, then hangs.

This is the codec info that VLC shows for the file:

10-but H264 is not supported on Pi.

This is probably anime.

No, not anime. Tons of video encoded in H264, some thing seemingly uniquely.
I was fairly sure this used to work …

The interesting thing is that this is how VLC reports the media after passing it through handbrake converting to 720p mp4:

Sorry – I’ve misread that. It doesn’t look like Hi10, so should play fine.

My suggestion is to post some logs.

Here is an example log:

2021-12-22 16:57:07.310 T:402 INFO : VideoPlayer::OpenFile: nfs://10.0.0.70/volume1/video/Movies/test.mp4
2021-12-22 16:57:07.313 T:2208 INFO : Creating InputStream
2021-12-22 16:57:07.470 T:2208 INFO : Creating Demuxer
2021-12-22 16:57:09.355 T:2208 INFO : Opening stream: 0 source: 256
2021-12-22 16:57:09.355 T:2208 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 800, fps: 23.976, 3D: false
2021-12-22 16:57:09.356 T:2208 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 23.976025, flags: 0x0
2021-12-22 16:57:09.356 T:2208 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 24.000000, flags: 0x0
2021-12-22 16:57:09.356 T:2208 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 59.940063, flags: 0x0
2021-12-22 16:57:09.356 T:2208 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 60.000000, flags: 0x0
2021-12-22 16:57:09.356 T:2208 INFO : Skipped 1 duplicate messages…
2021-12-22 16:57:09.356 T:2208 INFO : Display resolution ADJUST : 1920x1080 @ 23.976025 Hz (41) (weight: 0.000)
2021-12-22 16:57:09.369 T:402 INFO : VideoPlayer: OnLostDisplay received
2021-12-22 16:57:09.369 T:402 WARNING : CDVDMessageQueue(audio)::Put MSGQ_NOT_INITIALIZED
2021-12-22 16:57:09.369 T:402 WARNING : CDVDMessageQueue(video)::Put MSGQ_NOT_INITIALIZED
2021-12-22 16:57:09.370 T:402 INFO : GLES: Maximum texture width: 2048
2021-12-22 16:57:09.371 T:2208 INFO : Creating video codec with codec id: 27
2021-12-22 16:57:09.371 T:2208 INFO : CDVDVideoCodecDRMPRIME::Open - using decoder V4L2 mem2mem H.264 decoder wrapper
2021-12-22 16:57:09.425 T:2208 INFO : Creating video thread
2021-12-22 16:57:09.425 T:2210 INFO : running thread: video_thread
2021-12-22 16:57:09.426 T:2208 INFO : Opening stream: 1 source: 256
2021-12-22 16:57:09.426 T:2208 INFO : Finding audio codec for: 86018
2021-12-22 16:57:09.429 T:402 INFO : VideoPlayer: OnResetDisplay received
2021-12-22 16:57:09.429 T:402 WARNING : CDVDMessageQueue(audio)::Put MSGQ_NOT_INITIALIZED
2021-12-22 16:57:09.431 T:2208 INFO : Skipped 1 duplicate messages…
2021-12-22 16:57:09.431 T:2208 INFO : CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder aac
2021-12-22 16:57:09.431 T:2208 INFO : Creating audio thread
2021-12-22 16:57:09.431 T:2211 INFO : running thread: CVideoPlayerAudio::Process()
2021-12-22 16:57:09.443 T:2211 INFO : Creating audio stream (codec id: 86018, channels: 6, sample rate: 48000, no pass-through)
2021-12-22 16:57:09.445 T:428 INFO : CActiveAESink::OpenSink - initialize sink
2021-12-22 16:57:09.445 T:428 INFO : CAESinkALSA::Initialize - Attempting to open device “hdmi:CARD=vc4hdmi,DEV=0”
2021-12-22 16:57:09.454 T:428 INFO : CAESinkALSA::Initialize - Opened device “hdmi:CARD=vc4hdmi,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x02”
2021-12-22 16:57:09.456 T:428 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2021-12-22 16:57:09.456 T:428 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE3
2021-12-22 16:57:09.461 T:428 WARNING : CAESinkAlsa::InitializeHW - Using default alsa values - set failed
2021-12-22 16:57:09.462 T:428 INFO : CAESinkALSA::Initialize - Attempting to open device “default”
2021-12-22 16:57:09.475 T:428 INFO : CAESinkALSA::Initialize - Opened device “default”
2021-12-22 16:57:09.479 T:428 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2021-12-22 16:57:09.480 T:428 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE3
2021-12-22 16:57:09.490 T:428 WARNING : CAESinkAlsa::InitializeHW - Using default alsa values - set failed
2021-12-22 16:57:09.492 T:428 ERROR : CActiveAESink::OpenSink - no sink was returned
2021-12-22 16:57:09.493 T:427 ERROR : ActiveAE::InitSink - returned error
2021-12-22 16:57:09.493 T:427 WARNING : CActiveAE::StateMachine - signal: 11 from port: OutputControlPort not handled for state: 2
2021-12-22 16:57:09.493 T:427 WARNING : CActiveAE::StateMachine - signal: 12 from port: OutputControlPort not handled for state: 2
2021-12-22 16:57:10.015 T:402 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 800, fps: 23.976, 3D: false
2021-12-22 16:57:10.016 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 23.976025, flags: 0x0
2021-12-22 16:57:10.017 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 24.000000, flags: 0x0
2021-12-22 16:57:10.017 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 59.940063, flags: 0x0
2021-12-22 16:57:10.017 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 60.000000, flags: 0x0
2021-12-22 16:57:10.017 T:402 INFO : Skipped 1 duplicate messages…
2021-12-22 16:57:10.017 T:402 INFO : Display resolution ADJUST : 1920x1080 @ 23.976025 Hz (41) (weight: 0.000)
2021-12-22 16:57:11.847 T:2211 ERROR : CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
2021-12-22 16:57:22.705 T:2211 ERROR : Skipped 5 duplicate messages…
2021-12-22 16:57:22.705 T:2211 ERROR : CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
2021-12-22 16:57:33.564 T:2211 ERROR : Skipped 5 duplicate messages…
2021-12-22 16:57:33.564 T:2211 ERROR : CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
2021-12-22 16:57:41.295 T:402 INFO : Skipped 4 duplicate messages…
2021-12-22 16:57:41.295 T:402 INFO : [WHITELIST] Searching the whitelist for: width: 1920, height: 800, fps: 23.976, 3D: false
2021-12-22 16:57:41.296 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 23.976025, flags: 0x0
2021-12-22 16:57:41.296 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 24.000000, flags: 0x0
2021-12-22 16:57:41.296 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 59.940063, flags: 0x0
2021-12-22 16:57:41.296 T:402 ERROR : ** T99 ** 1920/800 vs. 1920/1080 - 23.976025 vs. 60.000000, flags: 0x0
2021-12-22 16:57:41.297 T:402 INFO : Skipped 1 duplicate messages…
2021-12-22 16:57:41.297 T:402 INFO : Display resolution ADJUST : 1920x1080 @ 23.976025 Hz (41) (weight: 0.000)
2021-12-22 16:57:42.613 T:2211 ERROR : CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
2021-12-22 16:57:46.673 T:402 INFO : Skipped 2 duplicate messages…
2021-12-22 16:57:46.673 T:402 INFO : CVideoPlayer::CloseFile()
2021-12-22 16:57:46.674 T:402 INFO : VideoPlayer: waiting for threads to exit
2021-12-22 16:57:46.677 T:2208 INFO : CVideoPlayer::OnExit()
2021-12-22 16:57:46.679 T:2208 INFO : Closing stream player 1
2021-12-22 16:57:46.679 T:2208 INFO : Waiting for audio thread to exit
2021-12-22 16:57:48.042 T:2211 ERROR : CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
2021-12-22 16:57:48.042 T:2211 INFO : thread end: CVideoPlayerAudio::OnExit()
2021-12-22 16:57:48.042 T:2208 INFO : Closing audio device
2021-12-22 16:57:48.083 T:428 INFO : CActiveAESink::OpenSink - initialize sink
2021-12-22 16:57:48.084 T:428 INFO : CAESinkALSA::Initialize - Attempting to open device “hdmi:CARD=vc4hdmi,DEV=0”
2021-12-22 16:57:48.084 T:2208 INFO : Deleting audio codec
2021-12-22 16:57:48.085 T:2208 INFO : Closing stream player 2
2021-12-22 16:57:48.085 T:2208 INFO : waiting for video thread to exit
2021-12-22 16:57:48.085 T:2210 ERROR : Got MSGQ_ABORT or MSGO_IS_ERROR return true
2021-12-22 16:57:48.086 T:2210 INFO : thread end: video_thread
2021-12-22 16:57:48.086 T:2208 INFO : deleting video codec
2021-12-22 16:57:48.097 T:428 INFO : CAESinkALSA::Initialize - Opened device “hdmi:CARD=vc4hdmi,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00”
2021-12-22 16:57:48.100 T:428 INFO : CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
2021-12-22 16:57:48.100 T:428 INFO : CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE3
2021-12-22 16:57:48.122 T:2214 INFO : Deleting settings information for files nfs://10.0.0.70/volume1/video/Movies/The.Matrix.Resurrections.mp4
2021-12-22 16:57:48.132 T:402 INFO : VideoPlayer: finished waiting
2021-12-22 16:57:48.132 T:402 INFO : CVideoPlayer::CloseFile()
2021-12-22 16:57:48.132 T:402 INFO : VideoPlayer: waiting for threads to exit
2021-12-22 16:57:48.132 T:402 INFO : VideoPlayer: finished waiting
2021-12-22 16:57:48.219 T:402 INFO : GLES: Maximum texture width: 2048
2021-12-22 16:57:58.041 T:2214 INFO : CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10

A bit more info. I found a tool to give a fair amount of info on the video codec, so used it to compare a couple of files. The first is the video file (mp4) that doesn’t work (plays a few frames, slows, hangs). The second is the same thing passed through HandBrake, which works fine.

This one fails:

General
Format : MPEG-4
Format profile : Base Media
Codec ID : isom (isom/iso2/avc1/mp41)
File size : 2.73 GiB
Duration : 2 h 27 min
Overall bit rate : 2 639 kb/s
Writing application : Lavf58.39.101

Video
ID : 1
Format : AVC
Format/Info : Advanced Video Codec
Format profile : High@L4.1
Format settings : CABAC / 4 Ref Frames
Format settings, CABAC : Yes
Format settings, Reference frames : 4 frames
Codec ID : avc1
Codec ID/Info : Advanced Video Coding
Duration : 2 h 27 min
Bit rate : 2 250 kb/s
Width : 1 920 pixels
Height : 800 pixels
Display aspect ratio : 2.40:1
Frame rate mode : Constant
Frame rate : 23.976 (24000/1001) FPS
Color space : YUV
Chroma subsampling : 4:2:0
Bit depth : 8 bits
Scan type : Progressive
Bits/(Pixel*Frame) : 0.061
Stream size : 2.32 GiB (85%)
Writing library : x264 core 159
Encoding settings : cabac=1 / ref=4 / deblock=1:-1:-1 / analyse=0x3:0x133 / me=umh / subme=9 / psy=1 / psy_rd=1.00:0.15 / mixed_ref=1 / me_range=24 / chroma_me=1 / trellis=2 / 8x8dct=1 / cqm=0 / deadzone=21,11 / fast_pskip=0 / chroma_qp_offset=-3 / threads=18 / lookahead_threads=1 / sliced_threads=0 / nr=0 / decimate=1 / interlaced=0 / bluray_compat=0 / constrained_intra=0 / bframes=3 / b_pyramid=2 / b_adapt=2 / b_bias=0 / direct=3 / weightb=1 / open_gop=0 / weightp=2 / keyint=250 / keyint_min=23 / scenecut=40 / intra_refresh=0 / rc_lookahead=60 / rc=2pass / mbtree=1 / bitrate=2250 / ratetol=1.0 / qcomp=0.60 / qpmin=0 / qpmax=69 / qpstep=4 / cplxblur=20.0 / qblur=0.5 / vbv_maxrate=31250 / vbv_bufsize=31250 / nal_hrd=none / filler=0 / ip_ratio=1.40 / aq=1:1.00
Codec configuration box : avcC

Audio
ID : 2
Format : AAC LC
Format/Info : Advanced Audio Codec Low Complexity
Codec ID : mp4a-40-2
Duration : 2 h 27 min
Bit rate mode : Constant
Bit rate : 384 kb/s
Channel(s) : 6 channels
Channel layout : C L R Ls Rs LFE
Sampling rate : 48.0 kHz
Frame rate : 46.875 FPS (1024 SPF)
Compression mode : Lossy
Stream size : 406 MiB (15%)
Default : Yes
Alternate group : 1

This one works:

General
Format : MPEG-4
Format profile : Base Media / Version 2
Codec ID : mp42 (mp42/iso2/avc1/mp41)
File size : 2.84 GiB
Duration : 2 h 27 min
Overall bit rate : 2 748 kb/s
Encoded date : UTC 2021-12-23 05:03:03
Tagged date : UTC 2021-12-23 05:03:03
Writing application : HandBrake 1.4.2 2021100300

Video
ID : 1
Format : AVC
Format/Info : Advanced Video Codec
Format profile : Main@L4
Format settings : CABAC / 4 Ref Frames
Format settings, CABAC : Yes
Format settings, Reference frames : 4 frames
Codec ID : avc1
Codec ID/Info : Advanced Video Coding
Duration : 2 h 27 min
Bit rate : 2 577 kb/s
Width : 1 920 pixels
Height : 800 pixels
Display aspect ratio : 2.40:1
Frame rate mode : Variable
Frame rate : 23.976 (24000/1001) FPS
Minimum frame rate : 23.974 FPS
Maximum frame rate : 23.981 FPS
Color space : YUV
Chroma subsampling : 4:2:0
Bit depth : 8 bits
Scan type : Progressive
Bits/(Pixel*Frame) : 0.070
Stream size : 2.66 GiB (94%)
Writing library : x264 core 163 r3059 b684ebe0
Encoding settings : cabac=1 / ref=2 / deblock=1:0:0 / analyse=0x1:0x111 / me=hex / subme=6 / psy=1 / psy_rd=1.00:0.00 / mixed_ref=1 / me_range=16 / chroma_me=1 / trellis=1 / 8x8dct=0 / cqm=0 / deadzone=21,11 / fast_pskip=1 / chroma_qp_offset=-2 / threads=15 / lookahead_threads=2 / sliced_threads=0 / nr=0 / decimate=1 / interlaced=0 / bluray_compat=0 / constrained_intra=0 / bframes=3 / b_pyramid=2 / b_adapt=1 / b_bias=0 / direct=1 / weightb=1 / open_gop=0 / weightp=1 / keyint=240 / keyint_min=24 / scenecut=40 / intra_refresh=0 / rc_lookahead=30 / rc=crf / mbtree=1 / crf=22.0 / qcomp=0.60 / qpmin=0 / qpmax=69 / qpstep=4 / vbv_maxrate=20000 / vbv_bufsize=25000 / crf_max=0.0 / nal_hrd=none / filler=0 / ip_ratio=1.40 / aq=1:1.00
Encoded date : UTC 2021-12-23 05:03:03
Tagged date : UTC 2021-12-23 05:03:03
Color range : Limited
Color primaries : BT.709
Transfer characteristics : BT.709
Matrix coefficients : BT.709
mdhd_Duration : 8874866
Codec configuration box : avcC

Audio
ID : 2
Format : AAC LC
Format/Info : Advanced Audio Codec Low Complexity
Codec ID : mp4a-40-2
Duration : 2 h 27 min
Source duration : 2 h 27 min
Bit rate mode : Constant
Bit rate : 164 kb/s
Channel(s) : 2 channels
Channel layout : L R
Sampling rate : 48.0 kHz
Frame rate : 46.875 FPS (1024 SPF)
Compression mode : Lossy
Stream size : 174 MiB (6%)
Source stream size : 174 MiB (6%)
Title : Stereo
Default : Yes
Alternate group : 1
Encoded date : UTC 2021-12-23 05:03:03
Tagged date : UTC 2021-12-23 05:03:03
mdhd_Duration : 8874900

Complete logs with debugging enabled will be more useful.

To get a better understanding of the problem you are experiencing we need more information from you. The best way to get this information is for you to upload logs that demonstrate your problem. You can learn more about how to submit a useful support request here.

Depending on the used skin you have to set the settings-level to standard or higher, in summary:

  • enable debug logging at settings->system->logging

  • reboot the OSMC device twice(!)

  • reproduce the issue

  • upload the log set (all configs and logs!) either using the Log Uploader method within the My OSMC menu in the GUI or the ssh method invoking command grab-logs -A

  • publish the provided URL from the log set upload, here

Thanks for your understanding. We hope that we can help you get up and running again shortly.

OSMC skin screenshot:

Interestingly, both the command-line tool and the GUI based version (which I guess invokes the same binary) hang.

So I guessed at the usage (no man entry, and no help that I can see) and used:

grab-logs -A -T /tmp/log.txt

That file can be accessed here: https://drive.google.com/file/d/1F6qVXXFgzLPEgeFv8NXARr-_X46tqV1v/view?usp=sharing


EDIT: The upload did finally complete: https://paste.osmc.tv/awirefaron

grab-logs -h

I’m also seeing this symptom (playback grinding to a halt after about 10 seconds) on my RPi 2 since the last update. rbp2-mediacenter-osmc package version is 19.3.0-10. I can provide debug logs too if that would be helpful.

I’ve now taken a look at the debug logs and found a repeated messages like this:

2021-12-28 13:39:49.697 T:382      INFO <general>: CActiveAE::ApplySettings - Forcing samplerate to 48000
2021-12-28 13:39:49.698 T:383      INFO <general>: CActiveAESink::OpenSink - initialize sink
2021-12-28 13:39:49.698 T:383     DEBUG <general>: CActiveAESink::OpenSink - trying to open device ALSA:default
2021-12-28 13:39:49.698 T:383      INFO <general>: CAESinkALSA::Initialize - Attempting to open device "default"
2021-12-28 13:39:49.710 T:383      INFO <general>: CAESinkALSA - Unable to open device "default" for playback
2021-12-28 13:39:49.710 T:383     ERROR <general>: CAESinkALSA::Initialize - failed to initialize device "default"
2021-12-28 13:39:49.711 T:383     ERROR <general>: CActiveAESink::OpenSink - no sink was returned
2021-12-28 13:39:49.711 T:382     ERROR <general>: ActiveAE::InitSink - returned error

So I looked at the audio settings and found that the audio device option was greyed out. I’d made some changes to /boot/config-user.txt to enable analogue audio output so I compared what I had with what others had posted and found that I was missing a line reading “dtparam=audio=on”. Once I added that and rebooted everything was good again.

I had a look at PhilipPeake’s log and while it looks different, there are some audio related errors:
EG

Dec 23 10:55:36 osmc kernel: hdmi-audio-codec hdmi-audio-codec.1.auto: Not able to map channels to speakers (-22)
Dec 23 10:55:36 osmc kernel: hdmi-audio-codec hdmi-audio-codec.1.auto: ASoC: error at snd_soc_pcm_dai_prepare on i2s-hifi: -22
Dec 23 10:55:36 osmc kernel:  MAI: ASoC: DAI prepare error: -22

So it might also be an audio issue.

1 Like

That might make some sense.
The biggest difference between the file that works and that which doesn’t is the audio…

Amazing: had the very same issue with video files that froze after a couple of secs after having worked for years like a charme on my pi2 - on a hard disk connected directly.
Adding the line dtparam=audio=on in /boot/config-user.txt solved the issue for me!

Thanks a lot for this!