Sound issue in brief: Returning to MrMC after using Netflix or Hulu I get audio stutters playing files within MrMc in pretty much all video files I have tried so far. This consists of stutters and clicks while the video appears okay on screen. Restarting the ATV 4K fixes the issue but the problem returns after using aforementioned apps again.
I downloaded Infuse and there are no issues playing the same files within infuse after Hulu / Netflix etc.
Setup: ATV > Sony HTNT5 soundbar with surround speakers > TV all by HDMI cable.
Passthrough in MrMc currently off
ATV settings currently 5.1, reduce loud sounds off, audio mode auto (although I’ve tried many permutations & combinations)
Debug log playing file when sound is working:
Code: Select all
18:30:30 T:6103543808 DEBUG: Previous line repeats 2 times.
18:30:30 T:6103543808 DEBUG: ------ Window Init (DialogBusy.xml) ------
18:30:30 T:6103543808 DEBUG: CPU used = 13/300 percent, App Memory: 207.98 MBs, delta = -36880384 bytes
18:30:30 T:6103543808 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
18:30:30 T:6103543808 DEBUG: RunQuery took 1 ms for 15 items query: SELECT files.strFilename, files.playCount, bookmark.timeInSeconds, bookmark.totalTimeInSeconds FROM files LEFT JOIN bookmark ON files.idFile = bookmark.idFile AND bookmark.type = 1 WHERE files.idPath=485
18:30:31 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:32 T:6103543808 DEBUG: Previous line repeats 1 times.
18:30:32 T:6103543808 DEBUG: OnPlayMedia smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:30:32 T:6103543808 DEBUG: GetMovieId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMovie from movie where idFile=849
18:30:32 T:6103543808 DEBUG: GetEpisodeId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idEpisode from episode where idFile=849
18:30:32 T:6103543808 DEBUG: GetMusicVideoId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMVideo from musicvideo where idFile=849
18:30:32 T:6103543808 DEBUG: Loading settings for smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:30:32 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers(smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv)
18:30:32 T:6103543808 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
18:30:32 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
18:30:32 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
18:30:32 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
18:30:32 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
18:30:32 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
18:30:32 T:6103543808 NOTICE: CDVDPlayer::Opening: smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:30:32 T:6103543808 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:30:32 T:6101823488 NOTICE: Creating InputStream
18:30:32 T:6101823488 DEBUG: CSMBFile::Open - opened homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv, fd=10000
18:30:32 T:6101823488 DEBUG: ScanForExternalSubtitles: Searching for subtitles...
18:30:32 T:6101823488 DEBUG: ScanForExternalSubtitles: END (total time: 3 ms)
18:30:32 T:6101823488 NOTICE: Creating Demuxer
18:30:32 T:6101823488 DEBUG: Open - m_ioContext->max_packet_size(1) = 32768
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 32768
18:30:32 T:6101823488 DEBUG: Open - probing detected format [matroska,webm]
18:30:32 T:6101823488 DEBUG: Open - avformat_find_stream_info starting
18:30:32 T:6101823488 DEBUG: ffmpeg[16BB27000]: [h264] Reinit context to 1920x1088, pix_fmt: yuv420p
18:30:32 T:6101823488 DEBUG: Open - av_find_stream_info finished
18:30:32 T:6101823488 INFO: ffmpeg[16BB27000]: Input #0, matroska,webm, smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mk':
18:30:32 T:6101823488 INFO: ffmpeg[16BB27000]: Metadata:
18:30:32 T:6101823488 INFO: ffmpeg[16BB27000]: ENCODER : Lavf55.19.104
18:30:32 T:6101823488 INFO: ffmpeg[16BB27000]: Duration: 00:00:48.97, start: 0.000000, bitrate: 21791 kb/s
18:30:32 T:6101823488 INFO: ffmpeg[16BB27000]: Stream #0:0(eng): Video: h264 (Constrained Baseline), yuv420p(progressive), 1920x1080 [SAR 1:1 DAR 16:9], 25 fps, 25 tbr, 1k tbn, 50 tbc (default)
18:30:32 T:6101823488 INFO: ffmpeg[16BB27000]: Stream #0:1: Audio: dts (DTS), 48000 Hz, 5.1(side), fltp, 1536 kb/s
18:30:32 T:6101823488 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
18:30:32 T:6101823488 DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
18:30:32 T:6101823488 NOTICE: Opening stream: 0 source: 256
18:30:32 T:6101823488 NOTICE: Creating video codec with codec id: 28
18:30:32 T:6101823488 DEBUG: FactoryCodec - Video: vtb - Opening
18:30:32 T:6101823488 NOTICE: Constructing new format description
18:30:32 T:6101823488 DEBUG: VideoToolBox: opened width(1920), height(1080)
18:30:32 T:6101823488 DEBUG: FactoryCodec - Video: vtb-h264 - Opened
18:30:32 T:6101823488 NOTICE: Creating video thread
18:30:32 T:6101823488 NOTICE: Opening stream: 1 source: 256
18:30:32 T:6106411008 DEBUG: CVideoSyncIos::Setup setting up OSX
18:30:32 T:6101823488 NOTICE: Finding audio codec for: 86020
18:30:32 T:6117306368 NOTICE: running thread: video_thread
18:30:32 T:6106411008 DEBUG: CVideoSyncIos: setting up displaylink
18:30:32 T:6106411008 DEBUG: CVideoSyncIos::GetFps Detected refreshrate: 59.940060 hertz
18:30:32 T:6106411008 DEBUG: CVideoReferenceClock: Detected refreshrate: 59.940 hertz
18:30:32 T:6101823488 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
18:30:32 T:6101823488 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
18:30:32 T:6101823488 NOTICE: Creating audio thread
18:30:32 T:6101823488 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:30:32 T:6117879808 NOTICE: running thread: CDVDPlayerAudio::Process()
18:30:32 T:6101823488 DEBUG: OnPlayBackStarted: play state was 1, starting 1
18:30:32 T:6117306368 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
18:30:32 T:6103543808 DEBUG: PlayFile: OpenFile succeed, play state 2
18:30:32 T:6103543808 DEBUG: OnPlayBackStarted: play state was 2, starting 0
18:30:32 T:6103543808 DEBUG: CGUIInfoManager::SetCurrentMovie(smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv)
18:30:32 T:6103543808 DEBUG: GetMovieId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMovie from movie where idFile=849
18:30:32 T:6103543808 DEBUG: GetEpisodeId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idEpisode from episode where idFile=849
18:30:32 T:6103543808 DEBUG: GetMusicVideoId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMVideo from musicvideo where idFile=849
18:30:32 T:6103543808 DEBUG: CTraktServiceJob::Announce OnPlay currentSeconds = 0.000000
18:30:32 T:6116732928 DEBUG: CTraktServiceJob::OnPlay currentTime = 0.000000
18:30:32 T:6116732928 DEBUG: CTraktServices::ReportProgress status = start, percentage = 0.000000
18:30:32 T:6117879808 NOTICE: Creating audio stream (codec id: 86020, channels: 6, sample rate: 48000, no pass-through)
18:30:32 T:6117879808 DEBUG: CDVDPlayerAudio:: synctype set to 1: resample
18:30:32 T:6105264128 INFO: CActiveAESink::OpenSink - initialize sink
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 74068
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 96650
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 126990
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 147792
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 164332
18:30:32 T:6105264128 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINIOS:default
18:30:32 T:6105264128 DEBUG: virtual bool CAESinkDARWINIOS::Initialize(AEAudioFormat &, std::string &): AudioStreamBasicDescription: [lpcm] Mixable Interleaved 6 Channel 32-bit Floating Point LE (48000Hz) pcm
18:30:32 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting channels 6
18:30:32 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting samplerate 48000.000000
18:30:32 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting buffer duration to 0.128000
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 183247
18:30:32 T:6117306368 DEBUG: GetPicture - VTBDecoderDecode dts(-4503599627370496.000000), pts(0.000000), old_pts(26920000.000000)
18:30:32 T:6117306368 NOTICE: fps: 25.000000, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080, colorrange: Limited, colorspace: unknown, colortransfer: unknown
18:30:32 T:6117306368 DEBUG: OutputPicture - change configuration. 1920x1080. framerate: 25.00. format: BGRA
18:30:32 T:6117306368 NOTICE: Display resolution DESKTOP : 3840x2160@ 59.94 - Full Screen (16)
18:30:32 T:6117306368 DEBUG: displayRateSwitch request: refreshRate = 25.00, dynamicRange = SDR
18:30:32 T:6117306368 DEBUG: CXBMCRenderManager::Configure - 4
18:30:32 T:6117306368 DEBUG: CVideoReferenceClock: Clock speed 99.900099%
18:30:32 T:7261201088 DEBUG: CWinSystemIOS::AnnounceOnLostDevice
18:30:32 T:6103543808 DEBUG: Activating window ID: 12005
18:30:32 T:6103543808 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
18:30:32 T:6103543808 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
18:30:32 T:6103543808 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
18:30:32 T:6103543808 NOTICE: Using GL_TEXTURE_2D
18:30:32 T:6103543808 DEBUG: GL: Requested render method: 0
18:30:32 T:6103543808 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:30:32 T:6103543808 ERROR: GL: BaseYUV2RGBGLSLShader - unsupported format 13
18:30:32 T:6103543808 ERROR: Previous line repeats 1 times.
18:30:32 T:6103543808 NOTICE: GL: NPOT texture support detected
18:30:32 T:6101823488 DEBUG: CDVDPlayer::HandleMessages - player started DVDPLAYER_VIDEO
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 197207
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 207212
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 273892
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 276660
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 340970
18:30:32 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() total latency = 0.072000
18:30:32 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setup audio format: [lpcm] Mixable Interleaved 6 Channel 32-bit Floating Point LE (48000Hz)
18:30:32 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() audio route = HDMIOutput
18:30:32 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() sampleRate 48000.000000
18:30:32 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() outputLatency 0.040000
18:30:32 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() IOBufferDuration 0.032000
18:30:32 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() outputNumberOfChannels 6
18:30:32 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() maximumOutputNumberOfChannels 6
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: void dumpAVAudioSessionProperties()
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: input count = 0
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: output count = 1
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions : portName, Apple TV
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: channelLabel, -1
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: channelName , Apple TV 1
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: channelLabel, -1
18:30:32 T:6105264128 DEBUG: DumpAudioDescriptions: channelName , Apple TV 2
18:30:32 T:6101823488 DEBUG: Read - max read bytes = 343717
18:30:33 T:6105264128 DEBUG: CActiveAESink::OpenSink - DARWINIOS Initialized:
18:30:33 T:6105264128 DEBUG: Output Device : Default
18:30:33 T:6105264128 DEBUG: Sample Rate : 48000
18:30:33 T:6105264128 DEBUG: Sample Format : AE_FMT_FLOAT
18:30:33 T:6105264128 DEBUG: Channel Count : 6
18:30:33 T:6105264128 DEBUG: Channel Layout: FL,FC,FR,BL,BR,LFE
18:30:33 T:6105264128 DEBUG: Frames : 1024
18:30:33 T:6105264128 DEBUG: Frame Size : 24
18:30:33 T:6105264128 DEBUG: CActiveAESink::GenerateNoise - noiseFactor = 0.000010
18:30:33 T:6104690688 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:30:33 T:6101823488 DEBUG: Read - max read bytes = 362730
18:30:33 T:6101823488 DEBUG: Read - max read bytes = 394539
18:30:33 T:7261201088 NOTICE: CDVDPlayer: OnLostDevice received
18:30:33 T:7261201088 DEBUG: displayModeSwitchInProgress == YES, refreshRate = 25.00, dynamicRange = SDR
18:30:33 T:6117306368 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_PAUSE: 1
18:30:33 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:33 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:30:33 T:6100103168 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:33 T:6105837568 DEBUG: JSONRPC: Value does not lay between minimum and maximum in type playlistid
18:30:33 T:7261201088 DEBUG: -[MainController displayLinkTick:]: displayRate = 50.000000
18:30:33 T:6100103168 DEBUG: webserver: request received for /jsonrpc?Player.GetItem
18:30:33 T:6100103168 DEBUG: GetMovieId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMovie from movie where idFile=849
18:30:33 T:6100103168 DEBUG: GetEpisodeId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idEpisode from episode where idFile=849
18:30:33 T:6100103168 DEBUG: GetMusicVideoId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMVideo from musicvideo where idFile=849
18:30:33 T:6100103168 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:33 T:6103543808 DEBUG: CPU used = 13/300 percent, App Memory: 260.50 MBs, delta = 55066624 bytes
18:30:33 T:6117879808 ERROR: CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
18:30:33 T:6117879808 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_PAUSE: 1
18:30:34 T:6100103168 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:34 T:6100103168 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:30:34 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:34 T:6105837568 DEBUG: webserver: request received for /image/image://video@smb%253a%252f%252f192.168.1.143%252fhomes%252fadmin%252fTest%2520Videos%252fdts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv/
18:30:35 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:35 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:35 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:30:35 T:7261201088 DEBUG: CWinSystemIOS::AnnounceOnResetDevice
18:30:35 T:7261201088 NOTICE: CDVDPlayer: OnResetDevice received
18:30:35 T:6104690688 DEBUG: CActiveAE - display reset event
18:30:35 T:7261201088 DEBUG: displayModeSwitchInProgress == DONE, refreshRate = 50.00, dynamicRange = SDR
18:30:35 T:6105264128 INFO: CActiveAESink::OpenSink - initialize sink
18:30:35 T:6105264128 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINIOS:default
18:30:35 T:6105264128 DEBUG: virtual bool CAESinkDARWINIOS::Initialize(AEAudioFormat &, std::string &): AudioStreamBasicDescription: [lpcm] Mixable Interleaved 6 Channel 32-bit Floating Point LE (48000Hz) pcm
18:30:35 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting channels 6
18:30:35 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting samplerate 48000.000000
18:30:35 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting buffer duration to 0.128000
18:30:35 T:6106411008 DEBUG: CVideoSyncIos::Cleanup cleaning up OSX
18:30:35 T:6106411008 DEBUG: CVideoSyncIos::Setup setting up OSX
18:30:35 T:6106411008 DEBUG: CVideoSyncIos: setting up displaylink
18:30:35 T:6106411008 DEBUG: CVideoSyncIos::GetFps Detected refreshrate: 50.000000 hertz
18:30:35 T:6106411008 DEBUG: CVideoReferenceClock: Detected refreshrate: 50.000 hertz
18:30:35 T:6103543808 DEBUG: CPU used = 13/300 percent, App Memory: 251.58 MBs, delta = -9355264 bytes
18:30:36 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:36 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:36 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:30:36 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() total latency = 0.072000
18:30:36 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setup audio format: [lpcm] Mixable Interleaved 6 Channel 32-bit Floating Point LE (48000Hz)
18:30:36 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() audio route = HDMIOutput
18:30:36 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() sampleRate 48000.000000
18:30:36 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() outputLatency 0.040000
18:30:36 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() IOBufferDuration 0.032000
18:30:36 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() outputNumberOfChannels 6
18:30:36 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() maximumOutputNumberOfChannels 6
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: void dumpAVAudioSessionProperties()
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: input count = 0
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: output count = 1
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions : portName, Apple TV
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: channelLabel, -1
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: channelName , Apple TV 1
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: channelLabel, -1
18:30:36 T:6105264128 DEBUG: DumpAudioDescriptions: channelName , Apple TV 2
18:30:36 T:6105264128 DEBUG: CActiveAESink::OpenSink - DARWINIOS Initialized:
18:30:36 T:6105264128 DEBUG: Output Device : Default
18:30:36 T:6105264128 DEBUG: Sample Rate : 48000
18:30:36 T:6105264128 DEBUG: Sample Format : AE_FMT_FLOAT
18:30:36 T:6105264128 DEBUG: Channel Count : 6
18:30:36 T:6105264128 DEBUG: Channel Layout: FL,FC,FR,BL,BR,LFE
18:30:36 T:6105264128 DEBUG: Frames : 1024
18:30:36 T:6105264128 DEBUG: Frame Size : 24
18:30:36 T:6105264128 DEBUG: CActiveAESink::GenerateNoise - noiseFactor = 0.000010
18:30:36 T:6104690688 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:30:37 T:6105837568 DEBUG: Previous line repeats 3 times.
18:30:37 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:37 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:37 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:30:38 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:30:38 T:6105837568 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:30:38 T:6105837568 DEBUG: webserver: request received for /jsonrpc?System.IsLite
18:30:38 T:6105837568 DEBUG: webserver: request received for /vfs%2Fspecial%3A%2F%2Flogs%2Fmrmc.log?1530167433213
Debug log playing same file with sound problem (ie after playing a file in Netflix):
Code: Select all
18:33:38 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:40 T:6103543808 DEBUG: Previous line repeats 1 times.
18:33:40 T:6103543808 DEBUG: CPU used = 12/300 percent, App Memory: 240.92 MBs, delta = 16334848 bytes
18:33:40 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:42 T:6103543808 DEBUG: Previous line repeats 2 times.
18:33:42 T:6103543808 DEBUG: CPU used = 12/300 percent, App Memory: 240.73 MBs, delta = -196608 bytes
18:33:43 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:43 T:6103543808 DEBUG: RunQuery took 1 ms for 15 items query: SELECT files.strFilename, files.playCount, bookmark.timeInSeconds, bookmark.totalTimeInSeconds FROM files LEFT JOIN bookmark ON files.idFile = bookmark.idFile AND bookmark.type = 1 WHERE files.idPath=485
18:33:44 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:45 T:6103543808 DEBUG: Previous line repeats 1 times.
18:33:45 T:6103543808 DEBUG: CPU used = 9/300 percent, App Memory: 239.86 MBs, delta = -917504 bytes
18:33:46 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:46 T:6103543808 DEBUG: OnPlayMedia smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:33:46 T:6103543808 DEBUG: GetMovieId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMovie from movie where idFile=849
18:33:46 T:6103543808 DEBUG: GetEpisodeId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idEpisode from episode where idFile=849
18:33:46 T:6103543808 DEBUG: GetMusicVideoId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMVideo from musicvideo where idFile=849
18:33:46 T:6103543808 DEBUG: Loading settings for smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:33:46 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers(smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv)
18:33:46 T:6103543808 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
18:33:46 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
18:33:46 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
18:33:46 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
18:33:46 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
18:33:46 T:6103543808 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
18:33:46 T:6103543808 NOTICE: CDVDPlayer::Opening: smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:33:46 T:6103543808 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:33:46 T:6100676608 NOTICE: Creating InputStream
18:33:46 T:6100676608 DEBUG: CSMBFile::Open - opened homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv, fd=10000
18:33:46 T:6100676608 DEBUG: ScanForExternalSubtitles: Searching for subtitles...
18:33:46 T:6100676608 DEBUG: ScanForExternalSubtitles: END (total time: 3 ms)
18:33:46 T:6100676608 NOTICE: Creating Demuxer
18:33:46 T:6100676608 DEBUG: Open - m_ioContext->max_packet_size(1) = 32768
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 32768
18:33:46 T:6100676608 DEBUG: Open - probing detected format [matroska,webm]
18:33:46 T:6100676608 DEBUG: Open - avformat_find_stream_info starting
18:33:46 T:6100676608 DEBUG: ffmpeg[16BA0F000]: [h264] Reinit context to 1920x1088, pix_fmt: yuv420p
18:33:46 T:6100676608 DEBUG: Open - av_find_stream_info finished
18:33:46 T:6100676608 INFO: ffmpeg[16BA0F000]: Input #0, matroska,webm, smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mk':
18:33:46 T:6100676608 INFO: ffmpeg[16BA0F000]: Metadata:
18:33:46 T:6100676608 INFO: ffmpeg[16BA0F000]: ENCODER : Lavf55.19.104
18:33:46 T:6100676608 INFO: ffmpeg[16BA0F000]: Duration: 00:00:48.97, start: 0.000000, bitrate: 21791 kb/s
18:33:46 T:6100676608 INFO: ffmpeg[16BA0F000]: Stream #0:0(eng): Video: h264 (Constrained Baseline), yuv420p(progressive), 1920x1080 [SAR 1:1 DAR 16:9], 25 fps, 25 tbr, 1k tbn, 50 tbc (default)
18:33:46 T:6100676608 INFO: ffmpeg[16BA0F000]: Stream #0:1: Audio: dts (DTS), 48000 Hz, 5.1(side), fltp, 1536 kb/s
18:33:46 T:6100676608 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
18:33:46 T:6100676608 DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
18:33:46 T:6100676608 NOTICE: Opening stream: 0 source: 256
18:33:46 T:6100676608 NOTICE: Creating video codec with codec id: 28
18:33:46 T:6100676608 DEBUG: FactoryCodec - Video: vtb - Opening
18:33:46 T:6100676608 NOTICE: Constructing new format description
18:33:46 T:6100676608 DEBUG: VideoToolBox: opened width(1920), height(1080)
18:33:46 T:6100676608 DEBUG: FactoryCodec - Video: vtb-h264 - Opened
18:33:46 T:6100676608 NOTICE: Creating video thread
18:33:46 T:6100676608 NOTICE: Opening stream: 1 source: 256
18:33:46 T:6104117248 DEBUG: CVideoSyncIos::Setup setting up OSX
18:33:46 T:6100676608 NOTICE: Finding audio codec for: 86020
18:33:46 T:6105837568 NOTICE: running thread: video_thread
18:33:46 T:6104117248 DEBUG: CVideoSyncIos: setting up displaylink
18:33:46 T:6104117248 DEBUG: CVideoSyncIos::GetFps Detected refreshrate: 59.940060 hertz
18:33:46 T:6104117248 DEBUG: CVideoReferenceClock: Detected refreshrate: 59.940 hertz
18:33:46 T:6100676608 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
18:33:46 T:6100676608 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
18:33:46 T:6100676608 NOTICE: Creating audio thread
18:33:46 T:6100676608 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv
18:33:46 T:6106984448 NOTICE: running thread: CDVDPlayerAudio::Process()
18:33:46 T:6100676608 DEBUG: OnPlayBackStarted: play state was 1, starting 1
18:33:46 T:6103543808 DEBUG: PlayFile: OpenFile succeed, play state 2
18:33:46 T:6103543808 DEBUG: OnPlayBackStarted: play state was 2, starting 0
18:33:46 T:6105837568 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
18:33:46 T:6103543808 DEBUG: CGUIInfoManager::SetCurrentMovie(smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv)
18:33:46 T:6103543808 DEBUG: GetMovieId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMovie from movie where idFile=849
18:33:46 T:6103543808 DEBUG: GetEpisodeId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idEpisode from episode where idFile=849
18:33:46 T:6103543808 DEBUG: GetMusicVideoId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMVideo from musicvideo where idFile=849
18:33:46 T:6103543808 DEBUG: CTraktServiceJob::Announce OnPlay currentSeconds = 0.000000
18:33:46 T:6101250048 DEBUG: CTraktServiceJob::OnPlay currentTime = 0.000000
18:33:46 T:6101250048 DEBUG: CTraktServices::ReportProgress status = start, percentage = 0.000000
18:33:46 T:6106984448 NOTICE: Creating audio stream (codec id: 86020, channels: 6, sample rate: 48000, no pass-through)
18:33:46 T:6106984448 DEBUG: CDVDPlayerAudio:: synctype set to 1: resample
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 74068
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 96650
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 126990
18:33:46 T:6105264128 INFO: CActiveAESink::OpenSink - initialize sink
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 147792
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 164332
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 183247
18:33:46 T:6105264128 DEBUG: CActiveAESink::OpenSink - trying to open device DARWINIOS:default
18:33:46 T:6105264128 DEBUG: virtual bool CAESinkDARWINIOS::Initialize(AEAudioFormat &, std::string &): AudioStreamBasicDescription: [lpcm] Mixable Interleaved 6 Channel 32-bit Floating Point LE (48000Hz) pcm
18:33:46 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting channels 6
18:33:46 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting samplerate 48000.000000
18:33:46 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setting buffer duration to 0.128000
18:33:46 T:6105264128 WARNING: AVAudioSession setActive NO failed: 560030580
18:33:46 T:6105837568 DEBUG: GetPicture - VTBDecoderDecode dts(-4503599627370496.000000), pts(0.000000), old_pts(34560000.000000)
18:33:46 T:6105837568 NOTICE: fps: 25.000000, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080, colorrange: Limited, colorspace: unknown, colortransfer: unknown
18:33:46 T:6105837568 DEBUG: OutputPicture - change configuration. 1920x1080. framerate: 25.00. format: BGRA
18:33:46 T:6105837568 NOTICE: Display resolution DESKTOP : 3840x2160@ 59.94 - Full Screen (16)
18:33:46 T:6105837568 DEBUG: displayRateSwitch request: refreshRate = 25.00, dynamicRange = SDR
18:33:46 T:6105837568 DEBUG: CXBMCRenderManager::Configure - 4
18:33:46 T:6105837568 DEBUG: CVideoReferenceClock: Clock speed 99.900099%
18:33:46 T:6103543808 DEBUG: Activating window ID: 12005
18:33:46 T:6103543808 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
18:33:46 T:6103543808 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
18:33:46 T:6103543808 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
18:33:46 T:6103543808 NOTICE: Using GL_TEXTURE_2D
18:33:46 T:6103543808 DEBUG: GL: Requested render method: 0
18:33:46 T:6103543808 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:33:46 T:6103543808 ERROR: GL: BaseYUV2RGBGLSLShader - unsupported format 13
18:33:46 T:6103543808 ERROR: Previous line repeats 1 times.
18:33:46 T:6103543808 NOTICE: GL: NPOT texture support detected
18:33:46 T:6100676608 DEBUG: CDVDPlayer::HandleMessages - player started DVDPLAYER_VIDEO
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 197207
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 207212
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 273892
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 276660
18:33:46 T:6100676608 DEBUG: Read - max read bytes = 340970
18:33:47 T:6100676608 DEBUG: Read - max read bytes = 343717
18:33:47 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() total latency = 0.072000
18:33:47 T:6105264128 NOTICE: bool CAAudioUnitSink::setupAudio() setup audio format: [lpcm] Mixable Interleaved 6 Channel 32-bit Floating Point LE (48000Hz)
18:33:47 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() audio route = HDMIOutput
18:33:47 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() sampleRate 48000.000000
18:33:47 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() outputLatency 0.040000
18:33:47 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() IOBufferDuration 0.032000
18:33:47 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() outputNumberOfChannels 6
18:33:47 T:6105264128 NOTICE: void dumpAVAudioSessionProperties() maximumOutputNumberOfChannels 6
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: void dumpAVAudioSessionProperties()
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: input count = 0
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: output count = 1
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions : portName, Apple TV
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: channelLabel, -1
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: channelName , Apple TV 1
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: channelLabel, -1
18:33:47 T:6105264128 DEBUG: DumpAudioDescriptions: channelName , Apple TV 2
18:33:47 T:6105264128 DEBUG: CActiveAESink::OpenSink - DARWINIOS Initialized:
18:33:47 T:6105264128 DEBUG: Output Device : Default
18:33:47 T:6105264128 DEBUG: Sample Rate : 48000
18:33:47 T:6105264128 DEBUG: Sample Format : AE_FMT_FLOAT
18:33:47 T:6105264128 DEBUG: Channel Count : 6
18:33:47 T:6105264128 DEBUG: Channel Layout: FL,FC,FR,BL,BR,LFE
18:33:47 T:6105264128 DEBUG: Frames : 1024
18:33:47 T:6105264128 DEBUG: Frame Size : 24
18:33:47 T:6105264128 DEBUG: CActiveAESink::GenerateNoise - noiseFactor = 0.000010
18:33:47 T:6104690688 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:33:47 T:6100676608 DEBUG: Previous line repeats 1 times.
18:33:47 T:6100676608 DEBUG: CDVDPlayer::HandleMessages - player started DVDPLAYER_AUDIO
18:33:47 T:6100676608 DEBUG: CDVDPlayer::Sync - Audio - pts: 299000.000000, cache: 466666.684469, totalcache: 685333.311558
18:33:47 T:6100676608 DEBUG: CDVDPlayer::Sync - Video - pts: 0.000000, cache: 50000.000000, totalcache: 100000.000000
18:33:47 T:6100676608 DEBUG: CDVDPlayer::LogCacheState(HandlePlaySpeed) - CACHESTATE_DONE
18:33:47 T:6106984448 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(-167666.684469)
18:33:47 T:6105837568 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(-167666.684469)
18:33:47 T:6106984448 DEBUG: CDVDAudio::Resume - resume audio stream
18:33:47 T:6105837568 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
18:33:47 T:6104690688 DEBUG: ActiveAE - start sync of audio stream
18:33:47 T:6105837568 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
18:33:47 T:6100676608 DEBUG: Read - max read bytes = 362730
18:33:47 T:6100676608 DEBUG: Read - max read bytes = 394539
18:33:47 T:6104690688 DEBUG: ActiveAE::SyncStream - average error of -12.630962, start adjusting
18:33:47 T:6104690688 DEBUG: ActiveAE::SyncStream - average error -0.005962 below threshold of 30.000000
18:33:47 T:7261201088 DEBUG: -[MainController displayLinkTick:]: displayRate = 50.000000
18:33:47 T:6103543808 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
18:33:47 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:47 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:47 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:48 T:6103543808 DEBUG: CPU used = 9/300 percent, App Memory: 252.12 MBs, delta = 12861440 bytes
18:33:48 T:6104690688 DEBUG: ffmpeg[16BDE3000]: [in] tb:1/48000 samplefmt:flt samplerate:48000 chlayout:0x3f
18:33:48 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:48 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:48 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:49 T:6104690688 DEBUG: ffmpeg[16BDE3000]: [in] tb:1/48000 samplefmt:flt samplerate:48000 chlayout:0x3f
18:33:49 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:49 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:49 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:50 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 318.674717 above threshold of 200.000000
18:33:50 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:50 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:50 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 24.674717 below threshold of 30.000000
18:33:50 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:50 T:6103543808 DEBUG: CPU used = 29/300 percent, App Memory: 254.81 MBs, delta = 2818048 bytes
18:33:51 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:51 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:51 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 228.771544 above threshold of 200.000000
18:33:51 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:51 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 18.771544 below threshold of 30.000000
18:33:52 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:52 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:52 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:52 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 228.544094 above threshold of 200.000000
18:33:52 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 18.544094 below threshold of 30.000000
18:33:53 T:6103543808 DEBUG: CPU used = 29/300 percent, App Memory: 257.95 MBs, delta = 3293184 bytes
18:33:53 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:53 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:53 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:54 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 217.675945 above threshold of 200.000000
18:33:54 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 28.675945 below threshold of 30.000000
18:33:54 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:54 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:54 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:55 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 225.321008 above threshold of 200.000000
18:33:55 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 15.321008 below threshold of 30.000000
18:33:55 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:55 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:55 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:56 T:6103543808 DEBUG: CPU used = 34/300 percent, App Memory: 252.28 MBs, delta = -5947392 bytes
18:33:56 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 211.621645 above threshold of 200.000000
18:33:56 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 22.621645 below threshold of 30.000000
18:33:56 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:56 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:56 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:57 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 214.847462 above threshold of 200.000000
18:33:57 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:57 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:57 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 25.847462 below threshold of 30.000000
18:33:58 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:58 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:58 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:58 T:6103543808 DEBUG: CPU used = 34/300 percent, App Memory: 216.88 MBs, delta = -37126144 bytes
18:33:58 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 219.687087 above threshold of 200.000000
18:33:58 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 9.687087 below threshold of 30.000000
18:33:59 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:59 T:6123040768 DEBUG: webserver: request received for /
18:33:59 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:59 T:6123040768 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:59 T:6115012608 DEBUG: webserver: request received for /css/core.css?1.3.57
18:33:59 T:6100103168 DEBUG: webserver: request received for /js/xbmc.launcher.js?v=2.1.0
18:33:59 T:6100103168 DEBUG: webserver: request received for /css/ipad.css?1.0.5
18:33:59 T:6100103168 DEBUG: webserver: request received for /js/jquery-1.8.2.min.js?2.1.0
18:33:59 T:6115012608 DEBUG: webserver: request received for /js/json2.js?2.1.0
18:33:59 T:6108131328 DEBUG: webserver: request received for /js/iscroll-min.js?2.1.0
18:33:59 T:6115586048 DEBUG: webserver: request received for /js/xbmc.core.js?2.1.0
18:33:59 T:6116732928 DEBUG: webserver: request received for /js/xbmc.rpc.js?2.1.0
18:33:59 T:6117306368 DEBUG: webserver: request received for /js/MediaLibrary.js?2.1.0
18:33:59 T:6100103168 DEBUG: webserver: request received for /js/NowPlayingManager.js?2.1.0
18:33:59 T:6115012608 DEBUG: webserver: request received for /js/xbmc.init.js?2.1.0
18:33:59 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Playlist.GetPlaylists
18:33:59 T:6117306368 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:33:59 T:6117306368 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:33:59 T:6117306368 DEBUG: JSONRPC: Value does not lay between minimum and maximum in type playlistid
18:33:59 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:59 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetItem
18:33:59 T:6115012608 DEBUG: GetMovieId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMovie from movie where idFile=849
18:33:59 T:6115012608 DEBUG: GetEpisodeId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idEpisode from episode where idFile=849
18:33:59 T:6115012608 DEBUG: GetMusicVideoId (smb://192.168.1.143/homes/admin/Test Videos/dts_living_world_of_audio_v2_long_core_1080p-thedigitaltheater.mkv), query = select idMVideo from musicvideo where idFile=849
18:33:59 T:6117306368 DEBUG: webserver: request received for /favicon.ico
18:33:59 T:6117306368 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:33:59 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 207.452339 above threshold of 200.000000
18:34:00 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 18.452339 below threshold of 30.000000
18:34:00 T:6117306368 DEBUG: webserver: request received for /jsonrpc?Player.GetActivePlayers
18:34:00 T:6117306368 DEBUG: webserver: request received for /jsonrpc?Playlist.GetItems
18:34:00 T:6115012608 DEBUG: webserver: request received for /jsonrpc?Player.GetProperties
18:34:01 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 211.054179 above threshold of 200.000000
18:34:01 T:6104690688 DEBUG: ActiveAE::SyncStream - average error 22.054179 below threshold of 30.000000
18:34:01 T:6117306368 DEBUG: webserver: request received for /jsonrpc?System.IsLite
18:34:01 T:6117306368 DEBUG: webserver: request received for /vfs%2Fspecial%3A%2F%2Flogs%2Fmrmc.log?153016763604
Any ideas?