Occasional "slow-motion"

Setup: Vero4K, connected to AVR with audio passthrough (AC3/DTS).

Occasionally (but quite often, probably 1/2 video’s) midway the video it will start playing in “slow motion”. Audio will continue normally but will be out of sync with video as the video seems to be played at a lower speed. The solution is the rewind 10s (left arrow) so the video restarts at normal speed and resyncs with audio.
Nothing is logged in the kodi-log files at the moment.

This is unlikely when debug logging is enabled.

Is full debugging required? I doubt the misses will accept the constant information overlayed during playback.

You can enable debug logging without needing the overlay active.

How can I switch that off? Enable component-specific logging? I’ve enable it for ffmpeg, audio and video. Would that be enough?

  1. Go in via command line
    Details regarding how to access the command line interface can be found here on our Wiki: Accessing the command line - General - OSMC

  2. edit advancedsettings.xml
    nano .kodi/userdata/advancedsettings.xml

  3. Change the logging to enable debug logging without onscreen display
    <loglevel>1</loglevel> <!-- Change this to "1" to hide the on-screen debug log text -->

Will have tot verify but I encountered the issue and found this in the log (before that nothing in the logs for 10 minutes).

23:55:05.134 T:3218076656 NOTICE: CActiveAEStream::AddData - messy timestamps, increasing interval for measuring average error to 6000 ms

Could this be it? This file was re-encoded with ffmpeg:

ffmpeg version N-85750-ga75ef15 Copyright (c) 2000-2017 the FFmpeg developers
  built with gcc 6.3.0 (GCC)
  configuration: --enable-gpl --enable-version3 --enable-cuda --enable-cuvid --enable-d3d11va --enable-dxva2 --enable-libmfx --enable-nvenc --enable-avisynth --enable-bzlib --enable-fontconfig --enable-frei0r --enable-gnutls --enable-iconv --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libfreetype --enable-libgme --enable-libgsm --enable-libilbc --enable-libmodplug --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenh264 --enable-libopenjpeg --enable-libopus --enable-librtmp --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvo-amrwbenc --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs --enable-libxvid --enable-libzimg --enable-lzma --enable-zlib
  libavutil      55. 61.100 / 55. 61.100
  libavcodec     57. 93.100 / 57. 93.100
  libavformat    57. 72.101 / 57. 72.101
  libavdevice    57.  7.100 / 57.  7.100
  libavfilter     6. 88.100 /  6. 88.100
  libswscale      4.  7.101 /  4.  7.101
  libswresample   2.  8.100 /  2.  8.100
  libpostproc    54.  6.100 / 54.  6.100

It would help to see the whole log.

But yes – a bad encode will cause playback problems and result in Vero 4K having to resync.

Don’t know if it will shed some more light but anyway: https://paste.osmc.tv/cijivamewi.vhdl

Hi

Can you send me the file? If you are encoding it, I might be able to give you some pointers / advice.

Sam

The file is just a recode of some (large) rips I have. Basicly -c:a copy -c:v libx264 -crf 20 -tune film. No rocket science :slight_smile:

I also had some rips that had problems with FF/REW but I fixed that with mkvmerge --clusters-in-meta-seek. I will do that with these rips as well and see if that fixes the problems.

mkvmerge is create for remuxing when you have container issues; but I’m not sure why you’d have them in the first place if you’re doing the rips yourself.

Sam

No clue what the problem might be. If it’s an encoding issue I would expect the problem to occur every time at the same location but it doesn’t. When I notice it I’ve rewinded 5 minutes but the problem did not reproduce. So now I’m looking into remuxing the stream.

You are not being completely forthcoming with information here. In the absence of any other log other than the kodi.log, we have no idea if you are wired or wireless which could have huge implications particularly when your stated issue with “a recode of some (large) rips” is at question. Mediainfo output on the file could also be immensely useful when particular files are the subject. Feels like you are avoiding providing useful info as requested in the very link that you have quoted to others yourself.

I’m not avoiding providing “usefull” data but uploading a couple of GB of files seems a bit of an overkill. All you need to do is ask :slight_smile:
My system is wired, 1Gbps. FreeNAS with NFSv3. No stuttering or speed problems encountered so far.
As for “recoded files”. I’ve also encountered it on files I did not encode myself but that stumbled by accident on my HDD.

And as for using a script or whatever that uploads all information from my system without anonymizing it or giving me any option to review what is sent… sorry, once it’s on the internet it stays on the internet…

Mediainfo:

General
Unique ID                                : 166135242999499200972675918630992181900 (0x7CFC7BE2E83BDA16666DBC14110B7A8C)
Complete name                            : xxxxx.mkv
Format                                   : Matroska
Format version                           : Version 4 / Version 2
File size                                : 1.63 GiB
Duration                                 : 42mn 50s
Overall bit rate                         : 5 444 Kbps
Writing application                      : Lavf57.72.101
Writing library                          : Lavf57.72.101

Video
ID                                       : 1
Format                                   : AVC
Format/Info                              : Advanced Video Codec
Format profile                           : High@L4.0
Format settings, CABAC                   : Yes
Format settings, ReFrames                : 4 frames
Codec ID                                 : V_MPEG4/ISO/AVC
Duration                                 : 42mn 50s
Bit rate                                 : 4 695 Kbps
Width                                    : 1 920 pixels
Height                                   : 1 080 pixels
Display aspect ratio                     : 16:9
Frame rate mode                          : Constant
Frame rate                               : 23.976 fps
Color space                              : YUV
Chroma subsampling                       : 4:2:0
Bit depth                                : 8 bits
Scan type                                : Progressive
Bits/(Pixel*Frame)                       : 0.094
Stream size                              : 1.41 GiB (86%)
Writing library                          : x264 core 148 r2762 90a61ec
Encoding settings                        : cabac=1 / ref=1 / deblock=1:-1:-1 / analyse=0x3:0x113 / me=hex / subme=2 / psy=1 / psy_rd=1.00:0.15 / mixed_ref=0 / me_range=16 / chroma_me=1 / trellis=0 / 8x8dct=1 / cqm=0 / deadzone=21,11 / fast_pskip=1 / chroma_qp_offset=0 / threads=6 / 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=250 / keyint_min=23 / scenecut=40 / intra_refresh=0 / rc_lookahead=10 / rc=crf / mbtree=1 / crf=21.0 / qcomp=0.60 / qpmin=0 / qpmax=69 / qpstep=4 / ip_ratio=1.40 / aq=1:1.00
Language                                 : English
Default                                  : Yes
Forced                                   : No
DURATION                                 : 00:42:50.652000000
NUMBER_OF_FRAMES                         : 61634
NUMBER_OF_BYTES                          : 3930282368
_STATISTICS_WRITING_APP                  : mkvmerge v7.9.0 ('Birds') 32bit
_STATISTICS_WRITING_DATE_UTC             : 2016-08-30 08:38:16
_STATISTICS_TAGS                         : BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES

Audio
ID                                       : 2
Format                                   : E-AC-3
Format/Info                              : Audio Coding 3
Format settings, Endianness              : Big
Codec ID                                 : A_EAC3
Duration                                 : 42mn 50s
Bit rate mode                            : Constant
Bit rate                                 : 640 Kbps
Channel(s)                               : 6 channels
Channel positions                        : Front: L C R, Side: L R, LFE
Sampling rate                            : 48.0 KHz
Bit depth                                : 32 bits
Compression mode                         : Lossy
Stream size                              : 196 MiB (12%)
Language                                 : English
Default                                  : Yes
Forced                                   : No
DURATION                                 : 00:42:50.624000000
NUMBER_OF_FRAMES                         : 80332
NUMBER_OF_BYTES                          : 205649920
_STATISTICS_WRITING_APP                  : mkvmerge v7.9.0 ('Birds') 32bit
_STATISTICS_WRITING_DATE_UTC             : 2016-08-30 08:38:16
_STATISTICS_TAGS                         : BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES

Text
ID                                       : 3
Format                                   : UTF-8
Codec ID                                 : S_TEXT/UTF8
Codec ID/Info                            : UTF-8 Plain Text
Language                                 : English
Default                                  : No
Forced                                   : No
DURATION                                 : 00:42:09.197000000
NUMBER_OF_FRAMES                         : 1083
NUMBER_OF_BYTES                          : 35195
_STATISTICS_WRITING_APP                  : mkvmerge v7.9.0 ('Birds') 32bit
_STATISTICS_WRITING_DATE_UTC             : 2016-08-30 08:38:16
_STATISTICS_TAGS                         : BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES

<OFF TOPIC>I've worked in a IT support organization. We had our own "collector/explorer". I tapped people on the head if they asked for this when a customer rang in with e.g. a disk-problem as 99% of the collected information was useless for the problem at hand. I requested the information that could be usefull and asked for more information if needed. Sorry, that's the way I work... I'm only trying to help make OSMC an even better product than it already is. I've got my work-around but would hope nobody else runs into it.</OFF TOPIC>

I’m not sure what you feel we’ve asked for that would consist of more than 20mb…

We did when we wrote the useful support request wiki…

The linked instructions provide a clear method for saving the log locally after which you are free to sanitize it as you see fit before sending it to the paste site.

Thanks for your cooperation in helping us help you now though.

Do the affected files behave the same when played from storage on the device itself?

Haven’t tried to copy them to local storage. I would have to copy a lot files to local storage before playing them in hope that the problem re-occurs. The same file, when restarted (e.g. 10 minutes rewind) will not show the same behaviour, it will play correctly. During a 2h movie, the problem might occur (or not) and after using the work-around (skipping back 30s) has to my knowledge never happened again (in that movie).

Sam asked if I could upload a file that had the issue; as you can see from the mediainfo it’s 1.6GB.

Sanitized logs (gzip’d as > 75MB) can be downloaded here: https://paste.osmc.tv/ofoxipivuh

sam@sam-XPS-15-9550:/tmp$ gunzip ofoxipivuh.gz 

gzip: ofoxipivuh.gz: not in gzip format

We’re not a file locker. We cap logs at 20M.

Even if we get 75M of logs; there’s no real way we can trawl through that. Ideally with logs, we want the smallest log which reproduces the problem.

I’m not sure how you tried to upload binary files to the paste server but it won’t work properly.

Try playing back the content that causes a problem locally; if it works fine, then there’s a network issue that might need investigating.

Cheers

Sam

This is likely why you have 75mb worth of logs. No one asked to see those enabled. We would only like to see logs with debugging enabled and the additional system logs created with grab-logs -A
Should certainly be no where near 75mb…