OSMC Blue screen sad face when viewing certain OTA recordings on Pi

Help and Support Raspberry Pi
1

I’m running the stretch version of OSMC on a Pi3 with the latest version of PVR Client for HDHomeRun (1.2.6). Though I’m running the stretch version, the problem that I describe here was also occurring on the standard 2017.10-1 version as well.

I use the HDHomeRun DVR service to record OTA TV and view later via Kodi on OSMC. My particular installation is unusual because the HDHomeRun HDTC tuner is remote. My LAN is extended via a MikroTik wireless link across a lake to a hill where the TV antenna and the tuner are located because I cannot get an OTA signal at my house. This link works well and is fast (> 100 Mbit/sec) but occasionally experiences a short “hit”. When this happens the OTA recording apparently can get somewhat corrupted. This does not happen often, perhaps 3 shows a month have this problem.

The recordings with these glitches still play successfully on a firestick where I’ve installed Kodi with the PVR client. They also play successfully using the HDHomeRun Kodi Add-on both on the firestick and on the OSMC Raspberry Pi box. However, if I try to play these recordings using the preferred PVR Client I immediately get a OSMC blue screen sad face.

I made one of these recordings available to the developer of the HDHomeRun PVR Client.

You can find it here: https://drive.google.com/file/d/1TUWe7WsNLgD1Z-NQAdnGkwjrqoNcVqkQ/view?usp=sharing

The developer of the PVR Client comments are below. Since this only happens on OSMC on the Pi and not on the firestick, it appears that it may be an OSMC bug (or a bug in a library or ffmeg on the Pi platform).

Developer Comments:

"Well, that didn’t take long. The file does appear to be corrupt. At offset 0x2310A200 (decimal: 588292608) the MPEG-TS stream goes wonky and a ton of garbage data is present until offset 0x2310C300 (decimal: 588301056). Unfortunately that offset doesn’t align properly for an MPEG-TS stream, and I think this may be why it’s killing Kodi on some systems. My guess is that ffmpeg (what Kodi uses to decode MPEG-TS streams) can’t deal with this glitch.

I’ll keep playing around with it, but I doubt there is anything I will be able to do directly to avoid the crash, I’m not fantastic at Linux debugging but I’m 95% sure the crash is happening inside of Kodi as opposed to in my code. I will absolutely confirm that, of course, I don’t want to just blame Kodi :slight_smile:

I would definitely tell SiliconeDust about this, and send them this file. Let them know the defect in the recorded stream occurs at offset 0x2310A200, and that while it does appear to recover at offset 0x2310C300, the stream is no longer aligned to 188-byte boundaries after the corruption. The crash is likely a Kodi/ffmpeg concern.

I think the OSMC people would [also] appreciate it, they seem like they would anyway. My money is on a bug in the ffmpeg implementation on that platform, calculating something slightly wrong due to the misaligned data and trying to read/write to a bad memory location. I can’t find any specific defects in the PVR, it appears to be sending Kodi/OSMC the data that it’s asking for."

2

Thank you for this report

Can we see a debug log of you playing this?
Do you have the MPEG2 license pack

3

Good question. I do not have the MPEG2 license pack.

You can find my logs here: https://paste.osmc.tv/oloqomekop

One more bit I just discovered. The above log ends when ffmpeg returns an error saying the decoding for stream 0 failed. When I play the same video on the firestick with the same DVR client, I see the same error in the log, but then the log continues and the file actually plays successfully. (see below for log excerpt from the firestick kodi log). Not sure if this will help or not…but it looks like the error in OSMC is treated as a fatal one, while on the firestick some type of recovery allows the file to actually play.

Thanks for looking into this.

firestick log excerpt:

20:56:53.698 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [h264] SPS unavailable in decode_picture_timing
20:56:53.699 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [h264] non-existing PPS 0 referenced
20:56:53.699 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [h264] SPS unavailable in decode_picture_timing
20:56:53.700 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [h264] non-existing PPS 0 referenced
20:56:53.700 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [h264] decode_slice_header error
20:56:53.700 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [h264] no frame!
20:56:53.701 T:18446744072510105880 INFO: ffmpeg[B881E918]: [mpegts] decoding for stream 0 failed
20:56:53.792 T:18446744072510105880 DEBUG: ffmpeg[B881E918]: [mpegts] Could not find codec parameters for stream 0 (Video: h264 ([27][0][0][0] / 0x001B), none): unspecified size
20:56:53.807 T:18446744072510105880 DEBUG: ffmpeg[B881E918]: [mpegts] Consider increasing the value for the ‘analyzeduration’ and ‘probesize’ options
20:56:53.807 T:18446744072510105880 DEBUG: Open - av_find_stream_info finished
20:56:53.808 T:18446744072510105880 INFO: ffmpeg[B881E918]: Input #0, mpegts, pvr://recordings/tv/active/Bull/Bull s02e05 (2017)%20Play%20the%20Hand%20You%27re%20Dealt, TV%20(WWTVDT), 20171025_005900, http://192.168.88.11:1039/recorded/cmd?id=27d9ff52.pv’:
20:56:53.809 T:18446744072510105880 INFO: ffmpeg[B881E918]: Duration: 01:02:00.51, start: 86045.185611, bitrate: 3437 kb/s
20:56:53.809 T:18446744072510105880 INFO: ffmpeg[B881E918]: Program 3
20:56:53.811 T:18446744072510105880 INFO: ffmpeg[B881E918]: Stream #0:0[0x31]: Video: h264 ([27][0][0][0] / 0x001B), none, 29.97 fps, 29.97 tbr, 90k tbn, 180k tbc
20:56:53.812 T:18446744072510105880 INFO: ffmpeg[B881E918]: Stream #0:10x34: Audio: ac3 (AC-3 / 0x332D4341), 48000 Hz, stereo, fltp, 192 kb/s
20:56:53.813 T:18446744072510105880 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 0
20:56:53.813 T:18446744072510105880 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 1
20:56:53.836 T:18446744072510105880 NOTICE: Opening stream: 0 source: 256
20:56:53.836 T:18446744072510105880 NOTICE: Creating video codec with codec id: 28
20:56:53.837 T:18446744072510105880 DEBUG: FactoryCodec - Video: mediacodec - Opening
20:56:53.837 T:18446744072510105880 ERROR: CDVDVideoCodecAndroidMediaCodec::Open - null size, cannot handle
20:56:53.838 T:18446744072510105880 DEBUG: FactoryCodec - Video: mediacodec - Failed
20:56:53.838 T:18446744072510105880 DEBUG: FactoryCodec - Video: - Opening
20:56:53.838 T:18446744072510105880 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
20:56:53.839 T:18446744072510105880 DEBUG: CDVDVideoCodecFFmpeg - open frame threaded with 6 threads
20:56:53.842 T:18446744072510105880 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-h264
20:56:53.843 T:18446744072510105880 DEBUG: FactoryCodec - Video: ff-h264 - Opened
20:56:53.843 T:18446744072510105880 DEBUG: CVideoPlayerVideo::OpenStream - open stream with codec id: 28
20:56:53.844 T:18446744072510105880 NOTICE: Creating video thread
20:56:53.844 T:18446744072510105880 NOTICE: Opening stream: 1 source: 256
20:56:53.846 T:18446744072510105880 NOTICE: Finding audio codec for: 86019
20:56:53.846 T:18446744072510105880 DEBUG: FactoryCodec - Audio: passthrough - Opening
20:56:53.847 T:18446744072510105880 DEBUG: FactoryCodec - Audio: passthrough - Failed
20:56:53.847 T:18446744072510105880 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
20:56:53.849 T:18446744072510105880 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
20:56:53.850 T:18446744072501604352 DEBUG: Thread VideoPlayerVideo start, auto delete: false
20:56:53.851 T:18446744072501604352 NOTICE: running thread: video_thread
20:56:53.851 T:18446744072510105880 NOTICE: Creating audio thread
20:56:53.852 T:18446744072503675208 DEBUG: Thread VideoPlayerAudio start, auto delete: false
20:56:53.852 T:18446744072503675208 NOTICE: running thread: CVideoPlayerAudio::Process()
20:56:53.853 T:18446744072510105880 DEBUG: ReadEditDecisionLists - Checking for edit decision list (EDL) for PVR recording: pvr://recordings/tv/active/Bull/Bull s02e05 (2017)%20Play%20the%20Hand%20You%27re%20Dealt, TV%20(WWTVDT), 20171025_005900, http://192.168.88.11:1039/recorded/cmd?id=27d9ff52.pvr
20:56:53.855 T:18446744072510105880 DEBUG: ReadPvr - Reading Edl for recording: Bull
20:56:53.856 T:18446744072510105880 DEBUG: OnPlayBackStarted: play state was 1, starting 1
20:56:53.856 T:18446744072490565648 DEBUG: PlayFile: OpenFile succeed, play state 2
20:56:53.856 T:18446744072490565648 DEBUG: OnPlayBackStarted: play state was 2, starting 0
20:56:53.857 T:18446744072510105880 DEBUG: CVideoPlayer::SetCaching - caching state 2
20:56:53.858 T:18446744072510105880 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
20:56:53.862 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.863 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.864 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.866 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.868 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.869 T:18446744072503675208 DEBUG: CDVDAudio::Pause - pausing audio stream
20:56:53.870 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.871 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.872 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.874 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.875 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.877 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.878 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.880 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.889 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.894 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.894 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.895 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.897 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.898 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.899 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.903 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.904 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.905 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.905 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.907 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.913 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.915 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.915 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.918 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.921 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.925 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.925 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.948 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.948 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.963 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.965 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.967 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.982 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.983 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.984 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.987 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.989 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:53.997 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:53.999 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.004 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.009 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.018 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.020 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.027 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.028 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.034 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.035 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.043 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.043 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.048 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.050 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.051 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.052 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.061 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.064 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.066 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.066 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.071 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.075 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.080 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.080 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.081 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.082 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.085 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.085 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.089 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.091 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.092 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.092 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.093 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.093 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.102 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.102 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.103 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.107 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.112 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.113 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.113 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.114 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.124 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.124 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.125 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.126 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.126 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.127 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.127 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.128 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.129 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.129 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.130 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.137 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.138 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.138 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.140 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] SPS unavailable in decode_picture_timing
20:56:54.140 T:18446744072510105880 ERROR: ffmpeg[B881E918]: [NULL] non-existing PPS 0 referenced
20:56:54.142 T:18446744072510105880 DEBUG: CDVDDemuxFFmpeg::Read() fetching extradata, extradata_size(57)
20:56:54.198 T:18446744072492252008 DEBUG: CGUIInfoManager::SetCurrentMovie(pvr://recordings/tv/active/Bull/Bull s02e05 (2017)%20Play%20the%20Hand%20You%27re%20Dealt, TV%20(WWTVDT), 20171025_005900, http://192.168.88.11:1039/recorded/cmd?id=27d9ff52.pvr)
20:56:54.258 T:18446744072510105880 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 0
20:56:54.260 T:18446744072510105880 NOTICE: Opening stream: 0 source: 256
20:56:54.260 T:18446744072510105880 NOTICE: Creating video codec with codec id: 28
20:56:54.261 T:18446744072510105880 DEBUG: FactoryCodec - Video: mediacodec - Opening
20:56:54.261 T:18446744072510105880 INFO: CBitstreamConverter::Open Invalid avcC
20:56:54.277 T:18446744072490578216 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
20:56:54.277 T:18446744072490578216 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
20:56:54.662 T:18446744072510105880 DEBUG: CDVDVideoCodecAndroidMediaCodec::Open m_codecname(OMX.MTK.VIDEO.DECODER.AVC), colorFormat(19)
20:56:54.663 T:18446744072510105880 DEBUG: CDVDVideoCodecAndroidMediaCodec::Open m_codecname(OMX.MTK.VIDEO.DECODER.AVC), colorFormat(2135033992)
20:56:54.663 T:18446744072510105880 DEBUG: CDVDVideoCodecAndroidMediaCodec::Open m_codecname(OMX.MTK.VIDEO.DECODER.AVC), colorFormat(2130706433)
20:56:54.718 T:18446744072510105880 DEBUG: CDVDVideoCodecAndroidMediaCodec:: width(1280), height(540), stride(0), slice-height(0), color-format(0)
20:56:54.718 T:18446744072510105880 DEBUG: CDVDVideoCodecAndroidMediaCodec:: crop-left(0), crop-top(0), crop-right(0), crop-bottom(0)
20:56:54.718 T:18446744072510105880 DEBUG: CDVDVideoCodecAndroidMediaCodec:: Multi-Surface Rendering
20:56:54.718 T:18446744072510105880 INFO: CDVDVideoCodecAndroidMediaCodec:: Open Android MediaCodec OMX.MTK.VIDEO.DECODER.AVC
20:56:54.719 T:18446744072510105880 DEBUG: FactoryCodec - Video: amc-h264 - Opened
20:56:54.719 T:18446744072510105880 NOTICE: Opening stream: 1 source: 256
20:56:54.720 T:18446744072501604352 DEBUG: CVideoPlayerVideo::OpenStream - open stream with codec id: 28
20:56:54.725 T:18446744072501604352 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
20:56:54.725 T:18446744072501604352 DEBUG: CDVDVideoCodecAndroidMediaCodec::virtual void CDVDVideoCodecAndroidMediaCodec::SetCodecControl(int) 0->4000000
20:56:54.727 T:18446744072501604352 DEBUG: CDVDVideoCodecAndroidMediaCodec::Decode current state (2)
20:56:54.735 T:18446744072503675208 NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, no pass-through)
20:56:54.738 T:18446744072503675208 DEBUG: CVideoPlayerAudio:: synctype set to 0: clock feedback
20:56:54.744 T:18446744072510105880 NOTICE: Opening stream: 0 source: 256
20:56:54.745 T:18446744072510105880 NOTICE: Opening stream: 1 source: 256
20:56:54.745 T:18446744072510105880 NOTICE: Opening stream: 1 source: 1280
20:56:54.745 T:18446744072510105880 DEBUG: FactoryCodec - Overlay: Text Subtitle Decoder - Opening
20:56:54.746 T:18446744072510105880 DEBUG: FactoryCodec - Overlay: Text Subtitle Decoder - Opened
20:56:54.752 T:18446744072501604352 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
20:56:54.884 T:18446744072492318824 DEBUG: Previous line repeats 8 times.
20:56:54.885 T:18446744072492318824 INFO: CActiveAESink::OpenSink - initialize sink
20:56:54.885 T:18446744072492318824 DEBUG: Draining Audio
20:56:54.891 T:18446744072492318824 DEBUG: CActiveAESink::OpenSink - trying to open device AUDIOTRACK:AudioTrack
20:56:54.892 T:18446744072492318824 DEBUG: CAESinkAUDIOTRACK::Initialize requested: sampleRate 48000; format: AE_FMT_FLOATP; channels: 2
20:56:54.892 T:18446744072492318824 DEBUG: Updated SampleRate: 32000 Distance: 144000
20:56:54.893 T:18446744072492318824 DEBUG: Updated SampleRate: 44100 Distance: 35100
20:56:54.893 T:18446744072492318824 DEBUG: Updated SampleRate: 48000 Distance: 0
20:56:54.893 T:18446744072492318824 NOTICE: Trying to open: 48000 samplerate 12 channelMask 4 encoding
20:56:54.896 T:18446744072492318824 DEBUG: Minimum size we need for stream: 32768
20:56:54.897 T:18446744072492318824 DEBUG: Created Audiotrackbuffer with playing time of 170.666667 ms min buffer size: 65536 bytes
20:56:54.968 T:18446744072492318824 NOTICE: CAESinkAUDIOTRACK::Initializing with: m_sampleRate: 48000 format: AE_FMT_FLOAT (AE) method: PCM stream-type: PCM-STREAM min_buffer_size: 65536 m_frames: 4096 m_frameSize: 8 channels: 2
20:56:54.968 T:18446744072492318824 DEBUG: CActiveAESink::OpenSink - AUDIOTRACK Initialized:
20:56:54.968 T:18446744072492318824 DEBUG: Output Device : android
20:56:54.973 T:18446744072492318824 DEBUG: Sample Rate : 48000
20:56:54.973 T:18446744072492318824 DEBUG: Sample Format : AE_FMT_FLOAT
20:56:54.975 T:18446744072492318824 DEBUG: Channel Count : 2
20:56:54.975 T:18446744072492318824 DEBUG: Channel Layout: FL,FR
20:56:54.977 T:18446744072492318824 DEBUG: Frames : 4096
20:56:54.977 T:18446744072492318824 DEBUG: Frame Size : 8
20:56:55.000 T:18446744072492294600 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
20:56:55.011 T:18446744072501604352 DEBUG: Previous line repeats 1 times.
20:56:55.011 T:18446744072501604352 DEBUG: CDVDVideoCodecAndroidMediaCodec:: width(1280), height(540), stride(1280), slice-height(544), color-format(2130706433)
20:56:55.012 T:18446744072501604352 DEBUG: CDVDVideoCodecAndroidMediaCodec:: crop-left(0), crop-top(0), crop-right(1279), crop-bottom(539)
20:56:55.012 T:18446744072501604352 DEBUG: CDVDVideoCodecAndroidMediaCodec:: Multi-Surface Rendering
20:56:55.013 T:18446744072510105880 DEBUG: CVideoPlayer::HandleMessages - player started 1
20:56:55.024 T:18446744072501604352 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
20:56:55.030 T:18446744072501604352 DEBUG: CRenderManager::Configure - change configuration. 1280x540. display: 960x540. framerate: 29.97. format: MEDIACODECSURFACE
20:56:55.041 T:18446744072490565648 DEBUG: DeleteRenderer - deleting renderer
20:56:55.042 T:18446744072490565648 DEBUG: LinuxRendererGL: Cleaning up GL resources
20:56:55.043 T:18446744072490565648 DEBUG: Previous line repeats 1 times.
20:56:55.044 T:18446744072490565648 NOTICE: Using GL_TEXTURE_2D
20:56:55.045 T:18446744072490565648 NOTICE: GL: Using MediaCodec (Surface) render method
20:56:55.046 T:18446744072490565648 NOTICE: GL: NPOT texture support detected
20:56:55.048 T:18446744072490565648 DEBUG: CLinuxRendererGLES: Reorder drawpoints due to method change from 1 to 2048
20:56:55.049 T:18446744072490565648 DEBUG: CRenderManager::Configure - 3
20:56:55.056 T:18446744072510105880 DEBUG: CVideoPlayer::HandleMessages - player started 2
20:56:55.057 T:18446744072510105880 DEBUG: CVideoPlayer::SetCaching - caching state 3
20:56:55.057 T:18446744072510105880 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
20:56:55.057 T:18446744072510105880 DEBUG: CVideoPlayer::SetCaching - caching state 0
20:56:55.058 T:18446744072510105880 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000
20:56:55.058 T:18446744072510105880 DEBUG: VideoPlayer::Sync - Audio - pts: 2048000.000000, cache: 288000.017405, totalcache: 570666.670799
20:56:55.058 T:18446744072510105880 DEBUG: VideoPlayer::Sync - Video - pts: 2199466.000000, cache: 50000.000000, totalcache: 100000.000000
20:56:55.058 T:18446744072503675208 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1759999.982595)
20:56:55.059 T:18446744072503675208 DEBUG: CDVDAudio::Resume - resume audio stream
20:56:55.060 T:18446744072501604352 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1759999.982595)
20:56:55.072 T:18446744072501604352 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 0
20:56:55.074 T:18446744072492294600 DEBUG: ActiveAE - start sync of audio stream
20:56:55.076 T:18446744072490565648 DEBUG: RenderUpdate: Dest - 0.000000+0.000000-1280.000000x720.000000
20:56:55.077 T:18446744072490565648 DEBUG: RenderUpdate: Adj - 0.000000+0.000000-1920.000000x1080.000000
20:56:55.091 T:18446744072501604352 DEBUG: CVideoPlayerVideo::CalcDropRequirement - hurry: 1
20:56:55.095 T:18446744072501604352 DEBUG: CDVDVideoCodecAndroidMediaCodec::virtual void CDVDVideoCodecAndroidMediaCodec::SetCodecControl(int) 4000000->0
20:56:55.111 T:18446744072490565648 DEBUG: Activating window ID: 12005
20:56:55.111 T:18446744072490565648 DEBUG: ------ Window Deinit (MyPVRRecordings.xml) ------
20:56:55.113 T:18446744072490565648 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
20:56:55.113 T:18446744072490565648 INFO: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
20:56:55.227 T:18446744072492294600 DEBUG: ActiveAE::SyncStream - average error of -95.049737, start adjusting
20:56:55.228 T:18446744072492294600 DEBUG: ActiveAE::SyncStream - average error -10.049737 below threshold of 30.000000
20:56:56.253 T:18446744072503675208 DEBUG: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-70587.226040, adjusted:-70587.226040
20:56:59.448 T:18446744072501604352 DEBUG: CPullupCorrection: detected pattern of length 1: 33366.67, frameduration: 33366.666667
20:57:01.846 T:18446744072490565648 DEBUG: Keyboard: scancode: 0x04, sym: 0x0008, unicode: 0x0000, modifier: 0x0
20:57:02.534 T:18446744072501604352 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer
20:57:02.534 T:18446744072490565648 DEBUG: OnKey: long-backspace (0x100f008) pressed, action is Stop
20:57:02.558 T:18446744072490565648 NOTICE: CVideoPlayer::CloseFile()
20:57:02.558 T:18446744072490565648 NOTICE: VideoPlayer: waiting for threads to exit

4

Note that this problem persists with the stretch version of OSMC. As metioned, it does NOT happen on my firestick with Kodi, so it seems to be an OSMC issue.

5

Bump. I think I’ve provided all the logs an other information to duplicate this issue, but I’ve not received any response and the problem persists even when I upgraded to the test stretch upgrade. Interestingly I’ve discovered that if I try to play the same videos which fail in the the DVR addon using the videos option instead they play successfully.