2019-05-12 20:10:24.548 T:4090081856 NOTICE: Log level changed to "LOG_LEVEL_DEBUG_FREEMEM" 2019-05-12 20:10:24.548 T:4090081856 NOTICE: Enabled debug logging due to GUI setting. Level 2. 2019-05-12 20:10:24.549 T:4090081856 DEBUG: ------ Window Init () ------ 2019-05-12 20:10:37.196 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc 2019-05-12 20:10:37.196 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear 2019-05-12 20:10:37.197 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc 2019-05-12 20:10:37.197 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerCoreFactory::GetPlayers() 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: mms/udp 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp 2019-05-12 20:10:37.220 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (VideoPlayer) 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1 2019-05-12 20:10:37.221 T:4090081856 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players 2019-05-12 20:10:37.225 T:4090081856 DEBUG: Radio UECP (RDS) Processor - new CDVDRadioRDSData 2019-05-12 20:10:37.225 T:4090081856 NOTICE: VideoPlayer::OpenFile: 2019-05-12 20:10:37.225 T:4090081856 DEBUG: OnPlayBackStarted: CApplication::OnPlayBackStarted 2019-05-12 20:10:37.225 T:3607077760 DEBUG: Thread VideoPlayer start, auto delete: false 2019-05-12 20:10:37.226 T:3607077760 NOTICE: Creating InputStream 2019-05-12 20:10:37.226 T:3649041280 DEBUG: Thread JobWorker start, auto delete: true 2019-05-12 20:10:37.238 T:3649041280 DEBUG: Loading settings for 2019-05-12 20:10:37.256 T:4090081856 DEBUG: CVideoGUIInfo::InitCurrentItem() 2019-05-12 20:10:37.295 T:4090081856 DEBUG: CPlayerGUIInfo::InitCurrentItem() 2019-05-12 20:10:37.296 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnChanged from xbmc 2019-05-12 20:10:37.296 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1024, from xbmc, message OnChanged 2019-05-12 20:10:37.296 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc 2019-05-12 20:10:37.296 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay 2019-05-12 20:10:37.350 T:3607077760 DEBUG: CSMBFile::Open - opened , fd=10000 2019-05-12 20:10:37.363 T:3607077760 DEBUG: ScanForExternalSubtitles: Searching for subtitles... 2019-05-12 20:10:37.378 T:3607077760 DEBUG: ScanForExternalSubtitles: END (total time: 15 ms) 2019-05-12 20:10:37.378 T:3607077760 NOTICE: Creating Demuxer 2019-05-12 20:10:37.396 T:4090081856 DEBUG: ------ Window Init (DialogBusy.xml) ------ 2019-05-12 20:10:37.429 T:3607077760 DEBUG: Open - probing detected format [avi] 2019-05-12 20:10:38.767 T:3607077760 DEBUG: Open - avformat_find_stream_info starting 2019-05-12 20:10:38.770 T:3607077760 DEBUG: Open - av_find_stream_info finished 2019-05-12 20:10:38.771 T:3607077760 INFO: ffmpeg[D6FFA380]: Input #0, avi, from '': 2019-05-12 20:10:38.771 T:3607077760 INFO: ffmpeg[D6FFA380]: Metadata: 2019-05-12 20:10:38.771 T:3607077760 INFO: ffmpeg[D6FFA380]: encoder : VirtualDubMod 1.5.10.2 (build 2540/release) 2019-05-12 20:10:38.771 T:3607077760 INFO: ffmpeg[D6FFA380]: Duration: 00:51:56.20, start: 0.000000, bitrate: 1893 kb/s 2019-05-12 20:10:38.771 T:3607077760 INFO: ffmpeg[D6FFA380]: Stream #0:0: Video: mpeg4 (Advanced Simple Profile) (XVID / 0x44495658), yuv420p, 720x400 [SAR 1:1 DAR 9:5], 1303 kb/s, 25 fps, 25 tbr, 25 tbn, 25 tbc 2019-05-12 20:10:38.771 T:3607077760 INFO: ffmpeg[D6FFA380]: Stream #0:1: Audio: ac3 ([0] [0][0] / 0x2000), 48000 Hz, stereo, fltp, 384 kb/s 2019-05-12 20:10:38.772 T:3607077760 INFO: ffmpeg[D6FFA380]: Stream #0:2: Audio: ac3 ([0] [0][0] / 0x2000), 48000 Hz, stereo, fltp, 192 kb/s 2019-05-12 20:10:38.772 T:3607077760 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 0 2019-05-12 20:10:38.772 T:3607077760 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 1 2019-05-12 20:10:38.772 T:3607077760 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 2 2019-05-12 20:10:38.772 T:3607077760 NOTICE: Opening stream: 0 source: 256 2019-05-12 20:10:38.772 T:3607077760 NOTICE: Creating video codec with codec id: 12 2019-05-12 20:10:38.772 T:3607077760 DEBUG: CDVDVideoCodecDRMPRIME::Open - unable to find decoder for codec 12 2019-05-12 20:10:38.772 T:3607077760 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: MPEG-4 part 2 2019-05-12 20:10:38.773 T:3607077760 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-mpeg4 2019-05-12 20:10:38.773 T:3607077760 DEBUG: CVideoPlayerVideo::OpenStream - open stream with codec id: 12 2019-05-12 20:10:38.773 T:3607077760 NOTICE: Creating video thread 2019-05-12 20:10:38.773 T:3664954240 DEBUG: Thread VideoPlayerVideo start, auto delete: false 2019-05-12 20:10:38.774 T:3607077760 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: 2019-05-12 20:10:38.774 T:3664954240 NOTICE: running thread: video_thread 2019-05-12 20:10:38.774 T:3664954240 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_PAUSE: 0 2019-05-12 20:10:38.774 T:3607077760 NOTICE: Opening stream: 1 source: 256 2019-05-12 20:10:38.775 T:3607077760 NOTICE: Finding audio codec for: 86019 2019-05-12 20:10:38.775 T:3607077760 NOTICE: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder ac3 2019-05-12 20:10:38.775 T:3607077760 NOTICE: Creating audio thread 2019-05-12 20:10:38.776 T:3749364608 DEBUG: Thread VideoPlayerAudio start, auto delete: false 2019-05-12 20:10:38.776 T:3749364608 NOTICE: running thread: CVideoPlayerAudio::Process() 2019-05-12 20:10:38.776 T:3749364608 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_PAUSE: 0 2019-05-12 20:10:38.776 T:3607077760 DEBUG: CVideoPlayer::SetCaching - caching state 2 2019-05-12 20:10:38.776 T:3607077760 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 2019-05-12 20:10:38.776 T:3607077760 DEBUG: CVideoPlayer::HandleMessages - player 2 reported state: 0 2019-05-12 20:10:38.776 T:3607077760 DEBUG: CVideoPlayer::HandleMessages - player 1 reported state: 0 2019-05-12 20:10:38.776 T:3649041280 DEBUG: OnAVChange: CApplication::OnAVChange 2019-05-12 20:10:38.776 T:3607077760 DEBUG: CVideoPlayer::SetCaching - caching state 1 2019-05-12 20:10:38.776 T:3607077760 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 2019-05-12 20:10:38.777 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnAVChange from xbmc 2019-05-12 20:10:38.777 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnAVChange 2019-05-12 20:10:38.777 T:3664954240 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback 2019-05-12 20:10:38.786 T:3749364608 DEBUG: CDVDAudio::Pause - pausing audio stream 2019-05-12 20:10:38.787 T:3749364608 DEBUG: Previous line repeats 1 times. 2019-05-12 20:10:38.787 T:3749364608 NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, no pass-through) 2019-05-12 20:10:38.787 T:3749364608 DEBUG: CVideoPlayerAudio:: synctype set to 0: clock feedback 2019-05-12 20:10:38.788 T:4060078976 INFO: CActiveAESink::OpenSink - initialize sink 2019-05-12 20:10:38.788 T:4060078976 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:@:CARD=I2S,DEV=0 2019-05-12 20:10:38.789 T:3664954240 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: MPEG-4 part 2 2019-05-12 20:10:38.789 T:4060078976 INFO: CAESinkALSA::Initialize - Attempting to open device "@:CARD=I2S,DEV=0" 2019-05-12 20:10:38.789 T:3664954240 DEBUG: CDVDVideoCodecFFmpeg - open frame threaded with 6 threads 2019-05-12 20:10:38.790 T:3664954240 DEBUG: CDVDVideoCodecFFmpeg - Updated codec: ff-mpeg4 2019-05-12 20:10:38.809 T:3664954240 DEBUG: CRenderManager::Configure - change configuration. 720x400. display: 720x400. framerate: 25.00. 2019-05-12 20:10:38.842 T:4090081856 DEBUG: DeleteRenderer - deleting renderer 2019-05-12 20:10:38.842 T:4090081856 DEBUG: LinuxRendererGLES: Cleaning up GLES resources 2019-05-12 20:10:38.842 T:4090081856 NOTICE: GLES: Selecting single pass rendering 2019-05-12 20:10:38.842 T:4090081856 DEBUG: GLES: Requested render method: 0 2019-05-12 20:10:38.842 T:4090081856 NOTICE: GLES: Selecting YUV 2 RGB shader 2019-05-12 20:10:38.843 T:4090081856 DEBUG: GLES: BaseYUV2RGBGLSLShader: defines: #define XBMC_YV12 #define XBMC_COL_CONVERSION 2019-05-12 20:10:38.870 T:4090081856 DEBUG: Previous line repeats 1 times. 2019-05-12 20:10:38.870 T:4090081856 DEBUG: CRenderManager::Configure - 6 2019-05-12 20:10:38.870 T:3607077760 DEBUG: CVideoPlayer::HandleMessages - player started 2 2019-05-12 20:10:38.871 T:3649041280 DEBUG: OnAVChange: CApplication::OnAVChange 2019-05-12 20:10:38.871 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnAVChange from xbmc 2019-05-12 20:10:38.871 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnAVChange 2019-05-12 20:10:39.018 T:4060078976 INFO: CAESinkALSA::Initialize - Opened device "sysdefault:CARD=I2S" 2019-05-12 20:10:39.019 T:4060078976 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2019-05-12 20:10:39.019 T:4060078976 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE4 2019-05-12 20:10:39.019 T:4060078976 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2400, bufferSize 9600 2019-05-12 20:10:39.019 T:4060078976 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2400, bufferSize 9600 2019-05-12 20:10:39.020 T:4060078976 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 200 ms 2019-05-12 20:10:39.020 T:4060078976 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2 2019-05-12 20:10:39.020 T:4060078976 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL, FR 2019-05-12 20:10:39.020 T:4060078976 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL, FR (ALSA: none) 2019-05-12 20:10:39.020 T:4060078976 DEBUG: CActiveAESink::OpenSink - ALSA Initialized: 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Output Device : I2S 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Sample Rate : 48000 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Sample Format : AE_FMT_S24NE4 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Channel Count : 2 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Channel Layout: FL, FR 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Frames : 2400 2019-05-12 20:10:39.020 T:4060078976 DEBUG: Frame Size : 8 2019-05-12 20:10:39.023 T:4068471680 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted 2019-05-12 20:10:39.027 T:3607077760 DEBUG: CVideoPlayer::HandleMessages - player started 1 2019-05-12 20:10:39.027 T:3649041280 DEBUG: OnAVChange: CApplication::OnAVChange 2019-05-12 20:10:39.027 T:3607077760 DEBUG: VideoPlayer::Sync - Audio - pts: 288000.000000, cache: 516638.261119, totalcache: 800000.011921 2019-05-12 20:10:39.027 T:3607077760 DEBUG: VideoPlayer::Sync - Video - pts: 40000.000000, cache: 50000.000000, totalcache: 100000.000000 2019-05-12 20:10:39.027 T:3607077760 DEBUG: CVideoPlayer::SetCaching - caching state 0 2019-05-12 20:10:39.028 T:3749364608 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(-228638.261119), level: 80, cache: 515095.052119 2019-05-12 20:10:39.028 T:3664954240 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(-228638.261119) 2019-05-12 20:10:39.028 T:3607077760 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 2019-05-12 20:10:39.028 T:3749364608 DEBUG: CDVDAudio::Resume - resume audio stream 2019-05-12 20:10:39.028 T:4068471680 DEBUG: ActiveAE - start sync of audio stream 2019-05-12 20:10:39.029 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnAVChange from xbmc 2019-05-12 20:10:39.029 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnAVChange 2019-05-12 20:10:39.031 T:3649041280 DEBUG: OnAVStarted: CApplication::OnAVStarted 2019-05-12 20:10:39.032 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnAVStart from xbmc 2019-05-12 20:10:39.032 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnAVStart 2019-05-12 20:10:39.074 T:4090081856 DEBUG: Activating window ID: 12005 2019-05-12 20:10:39.074 T:4090081856 DEBUG: ------ Window Deinit (SettingsCategory.xml) ------ 2019-05-12 20:10:39.074 T:4090081856 DEBUG: FreeVisualisation() done 2019-05-12 20:10:39.075 T:4090081856 DEBUG: ------ Window Init (VideoFullScreen.xml) ------ 2019-05-12 20:10:39.080 T:3649041280 DEBUG: OnAVChange: CApplication::OnAVChange 2019-05-12 20:10:39.080 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnAVChange from xbmc 2019-05-12 20:10:39.080 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnAVChange 2019-05-12 20:10:39.139 T:4090081856 DEBUG: ------ Window Deinit (DialogBusy.xml) ------ 2019-05-12 20:10:39.173 T:4068471680 DEBUG: ActiveAE::SyncStream - average error of 16.908025, start adjusting 2019-05-12 20:10:39.173 T:4068471680 DEBUG: ActiveAE::SyncStream - average error 0.908025 below threshold of 30.000000 2019-05-12 20:10:39.492 T:3664954240 NOTICE: CDVDVideoCodecFFmpeg::CDropControl: calculated diff time: 40000 2019-05-12 20:10:40.224 T:3749364608 DEBUG: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-33362.743167, adjusted:-33362.743167 2019-05-12 20:10:43.912 T:3664954240 DEBUG: CPtsTracker: detected pattern of length 1: 40000.00, frameduration: 40000.000000 2019-05-12 20:11:02.656 T:4090081856 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate 2019-05-12 20:11:02.656 T:4090081856 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------ 2019-05-12 20:11:02.669 T:4090081856 DEBUG: CGUIWindowManager::PreviousWindow: Activate new 2019-05-12 20:11:02.669 T:4090081856 DEBUG: ------ Window Init (SettingsCategory.xml) ------ 2019-05-12 20:11:02.676 T:4090081856 NOTICE: CVideoPlayer::CloseFile() 2019-05-12 20:11:02.676 T:4090081856 DEBUG: DeleteRenderer - deleting renderer 2019-05-12 20:11:02.676 T:4090081856 DEBUG: LinuxRendererGLES: Cleaning up GLES resources 2019-05-12 20:11:02.678 T:4090081856 NOTICE: VideoPlayer: waiting for threads to exit 2019-05-12 20:11:02.680 T:3607077760 NOTICE: CVideoPlayer::OnExit() 2019-05-12 20:11:02.680 T:3607077760 DEBUG: CVideoPlayer: updating file item stream details with current streams 2019-05-12 20:11:02.680 T:3607077760 NOTICE: Closing stream player 1 2019-05-12 20:11:02.680 T:3607077760 NOTICE: Waiting for audio thread to exit 2019-05-12 20:11:02.723 T:3749364608 NOTICE: thread end: CVideoPlayerAudio::OnExit() 2019-05-12 20:11:02.723 T:3749364608 DEBUG: Thread VideoPlayerAudio 3749364608 terminating 2019-05-12 20:11:02.723 T:3607077760 NOTICE: Closing audio device 2019-05-12 20:11:02.773 T:3607077760 DEBUG: CDVDAudio::Flush - flush audio stream 2019-05-12 20:11:02.773 T:4068471680 DEBUG: CActiveAE::DiscardStream - audio stream deleted 2019-05-12 20:11:02.773 T:4068471680 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted 2019-05-12 20:11:02.775 T:3607077760 DEBUG: Previous line repeats 2 times. 2019-05-12 20:11:02.775 T:3607077760 NOTICE: Deleting audio codec 2019-05-12 20:11:02.775 T:4060078976 INFO: CActiveAESink::OpenSink - initialize sink 2019-05-12 20:11:02.775 T:3607077760 NOTICE: Closing stream player 2 2019-05-12 20:11:02.775 T:3607077760 NOTICE: waiting for video thread to exit 2019-05-12 20:11:02.810 T:3664954240 NOTICE: thread end: video_thread 2019-05-12 20:11:02.810 T:3664954240 DEBUG: Thread VideoPlayerVideo 3664954240 terminating 2019-05-12 20:11:02.810 T:3607077760 NOTICE: deleting video codec 2019-05-12 20:11:02.817 T:3607077760 DEBUG: CSMBFile::Close closing fd 10000 2019-05-12 20:11:02.821 T:3607077760 DEBUG: Thread VideoPlayer 3607077760 terminating 2019-05-12 20:11:02.821 T:4090081856 NOTICE: VideoPlayer: finished waiting 2019-05-12 20:11:02.821 T:4090081856 NOTICE: CVideoPlayer::CloseFile() 2019-05-12 20:11:02.821 T:4090081856 NOTICE: VideoPlayer: waiting for threads to exit 2019-05-12 20:11:02.821 T:4090081856 NOTICE: VideoPlayer: finished waiting 2019-05-12 20:11:02.824 T:4090081856 DEBUG: Radio UECP (RDS) Processor - delete ~CDVDRadioRDSData 2019-05-12 20:11:02.828 T:3649041280 INFO: Deleting settings information for files 2019-05-12 20:11:02.831 T:3607077760 DEBUG: Thread JobWorker start, auto delete: true 2019-05-12 20:11:02.831 T:3649041280 DEBUG: DoWork - Saving file state for video item 2019-05-12 20:11:02.849 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnUpdate from xbmc 2019-05-12 20:11:02.849 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnUpdate 2019-05-12 20:11:02.852 T:3607077760 DEBUG: OnPlayBackStopped: CApplication::OnPlayBackStopped 2019-05-12 20:11:02.852 T:4090069888 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc 2019-05-12 20:11:02.852 T:4090069888 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop 2019-05-12 20:11:02.987 T:4060078976 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:@:CARD=I2S,DEV=0 2019-05-12 20:11:02.987 T:4060078976 INFO: CAESinkALSA::Initialize - Attempting to open device "@:CARD=I2S,DEV=0" 2019-05-12 20:11:03.211 T:4060078976 INFO: CAESinkALSA::Initialize - Opened device "sysdefault:CARD=I2S" 2019-05-12 20:11:03.212 T:4060078976 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 2019-05-12 20:11:03.212 T:4060078976 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S24NE4 2019-05-12 20:11:03.213 T:4060078976 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2400, bufferSize 9600 2019-05-12 20:11:03.213 T:4060078976 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2400, bufferSize 9600 2019-05-12 20:11:03.213 T:4060078976 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 200 ms 2019-05-12 20:11:03.213 T:4060078976 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2 2019-05-12 20:11:03.214 T:4060078976 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL, FR 2019-05-12 20:11:03.214 T:4060078976 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL, FR (ALSA: none) 2019-05-12 20:11:03.214 T:4060078976 DEBUG: CActiveAESink::OpenSink - ALSA Initialized: 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Output Device : I2S 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Sample Rate : 48000 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Sample Format : AE_FMT_S24NE4 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Channel Count : 2 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Channel Layout: FL, FR 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Frames : 2400 2019-05-12 20:11:03.214 T:4060078976 DEBUG: Frame Size : 8 2019-05-12 20:11:03.216 T:4068471680 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted 2019-05-12 20:11:04.256 T:4090081856 NOTICE: Disabled debug logging due to GUI setting. Level 0. 2019-05-12 20:11:04.256 T:4090081856 NOTICE: Log level changed to "LOG_LEVEL_NORMAL"