Heavy stutter in 4k25p HDR

[Golge77]

I'm at work now so looking into debuglog when home.

I tried the option -use videoToolbox for 4k HEVC HDR I know that this is wrong settings but I wanted the video to not switch to HDR to see if it stops stuttering.
.........and I was right when playing the file with above activated it does not switch and no stutter appears.

It seems like stuttering appears when playing 4k25pHDR and the HDR mode is active .

[Golge77]

And debuglog?

22:51:25.479 T:6175338496 NOTICE: NFS is idle. Closing the remaining connections.
22:51:26.139 T:6175338496 NOTICE: Log level changed to "LOG_LEVEL_DEBUG_FREEMEM"
22:51:26.139 T:6175338496 NOTICE: Enabled debug logging due to GUI setting. Level 2.
22:51:36.103 T:6175338496 DEBUG: found key /userdata/profiles.xml
22:51:36.104 T:6175338496 DEBUG: Previous line repeats 1 times.
22:51:36.105 T:6175338496 DEBUG: NSUSerDefaults: compressed /userdata/profiles.xml from 923 to 324
22:51:36.105 T:6175338496 DEBUG: found key /userdata/guisettings.xml
22:51:36.116 T:6175338496 DEBUG: Previous line repeats 1 times.
22:51:36.116 T:6175338496 DEBUG: NSUSerDefaults: compressed /userdata/guisettings.xml from 31121 to 6187
22:51:36.123 T:6175338496 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
22:51:36.414 T:6175338496 DEBUG: ------ Window Deinit (SettingsCategory.xml) ------
22:51:36.414 T:6175338496 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
22:51:36.414 T:6175338496 DEBUG: ------ Window Init (Settings.xml) ------
22:51:38.455 T:6175338496 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
22:51:38.773 T:6175338496 DEBUG: ------ Window Deinit (Settings.xml) ------
22:51:38.774 T:6175338496 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
22:51:38.774 T:6175338496 DEBUG: ------ Window Init (Home.xml) ------
22:51:38.774 T:6175338496 DEBUG: CGUIWindowHome::SetupServices() - serverType() , serverUUID()
22:51:38.779 T:6175338496 DEBUG: CMultiPathDirectory::GetDirectory(multipath://multipath%3a%2f%2fspecial%253a%252f%252fprofile%252fplaylists%252fmusic%2fspecial%253a%252f%252fprofile%252fplaylists%252fmixed%2f/multipath%3a%2f%2fspecial%253a%252f%252fprofile%252fplaylists%252fvideo%2fspecial%253a%252f%252fprofile%252fplaylists%252fmixed%2f/)
22:51:38.779 T:6175338496 DEBUG: Getting Directory (multipath://special%3a%2f%2fprofile%2fplaylists%2fmusic/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
22:51:38.779 T:6175338496 DEBUG: CMultiPathDirectory::GetDirectory(multipath://special%3a%2f%2fprofile%2fplaylists%2fmusic/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
22:51:38.779 T:6175338496 DEBUG: Getting Directory (special://profile/playlists/music)
22:51:38.779 T:6175338496 DEBUG: Getting Directory (special://profile/playlists/mixed)
22:51:38.779 T:6175338496 DEBUG: CMultiPathDirectory::MergeItems, items = 0
22:51:38.779 T:6175338496 DEBUG: Getting Directory (multipath://special%3a%2f%2fprofile%2fplaylists%2fvideo/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
22:51:38.779 T:6175338496 DEBUG: CMultiPathDirectory::GetDirectory(multipath://special%3a%2f%2fprofile%2fplaylists%2fvideo/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
22:51:38.779 T:6175338496 DEBUG: Getting Directory (special://profile/playlists/video)
22:51:38.779 T:6175338496 DEBUG: Getting Directory (special://profile/playlists/mixed)
22:51:38.779 T:6175338496 DEBUG: CMultiPathDirectory::MergeItems, items = 0
22:51:38.779 T:6175338496 DEBUG: Previous line repeats 1 times.
22:51:38.779 T:6175338496 DEBUG: CGUIWindowHome::SetupStaticHomeButtons()
22:51:38.780 T:6172471296 DEBUG: CHomeShelfJob::UpdateMusic() - Running HomeShelf screen update
22:51:38.781 T:6172471296 DEBUG: CHomeShelfJob::UpdateVideos() - Running HomeShelf screen update
22:51:38.790 T:6172471296 ERROR: GetDirectory - Error getting library://video/inprogressepisodes.xml/
22:51:55.781 T:6175338496 DEBUG: SECTION:UnloadDelayed(DLL: libnfs.framework/libnfs)
22:51:56.505 T:6175338496 DEBUG: Activating window ID: 10025
22:51:56.818 T:6175338496 DEBUG: ------ Window Deinit (Home.xml) ------
22:51:56.839 T:6175338496 DEBUG: ------ Window Init (MyVideoNav.xml) ------
22:51:56.843 T:6175338496 DEBUG: SECTION:LoadDLL(libnfs.framework/libnfs)
22:51:56.845 T:6175338496 DEBUG: Loading: /private/var/containers/Bundle/Application/2F00EB70-1469-40CD-A006-22E47355CB02/MrMC.app/Frameworks/libnfs.framework/libnfs
22:51:56.888 T:6175338496 DEBUG: NFS: Context for 192.168.1.115/volume1/Diverse not open - get a new context.
22:51:56.932 T:6175338496 DEBUG: NFS: Connected to server 192.168.1.115 and export /volume1/Diverse
22:51:56.932 T:6175338496 DEBUG: NFS: chunks: r/w 131072/131072
22:51:58.446 T:6175338496 DEBUG: ExcludeFileOrFolder: File 'nfs://192.168.1.115/volume1/Diverse/HDR/@eaDir/' excluded. (Matches exclude rule RegExp:'\@eaDir')
22:52:00.647 T:6175338496 DEBUG: OnPlayMedia nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4
22:52:00.681 T:6175338496 DEBUG: Loading settings for nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4
22:52:00.689 T:6175338496 DEBUG: CPlayerCoreFactory::GetPlayers(nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4)
22:52:00.689 T:6175338496 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
22:52:00.690 T:6175338496 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
22:52:00.690 T:6175338496 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
22:52:00.690 T:6175338496 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
22:52:00.690 T:6175338496 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
22:52:00.690 T:6175338496 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
22:52:00.691 T:6175338496 NOTICE: CDVDPlayer::Opening: nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4
22:52:00.691 T:6175338496 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
22:52:00.692 T:6177058816 NOTICE: Creating InputStream
22:52:00.694 T:6177058816 DEBUG: CNFSFile::Open - opened volume1/Diverse/HDR/TF.mp4
22:52:00.696 T:6177058816 DEBUG: ScanForExternalSubtitles: Searching for subtitles...
22:52:00.697 T:6177058816 DEBUG: ScanForExternalSubtitles: END (total time: 2 ms)
22:52:00.697 T:6177058816 NOTICE: Creating Demuxer
22:52:00.697 T:6177058816 DEBUG: Open - m_ioContext->max_packet_size(1) = 0
22:52:00.721 T:6177058816 DEBUG: Open - probing detected format [mov,mp4,m4a,3gp,3g2,mj2]
22:52:00.725 T:6177058816 INFO: ffmpeg[1702E7000]: [mov,mp4,m4a,3gp,3g2,mj2] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol
22:52:00.725 T:6177058816 DEBUG: Open - avformat_find_stream_info starting
22:52:00.761 T:6177058816 DEBUG: Open - av_find_stream_info finished
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: Input #0, mov,mp4,m4a,3gp,3g2,mj2, nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp':
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: Metadata:
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: major_brand : mp42
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: minor_version : 512
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: compatible_brands: isomiso2mp41
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: creation_time : 2020-07-23T09:34:44.000000Z
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: encoder : HandBrake 1.3.3 2020061300
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: Duration: 00:00:47.04, start: 0.000000, bitrate: 39915 kb/s
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: Stream #0:0(und): Video: hevc (Main 10) (hvc1 / 0x31637668), yuv420p10le(tv, bt2020nc/bt2020/arib-std-b67), 3840x2160 [SAR 1:1 DAR 16:9], 39589 kb/s, 25 fps, 25 tbr, 90k tbn, 25 tbc (default)
22:52:00.761 T:6177058816 INFO: ffmpeg[1702E7000]: Metadata:
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: creation_time : 2020-07-23T09:34:44.000000Z
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: handler_name : VideoHandler
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: Stream #0:1(eng): Audio: ac3 (ac-3 / 0x332D6361), 48000 Hz, stereo, fltp, 320 kb/s (default)
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: Metadata:
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: creation_time : 2020-07-23T09:34:44.000000Z
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: handler_name : Stereo
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: Side data:
22:52:00.762 T:6177058816 INFO: ffmpeg[1702E7000]: audio service type: main
22:52:00.762 T:6177058816 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
22:52:00.762 T:6177058816 DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
22:52:00.762 T:6177058816 NOTICE: Opening stream: 0 source: 256
22:52:00.762 T:6177058816 NOTICE: Creating video codec with codec id: 174
22:52:00.762 T:6177058816 DEBUG: FactoryCodec - Video: vtb - Opening
22:52:00.762 T:6177058816 DEBUG: FactoryCodec - Video: vtb - Failed
22:52:00.763 T:6177058816 DEBUG: FactoryCodec - Video: avf- - Opening
22:52:00.763 T:6177058816 NOTICE: Constructing new format description
22:52:00.767 T:6177058816 DEBUG: FactoryCodec - Video: avf-h265 - Opened
22:52:00.767 T:6177058816 NOTICE: Creating video thread
22:52:00.767 T:6178779136 DEBUG: CDVDVideoCodecAVFoundation::Process Started
22:52:00.767 T:6181072896 NOTICE: running thread: video_thread
22:52:00.767 T:6177058816 NOTICE: Opening stream: 1 source: 256
22:52:00.767 T:6177058816 NOTICE: Finding audio codec for: 86019
22:52:00.769 T:6177058816 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
22:52:00.770 T:6177058816 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
22:52:00.770 T:6177058816 NOTICE: Creating audio thread
22:52:00.770 T:6177058816 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4
22:52:00.770 T:6186807296 NOTICE: running thread: CDVDPlayerAudio::Process()
22:52:00.771 T:6177058816 DEBUG: OnPlayBackStarted: play state was 1, starting 1
22:52:00.771 T:6175338496 DEBUG: PlayFile: OpenFile succeed, play state 2
22:52:00.771 T:6175338496 DEBUG: OnPlayBackStarted: play state was 2, starting 0
22:52:00.772 T:6181072896 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
22:52:00.772 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.777 T:6175338496 DEBUG: CGUIInfoManager::SetCurrentMovie(nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4)
22:52:00.779 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.780 T:6178779136 DEBUG: Process - CDVDVideoCodecAVFoundation::Start player_s(0.012528)
22:52:00.783 T:6186807296 DEBUG: ffmpeg[170C33000]: [ac3] Could not update timestamps for skipped samples.
22:52:00.783 T:6186807296 NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, no pass-through)
22:52:00.783 T:6186807296 DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
22:52:00.783 T:6176485376 INFO: CActiveAESink::OpenSink - initialize sink
22:52:00.783 T:6176485376 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINIOS:default
22:52:00.786 T:6176485376 DEBUG: CAESinkDARWINIOS::Initialize: asked for 2 channels
22:52:00.786 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.791 T:6175338496 DEBUG: CGUIWindowHome::Announce, type: 1, from xbmc, message OnPlay
22:52:00.791 T:6175338496 DEBUG: CGUIWindowHome::SetupServices() - !IsActive()
22:52:00.797 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.803 T:6176485376 NOTICE: getNativeAudioSettings:Stereo
22:52:00.804 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.811 T:6176485376 DEBUG: CAESinkDARWINIOS::Initialize: AudioStreamBasicDescription: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz) pcm
22:52:00.814 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting channels 2
22:52:00.814 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting samplerate 48000.000000
22:52:00.814 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting buffer duration to 0.042667
22:52:00.818 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.840 T:6176485376 DEBUG: Previous line repeats 2 times.
22:52:00.840 T:6176485376 NOTICE: dumpAVAudioSessionProperties:maxchannels 32, deactivateMaxchannels 32
22:52:00.847 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.850 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:total latency = 0.087167
22:52:00.850 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setup audio format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:audio route = HDMIOutput
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:sampleRate 48000.000000
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:outputLatency 0.001833
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:IOBufferDuration 0.042667
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:outputNumberOfChannels 2
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:maximumOutputNumberOfChannels 32
22:52:00.851 T:6176485376 NOTICE: dumpAVAudioSessionProperties:SessionPortOutputNumberOfChannels 2
22:52:00.851 T:6176485376 DEBUG: DumpAudioDescriptions: dumpAVAudioSessionProperties
22:52:00.852 T:6176485376 DEBUG: DumpAudioDescriptions: portName, Vardagsrum
22:52:00.852 T:6176485376 DEBUG: DumpAudioDescriptions: portType, HDMIOutput
22:52:00.852 T:6176485376 DEBUG: DumpAudioDescriptions: portChannelCount, 2
22:52:00.852 T:6176485376 NOTICE: CAESinkDARWINIOS::Initialize: channel_index 0, maxChannels 32, outputChannels 2, portChannelCount 2
22:52:00.854 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:00.862 T:6176485376 DEBUG: CActiveAESink::OpenSink - DARWINIOS Initialized:
22:52:00.862 T:6176485376 DEBUG: Output Device : Default
22:52:00.862 T:6176485376 DEBUG: Sample Rate : 48000
22:52:00.862 T:6176485376 DEBUG: Sample Format : AE_FMT_FLOAT
22:52:00.862 T:6176485376 DEBUG: Channel Count : 2
22:52:00.862 T:6176485376 DEBUG: Channel Layout: FL,FR
22:52:00.862 T:6176485376 DEBUG: Frames : 1024
22:52:00.862 T:6176485376 DEBUG: Frame Size : 8
22:52:00.862 T:6176485376 DEBUG: CActiveAESink::GenerateNoise - noiseFactor = 0.000010
22:52:00.863 T:6175911936 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:52:00.865 T:6177058816 DEBUG: CDVDPlayer::HandleMessages - player started DVDPLAYER_AUDIO
22:52:00.867 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:01.192 T:6181072896 DEBUG: Previous line repeats 49 times.
22:52:01.192 T:6181072896 NOTICE: fps: 25.000000, pwidth: 3840, pheight: 2160, dwidth: 3840, dheight: 2160, colorrange: Limited, colorspace: bt2020nc, colortransfer: arib-std-b67
22:52:01.192 T:6181072896 DEBUG: OutputPicture - change configuration. 3840x2160. framerate: 25.00. format: BYPASS
22:52:01.192 T:6181072896 NOTICE: Display resolution DESKTOP : 3840x2160@ 50.00 - Full Screen (16)
22:52:01.193 T:6181072896 DEBUG: displayRateSwitch request: refreshRate = 25.00, dynamicRange = HDR10
22:52:01.193 T:6181072896 DEBUG: CXBMCRenderManager::Configure - 3
22:52:01.217 T:6175338496 DEBUG: Activating window ID: 12005
22:52:01.218 T:6175338496 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
22:52:01.218 T:6175338496 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
22:52:01.221 T:6175338496 NOTICE: Using GL_TEXTURE_2D
22:52:01.223 T:6175338496 DEBUG: GL: Requested render method: 0
22:52:01.223 T:6175338496 NOTICE: GL: Using BYPASS render method
22:52:01.223 T:6175338496 NOTICE: GL: NPOT texture support detected
22:52:01.225 T:6177058816 DEBUG: CDVDPlayer::HandleMessages - player started DVDPLAYER_VIDEO
22:52:01.225 T:6177058816 DEBUG: CDVDPlayer::Sync - Audio - pts: 282666.000000, cache: 487166.688760, totalcache: 685333.311558
22:52:01.225 T:6177058816 DEBUG: CDVDPlayer::Sync - Video - pts: 0.000000, cache: 50000.000000, totalcache: 100000.000000
22:52:01.225 T:6177058816 DEBUG: CDVDPlayer::LogCacheState(HandlePlaySpeed) - CACHESTATE_DONE
22:52:01.225 T:6186807296 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(-204500.688760)
22:52:01.225 T:6186807296 DEBUG: CDVDAudio::Resume - resume audio stream
22:52:01.225 T:6181072896 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(-204500.688760)
22:52:01.226 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:01.226 T:6175911936 DEBUG: ActiveAE - start sync of audio stream
22:52:01.232 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
22:52:01.330 T:6175911936 DEBUG: Previous line repeats 1 times.
22:52:01.330 T:6175911936 DEBUG: ActiveAE::SyncStream - average error of 5.168249, start adjusting
22:52:01.331 T:6175911936 DEBUG: ActiveAE::SyncStream - average error 0.168249 below threshold of 30.000000
22:52:01.663 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
22:52:01.736 T:6181072896 DEBUG: Previous line repeats 3 times.
22:52:01.736 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
22:52:01.743 T:6181072896 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
22:52:01.848 T:6176485376 DEBUG: Previous line repeats 3 times.
22:52:01.848 T:6176485376 ERROR: CActiveAESink::OutputSamples - failed
22:52:01.865 T:6176485376 INFO: CActiveAESink::OpenSink - initialize sink
22:52:01.865 T:6176485376 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINIOS:default
22:52:01.865 T:6176485376 DEBUG: CAESinkDARWINIOS::Initialize: asked for 2 channels
22:52:01.871 T:6176485376 NOTICE: getNativeAudioSettings:Stereo
22:52:01.872 T:6176485376 DEBUG: CAESinkDARWINIOS::Initialize: AudioStreamBasicDescription: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz) pcm
22:52:01.874 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting channels 2
22:52:01.874 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting samplerate 48000.000000
22:52:01.874 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting buffer duration to 0.042667
22:52:01.896 T:6176485376 NOTICE: dumpAVAudioSessionProperties:maxchannels 32, deactivateMaxchannels 32
22:52:01.906 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:total latency = 0.087167
22:52:01.906 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setup audio format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
22:52:01.906 T:6176485376 NOTICE: dumpAVAudioSessionProperties:audio route = HDMIOutput
22:52:01.907 T:6176485376 NOTICE: dumpAVAudioSessionProperties:sampleRate 48000.000000
22:52:01.907 T:6176485376 NOTICE: dumpAVAudioSessionProperties:outputLatency 0.001833
22:52:01.907 T:6176485376 NOTICE: dumpAVAudioSessionProperties:IOBufferDuration 0.042667
22:52:01.907 T:6176485376 NOTICE: dumpAVAudioSessionProperties:outputNumberOfChannels 2
22:52:01.907 T:6176485376 NOTICE: dumpAVAudioSessionProperties:maximumOutputNumberOfChannels 32
22:52:01.907 T:6176485376 NOTICE: dumpAVAudioSessionProperties:SessionPortOutputNumberOfChannels 2
22:52:01.907 T:6176485376 DEBUG: DumpAudioDescriptions: dumpAVAudioSessionProperties
22:52:01.908 T:6176485376 DEBUG: DumpAudioDescriptions: portName, Vardagsrum
22:52:01.908 T:6176485376 DEBUG: DumpAudioDescriptions: portType, HDMIOutput
22:52:01.908 T:6176485376 DEBUG: DumpAudioDescriptions: portChannelCount, 2
22:52:01.908 T:6176485376 NOTICE: CAESinkDARWINIOS::Initialize: channel_index 0, maxChannels 32, outputChannels 2, portChannelCount 2
22:52:01.946 T:6176485376 DEBUG: CActiveAESink::OpenSink - DARWINIOS Initialized:
22:52:01.946 T:6176485376 DEBUG: Output Device : Default
22:52:01.946 T:6176485376 DEBUG: Sample Rate : 48000
22:52:01.946 T:6176485376 DEBUG: Sample Format : AE_FMT_FLOAT
22:52:01.946 T:6176485376 DEBUG: Channel Count : 2
22:52:01.946 T:6176485376 DEBUG: Channel Layout: FL,FR
22:52:01.946 T:6176485376 DEBUG: Frames : 1024
22:52:01.946 T:6176485376 DEBUG: Frame Size : 8
22:52:01.946 T:6176485376 DEBUG: CActiveAESink::GenerateNoise - noiseFactor = 0.000010
22:52:02.330 T:6175911936 DEBUG: ActiveAE::SyncStream - average error -149.290128 above threshold of 100.000000
22:52:02.330 T:6175911936 DEBUG: ActiveAE::SyncStream - average error -21.290128 below threshold of 30.000000
22:52:03.354 T:6175911936 DEBUG: ActiveAE::SyncStream - average error -135.237257 above threshold of 100.000000
22:52:03.354 T:6175911936 DEBUG: ActiveAE::SyncStream - average error -28.570590 below threshold of 30.000000
22:52:04.378 T:6186807296 DEBUG: CDVDClock::ErrorAdjust - CDVDPlayerAudio::OutputPacket - error:-28563.672952, adjusted:-28563.672952
22:52:46.138 T:6181072896 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 25.000000 fps
22:52:47.642 T:6186807296 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_EOF
22:52:47.719 T:6177058816 INFO: Process - eof reading from demuxer
22:52:47.719 T:6177058816 NOTICE: CDVDPlayer::OnExit()
22:52:47.719 T:6177058816 NOTICE: DVDPlayer: eof, waiting for queues to empty
22:52:47.719 T:6177058816 NOTICE: Closing stream player 1
22:52:47.719 T:6177058816 NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
22:52:47.720 T:6186807296 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
22:52:47.720 T:6177058816 NOTICE: Waiting for audio thread to exit
22:52:47.720 T:6186807296 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
22:52:47.720 T:6186807296 NOTICE: thread end: CDVDPlayerAudio::OnExit()
22:52:47.720 T:6177058816 NOTICE: Closing audio device
22:52:48.068 T:6175911936 DEBUG: CActiveAE::DiscardStream - audio stream deleted
22:52:48.068 T:6175911936 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:52:48.068 T:6177058816 DEBUG: Previous line repeats 1 times.
22:52:48.068 T:6177058816 NOTICE: Deleting audio codec
22:52:48.068 T:6177058816 NOTICE: Closing stream player 2
22:52:48.068 T:6177058816 NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
22:52:48.173 T:6177058816 ERROR: CDVDMsgGeneralSynchronize - timeout
22:52:48.282 T:6175911936 ERROR: Previous line repeats 1 times.
22:52:48.282 T:6175911936 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:52:48.379 T:6177058816 ERROR: CDVDMsgGeneralSynchronize - timeout
22:52:48.537 T:6176485376 ERROR: Previous line repeats 1 times.
22:52:48.537 T:6176485376 INFO: CActiveAESink::OpenSink - initialize sink
22:52:48.587 T:6177058816 ERROR: CDVDMsgGeneralSynchronize - timeout
22:52:48.597 T:6176485376 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINIOS:default
22:52:48.602 T:6176485376 DEBUG: CAESinkDARWINIOS::Initialize: asked for 2 channels
22:52:48.621 T:6176485376 NOTICE: getNativeAudioSettings:Stereo
22:52:48.623 T:6176485376 DEBUG: CAESinkDARWINIOS::Initialize: AudioStreamBasicDescription: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz) pcm
22:52:48.628 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting channels 2
22:52:48.628 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting samplerate 48000.000000
22:52:48.628 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setting buffer duration to 0.042667
22:52:48.657 T:6176485376 NOTICE: dumpAVAudioSessionProperties:maxchannels 32, deactivateMaxchannels 32
22:52:48.666 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:total latency = 0.087167
22:52:48.666 T:6176485376 NOTICE: CAAudioUnitSink::setupAudio:setup audio format: [lpcm] Mixable Interleaved 2 Channel 32-bit Floating Point LE (48000Hz)
22:52:48.667 T:6176485376 NOTICE: dumpAVAudioSessionProperties:audio route = HDMIOutput
22:52:48.667 T:6176485376 NOTICE: dumpAVAudioSessionProperties:sampleRate 48000.000000
22:52:48.667 T:6176485376 NOTICE: dumpAVAudioSessionProperties:outputLatency 0.001833
22:52:48.667 T:6176485376 NOTICE: dumpAVAudioSessionProperties:IOBufferDuration 0.042667
22:52:48.667 T:6176485376 NOTICE: dumpAVAudioSessionProperties:outputNumberOfChannels 2
22:52:48.667 T:6176485376 NOTICE: dumpAVAudioSessionProperties:maximumOutputNumberOfChannels 32
22:52:48.668 T:6176485376 NOTICE: dumpAVAudioSessionProperties:SessionPortOutputNumberOfChannels 2
22:52:48.668 T:6176485376 DEBUG: DumpAudioDescriptions: dumpAVAudioSessionProperties
22:52:48.668 T:6176485376 DEBUG: DumpAudioDescriptions: portName, Vardagsrum
22:52:48.668 T:6176485376 DEBUG: DumpAudioDescriptions: portType, HDMIOutput
22:52:48.668 T:6176485376 DEBUG: DumpAudioDescriptions: portChannelCount, 2
22:52:48.668 T:6176485376 NOTICE: CAESinkDARWINIOS::Initialize: channel_index 0, maxChannels 32, outputChannels 2, portChannelCount 2
22:52:48.693 T:6177058816 ERROR: CDVDMsgGeneralSynchronize - timeout
22:52:48.708 T:6176485376 DEBUG: CActiveAESink::OpenSink - DARWINIOS Initialized:
22:52:48.708 T:6176485376 DEBUG: Output Device : Default
22:52:48.708 T:6176485376 DEBUG: Sample Rate : 48000
22:52:48.708 T:6176485376 DEBUG: Sample Format : AE_FMT_FLOAT
22:52:48.708 T:6176485376 DEBUG: Channel Count : 2
22:52:48.708 T:6176485376 DEBUG: Channel Layout: FL,FR
22:52:48.708 T:6176485376 DEBUG: Frames : 1024
22:52:48.708 T:6176485376 DEBUG: Frame Size : 8
22:52:48.708 T:6176485376 DEBUG: CActiveAESink::GenerateNoise - noiseFactor = 0.000010
22:52:48.708 T:6175911936 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
22:52:48.798 T:6177058816 ERROR: CDVDMsgGeneralSynchronize - timeout
22:52:49.459 T:6181072896 ERROR: Previous line repeats 6 times.
22:52:49.460 T:6181072896 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
22:52:49.460 T:6181072896 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
22:52:49.460 T:6181072896 NOTICE: thread end: video_thread
22:52:49.460 T:6177058816 NOTICE: waiting for video thread to exit
22:52:49.461 T:6177058816 NOTICE: deleting video codec
22:52:49.472 T:6178779136 DEBUG: CDVDVideoCodecAVFoundation::Process Stopped
22:52:49.474 T:6177058816 DEBUG: CNFSFile::Close closing file volume1/Diverse/HDR/TF.mp4
22:52:49.475 T:6177058816 DEBUG: OnPlayBackEnded: play state was 2, ended 0
22:52:49.475 T:6177058816 DEBUG: CGUIWindowHome::Announce, type: 1, from xbmc, message OnStop
22:52:49.476 T:6177058816 DEBUG: CGUIWindowHome::SetupServices() - !IsActive()
22:52:49.499 T:6175338496 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
22:52:49.499 T:6175338496 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
22:52:49.505 T:6175338496 DEBUG: found key /userdata/profiles.xml
22:52:49.507 T:6175338496 DEBUG: Previous line repeats 1 times.
22:52:49.507 T:6175338496 DEBUG: NSUSerDefaults: compressed /userdata/profiles.xml from 923 to 324
22:52:49.507 T:6175338496 DEBUG: found key /userdata/guisettings.xml
22:52:49.519 T:6175338496 DEBUG: Previous line repeats 1 times.
22:52:49.519 T:6175338496 DEBUG: NSUSerDefaults: compressed /userdata/guisettings.xml from 31121 to 6187
22:52:49.520 T:6175338496 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
22:52:49.533 T:6175338496 DEBUG: ------ Window Init (MyVideoNav.xml) ------
22:52:49.542 T:6175338496 DEBUG: ExcludeFileOrFolder: File 'nfs://192.168.1.115/volume1/Diverse/HDR/@eaDir/' excluded. (Matches exclude rule RegExp:'\@eaDir')
22:52:49.605 T:6175338496 NOTICE: CDVDPlayer::CloseFile()
22:52:49.605 T:6175338496 NOTICE: DVDPlayer: waiting for threads to exit
22:52:49.605 T:6175338496 NOTICE: DVDPlayer: finished waiting
22:52:49.605 T:6175338496 DEBUG: displayRateReset
22:52:50.112 T:6175338496 NOTICE: CDVDPlayer::CloseFile()
22:52:50.112 T:6175338496 NOTICE: DVDPlayer: waiting for threads to exit
22:52:50.112 T:6175338496 NOTICE: DVDPlayer: finished waiting
22:52:50.120 T:6173618176 DEBUG: DoWork - Saving file state for video item nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4
22:52:50.128 T:6173618176 DEBUG: DoWork - Marking video item nfs://192.168.1.115/volume1/Diverse/HDR/TF.mp4 as watched
22:52:50.417 T:6176485376 ERROR: CActiveAESink::OutputSamples - failed
22:52:51.367 T:6172471296 DEBUG: JSONRPC: Value does not lay between minimum and maximum in type playerid

[amet]

Pastebin would be better and full log as well

[davilla]

sample plays fine here.

[amet]

plays fine here as well.. video of it playing below

https://www.dropbox.com/s/jnhs6yn2ajbeh ... 4.MOV?dl=0

[Golge77]

I uninstalled and reinstalled MrMc again, it's marginally better performance with the videoclip.

The odd this is that
When using "the Wrong settings" as explained earlier to force no switch to HDR it plays much smoother.

before version 3.9.7 when the HDR switch worked it played as smooth as now but only if you force it to not switch, when you let the clip switch to HDR with version 3.9.9 it does not play smooth.

I had no problem with this clip or other similar clip in the version before 3.9.7 and now I have.

I have checked via webinterface the cpu load etc. and it's aroung 6-12% when playing these samples and no other bottlenecks that I can see.

I have Infuse 5 Pro installed( no updates anymoreso it stays the same)I don't use it other than when I have trouble with shares or playback in MrMc I try if it is the same problem in Infuse or is it Apple update problem (running latest TvOS beta now)

When trying Infuse 5 pro with the clip it plays smooth allthough the colors are wrong due to bad HDR switch


Can you test if my sample plays smoother at your setup when force it to not switch to HDR?


The code below what does it mean?
22:52:00.691 T:6175338496 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED

[amet]

What do you mean to force it to not switch? Play as non HDR?

[Golge77]

With force I mean, If the option -use videoToolbox for 4k HEVC HDR is checked the video do not switch to HDR.

When playing the videoclip this way I get no stuttering,
when I uncheck it and the video switch to HDR then the stutter appears again

[amet]

I get no stuttering with or without using the “videoToolbox to play 4k hevc hdr”