19:42:02.440 T:4146888640 NOTICE: VideoPlayer: Opening: smb://test.mkv 19:42:02.440 T:4146888640 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED 19:42:02.442 T:3661632416 NOTICE: Creating InputStream 19:42:02.597 T:3661632416 NOTICE: Creating Demuxer 19:42:02.668 T:3661632416 NOTICE: Opening stream: 0 source: 256 19:42:02.668 T:3661632416 NOTICE: Creating video codec with codec id: 28 19:42:02.672 T:3661632416 NOTICE: Creating video thread 19:42:02.673 T:3500684192 NOTICE: running thread: video_thread 19:42:02.673 T:3661632416 NOTICE: Opening stream: 1 source: 256 19:42:02.673 T:3661632416 NOTICE: Finding audio codec for: 86018 19:42:02.675 T:3661632416 NOTICE: Creating audio thread 19:42:02.675 T:3492295584 NOTICE: running thread: CVideoPlayerAudio::Process() 19:42:02.685 T:3492295584 NOTICE: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through) 19:42:02.695 T:3500684192 NOTICE: CAMLCodec::OpenDecoder - using V4L2 pts format: 64Bit 19:42:02.738 T:4146888640 NOTICE: Display resolution ADJUST : 1920x1080 @ 50.00 - Full Screen (22) (weight: 0.000) 20:00:41.249 T:3492295584 NOTICE: CVideoPlayerAudio::Process - stream stalled 20:00:41.415 T:3492295584 NOTICE: CActiveAEStream::AddData - messy timestamps, increasing interval for measuring average error to 6000 ms 20:00:57.582 T:4146888640 NOTICE: CVideoPlayer::CloseFile() 20:00:57.582 T:4146888640 NOTICE: VideoPlayer: waiting for threads to exit 20:00:57.583 T:3661632416 NOTICE: CVideoPlayer::OnExit() 20:00:57.583 T:3661632416 NOTICE: Closing stream player 1 20:00:57.583 T:3661632416 NOTICE: Waiting for audio thread to exit 20:00:57.666 T:3492295584 NOTICE: thread end: CVideoPlayerAudio::OnExit() 20:00:57.667 T:3661632416 NOTICE: Closing audio device 20:00:57.754 T:3661632416 NOTICE: Deleting audio codec 20:00:57.754 T:3661632416 NOTICE: Closing stream player 2 20:00:57.754 T:3661632416 NOTICE: waiting for video thread to exit 20:00:57.768 T:3500684192 NOTICE: thread end: video_thread 20:00:57.769 T:3661632416 NOTICE: deleting video codec 20:00:57.879 T:4146888640 NOTICE: VideoPlayer: finished waiting 20:00:58.455 T:4146888640 NOTICE: CVideoPlayer::CloseFile() 20:00:58.456 T:4146888640 NOTICE: VideoPlayer: waiting for threads to exit 20:00:58.456 T:4146888640 NOTICE: VideoPlayer: finished waiting 20:00:58.456 T:4146888640 NOTICE: CVideoPlayer::CloseFile() 20:00:58.456 T:4146888640 NOTICE: VideoPlayer: waiting for threads to exit 20:00:58.456 T:4146888640 NOTICE: VideoPlayer: finished waiting 20:01:30.713 T:4146888640 NOTICE: Log level changed to "LOG_LEVEL_DEBUG_FREEMEM" 20:01:30.713 T:4146888640 NOTICE: Enabled debug logging due to GUI setting. Level 2. 20:01:30.714 T:4146888640 DEBUG: ------ Window Init () ------ 20:01:31.033 T:3972010912 DEBUG: PushCecKeypress - received key b duration 341 20:01:32.903 T:3972010912 DEBUG: PushCecKeypress - received key d8 duration 0 20:01:32.912 T:4146888640 DEBUG: OnKey: menu (0xd8) pressed, action is PreviousMenu 20:01:32.931 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate 20:01:33.230 T:4146888640 DEBUG: ------ Window Deinit (SettingsCategory.xml) ------ 20:01:33.231 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Activate new 20:01:33.231 T:4146888640 DEBUG: ------ Window Init (EventLog.xml) ------ 20:01:33.232 T:4146888640 DEBUG: CGUIMediaWindow::GetDirectory (events://) 20:01:33.232 T:4146888640 DEBUG: ParentPath = [] 20:01:33.349 T:3972010912 DEBUG: PushCecKeypress - received key d8 duration 446 20:01:34.120 T:3972010912 DEBUG: PushCecKeypress - received key d8 duration 0 20:01:34.148 T:4146888640 DEBUG: OnKey: menu (0xd8) pressed, action is Back 20:01:34.149 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate 20:01:34.470 T:4146888640 DEBUG: ------ Window Deinit (EventLog.xml) ------ 20:01:34.472 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Activate new 20:01:34.472 T:4146888640 DEBUG: ------ Window Init (Settings.xml) ------ 20:01:34.567 T:3972010912 DEBUG: PushCecKeypress - received key d8 duration 447 20:01:35.696 T:3972010912 DEBUG: PushCecKeypress - received key d8 duration 0 20:01:35.732 T:4146888640 DEBUG: OnKey: menu (0xd8) pressed, action is PreviousMenu 20:01:35.732 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate 20:01:36.033 T:4146888640 DEBUG: ------ Window Deinit (Settings.xml) ------ 20:01:36.033 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Activate new 20:01:36.033 T:4146888640 DEBUG: ------ Window Init (Home.xml) ------ 20:01:36.042 T:3546993568 DEBUG: CRecentlyAddedJob::UpdateMusic() - Running RecentlyAdded home screen update 20:01:36.080 T:3546993568 DEBUG: GetRecentlyAddedAlbumSongs() query: SELECT songview.*, songartistview.* FROM (SELECT idAlbum FROM album ORDER BY idAlbum DESC LIMIT 10) AS recentalbums JOIN songview ON songview.idAlbum = recentalbums.idAlbum JOIN songartistview ON songview.idSong = songartistview.idSong ORDER BY songview.idAlbum DESC, songview.idSong, songartistview.idRole, songartistview.iOrder 20:01:36.142 T:3972010912 DEBUG: PushCecKeypress - received key d8 duration 445 20:01:36.206 T:3546993568 DEBUG: GetRecentlyAddedAlbums query: SELECT albumview.*, albumartistview.* FROM (SELECT idAlbum FROM album WHERE strAlbum != '' ORDER BY idAlbum DESC LIMIT 10) AS recentalbums JOIN albumview ON albumview.idAlbum = recentalbums.idAlbum JOIN albumartistview ON albumview.idAlbum = albumartistview.idAlbum ORDER BY albumview.idAlbum desc, albumartistview.iOrder 20:01:36.250 T:3546993568 DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update 20:01:36.296 T:3546993568 DEBUG: RunQuery took 7 ms for 10 items query: select * from movie_view ORDER BY dateAdded desc, idMovie desc LIMIT 10 20:01:36.403 T:3546993568 DEBUG: RunQuery took 29 ms for 10 items query: select * from episode_view ORDER BY dateAdded desc, idEpisode desc LIMIT 10 20:01:36.518 T:3546993568 DEBUG: RunQuery took 3 ms for 0 items query: select * from musicvideo_view ORDER BY dateAdded desc, idMVideo desc LIMIT 10 20:01:36.519 T:3546993568 DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update 20:01:36.532 T:3546993568 DEBUG: GetArtistsByWhere query: SELECT COUNT(DISTINCT artistview.idArtist) FROM artistview WHERE ((EXISTS (SELECT 1 FROM song_artist WHERE song_artist.idArtist = artistview.idArtist AND song_artist.idRole = 1) OR EXISTS (SELECT 1 FROM album_artist WHERE album_artist.idArtist = artistview.idArtist)) AND (artistview.strArtist != '')) AND (artistview.strArtist <> 'Verschiedene Interpreten') 20:01:38.220 T:3972010912 DEBUG: PushCecKeypress - received key a7 duration 0 20:01:38.233 T:4146888640 DEBUG: OnKey: 167 (0xa7, obc88) pressed, action is Down 20:01:38.562 T:3972010912 DEBUG: PushCecKeypress - received key a7 duration 341 20:01:38.736 T:3972010912 DEBUG: PushCecKeypress - received key a7 duration 0 20:01:38.764 T:4146888640 DEBUG: OnKey: 167 (0xa7, obc88) pressed, action is Down 20:01:39.073 T:3972010912 DEBUG: PushCecKeypress - received key a7 duration 338 20:01:39.821 T:3972010912 DEBUG: PushCecKeypress - received key a8 duration 0 20:01:39.828 T:4146888640 DEBUG: OnKey: 168 (0xa8, obc87) pressed, action is Right 20:01:39.903 T:3500684192 DEBUG: ffmpeg[D0A833A0]: [swscaler] No accelerated colorspace conversion found from yuv420p to bgra. 20:01:40.166 T:3972010912 DEBUG: PushCecKeypress - received key a8 duration 346 20:01:41.128 T:3972010912 DEBUG: PushCecKeypress - received key b duration 0 20:01:41.135 T:4146888640 DEBUG: OnKey: 11 (0x0b, obc244) pressed, action is Select 20:01:41.135 T:4146888640 DEBUG: Activating window ID: 10025 20:01:41.437 T:4146888640 DEBUG: ------ Window Deinit (Home.xml) ------ 20:01:41.452 T:4146888640 DEBUG: ------ Window Init (MyVideoNav.xml) ------ 20:01:41.454 T:4146888640 DEBUG: CGUIMediaWindow::GetDirectory (videodb://inprogresstvshows/32/) 20:01:41.454 T:4146888640 DEBUG: ParentPath = [videodb://inprogresstvshows/32/] 20:01:41.470 T:3972010912 DEBUG: PushCecKeypress - received key b duration 341 20:01:41.504 T:4146888640 DEBUG: RunQuery took 34 ms for 2 items query: SELECT * FROM season_view WHERE season_view.idShow = 32 20:01:41.508 T:4146888640 DEBUG: RunQuery took 2 ms for 0 items query: select * from movie_view join movielinktvshow on movielinktvshow.idMovie=movie_view.idMovie WHERE movielinktvshow.idShow = 32 20:01:41.530 T:4146888640 DEBUG: WindowVideoNav::GetDirectory 20:01:41.582 T:3594679200 DEBUG: Thread BackgroundLoader start, auto delete: false 20:01:41.619 T:3594679200 DEBUG: Thread BackgroundLoader 3594679200 terminating 20:01:41.685 T:3546993568 DEBUG: ffmpeg[D36AD3A0]: [swscaler] No accelerated colorspace conversion found from yuv420p to bgra. 20:01:41.722 T:3661632416 DEBUG: ffmpeg[DA4013A0]: [swscaler] No accelerated colorspace conversion found from yuv420p to bgra. 20:01:43.193 T:3972010912 DEBUG: PushCecKeypress - received key b duration 0 20:01:43.229 T:4146888640 DEBUG: OnKey: 11 (0x0b, obc244) pressed, action is Select 20:01:43.241 T:4146888640 DEBUG: CGUIMediaWindow::GetDirectory (videodb://inprogresstvshows/32/4/?tvshowid=32) 20:01:43.242 T:4146888640 DEBUG: ParentPath = [videodb://inprogresstvshows/32/] 20:01:43.279 T:3500684192 DEBUG: RunQuery took 5 ms for 7 items query: select * from episode_view WHERE (episode_view.idShow = 32) AND ((episode_view.c12 = 4 or (episode_view.c12 = 0 and (episode_view.c15 = 0 or episode_view.c15 = 4)))) 20:01:43.303 T:4146888640 DEBUG: WindowVideoNav::GetDirectory 20:01:43.336 T:3594679200 DEBUG: Thread BackgroundLoader start, auto delete: false 20:01:43.429 T:3594679200 DEBUG: Thread BackgroundLoader 3594679200 terminating 20:01:43.529 T:3972010912 DEBUG: PushCecKeypress - received key b duration 337 20:01:44.885 T:3972010912 DEBUG: PushCecKeypress - received key b duration 0 20:01:44.893 T:4146888640 DEBUG: OnKey: 11 (0x0b, obc244) pressed, action is Select 20:01:44.895 T:4146888640 DEBUG: ------ Window Init (DialogContextMenu.xml) ------ 20:01:45.225 T:3972010912 DEBUG: PushCecKeypress - received key b duration 341 20:01:46.075 T:3972010912 DEBUG: PushCecKeypress - received key b duration 0 20:01:46.112 T:4146888640 DEBUG: OnKey: 11 (0x0b, obc244) pressed, action is Select 20:01:46.356 T:4146888640 DEBUG: ------ Window Deinit (DialogContextMenu.xml) ------ 20:01:46.358 T:4146888640 DEBUG: OnPlayMedia smb://test.mkv 20:01:46.361 T:4115710880 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc 20:01:46.361 T:4115710880 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear 20:01:46.361 T:4115710880 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc 20:01:46.361 T:4115710880 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd 20:01:46.379 T:4146888640 DEBUG: Loading settings for smb://test.mkv 20:01:46.411 T:4146888640 DEBUG: CPlayerCoreFactory::GetPlayers(smb://test.mkv) 20:01:46.411 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules 20:01:46.411 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules 20:01:46.411 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: mms/udp 20:01:46.412 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout 20:01:46.412 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp 20:01:46.412 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp 20:01:46.412 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams 20:01:46.412 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd 20:01:46.412 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage 20:01:46.413 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf 20:01:46.413 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv 20:01:46.413 T:4146888640 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio 20:01:46.413 T:4146888640 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players 20:01:46.413 T:4146888640 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (VideoPlayer) 20:01:46.413 T:4146888640 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0 20:01:46.413 T:4146888640 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1 20:01:46.413 T:4146888640 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players 20:01:46.414 T:3972010912 DEBUG: PushCecKeypress - received key b duration 338 20:01:46.423 T:4146888640 DEBUG: Radio UECP (RDS) Processor - new CDVDRadioRDSData 20:01:46.423 T:4146888640 NOTICE: VideoPlayer: Opening: smb://test.mkv 20:01:46.423 T:4146888640 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED 20:01:46.423 T:4146888640 DEBUG: LinuxRendererGL: Cleaning up GL resources 20:01:46.423 T:3594679200 DEBUG: Thread VideoPlayer start, auto delete: false 20:01:46.424 T:3594679200 NOTICE: Creating InputStream 20:01:46.444 T:3594679200 DEBUG: CFileCache::Open - opening using cache 20:01:46.446 T:3594679200 DEBUG: CSMBFile::Open - opened smb://test.mkv, fd=10000 20:01:46.448 T:3492295584 DEBUG: Thread FileCache start, auto delete: false 20:01:46.449 T:3594679200 DEBUG: ScanForExternalSubtitles: Searching for subtitles... 20:01:46.503 T:3594679200 DEBUG: ScanForExternalSubtitles: END (total time: 55 ms) 20:01:46.504 T:3594679200 NOTICE: Creating Demuxer 20:01:46.506 T:3594679200 DEBUG: Open - probing detected format [matroska,webm] 20:01:46.518 T:3594679200 DEBUG: Seek - waiting for position 348818633. 20:01:46.534 T:3492295584 INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?) 20:01:46.535 T:3594679200 DEBUG: Open - avformat_find_stream_info starting 20:01:46.549 T:3594679200 DEBUG: Open - av_find_stream_info finished 20:01:46.550 T:3594679200 INFO: ffmpeg[D64273A0]: Input #0, matroska,webm, smb://test.mk': 20:01:46.550 T:3594679200 INFO: ffmpeg[D64273A0]: Metadata: 20:01:46.550 T:3594679200 INFO: ffmpeg[D64273A0]: encoder : libebml v1.3.3 + libmatroska v1.4.4 20:01:46.550 T:3594679200 INFO: ffmpeg[D64273A0]: creation_time : 2016-08-28 08:20:48 20:01:46.550 T:3594679200 INFO: ffmpeg[D64273A0]: Duration: 00:44:08.32, start: 0.000000, bitrate: 1053 kb/s 20:01:46.551 T:3594679200 INFO: ffmpeg[D64273A0]: Chapter #0:0: start 0.054000, end 2648.320000 20:01:46.551 T:3594679200 INFO: ffmpeg[D64273A0]: Metadata: 20:01:46.551 T:3594679200 INFO: ffmpeg[D64273A0]: title : 00:00:00.054 20:01:46.551 T:3594679200 INFO: ffmpeg[D64273A0]: Stream #0:0(eng): Video: h264 (High), yuv420p, 718x402 [SAR 1:1 DAR 359:201], 25 fps, 25 tbr, 1k tbn, 50 tbc (default) 20:01:46.551 T:3594679200 INFO: ffmpeg[D64273A0]: Metadata: 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: BPS : 935301 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: BPS-eng : 935301 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: DURATION : 00:44:08.320000000 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: DURATION-eng : 00:44:08.320000000 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_FRAMES: 66208 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_FRAMES-eng: 66208 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_BYTES : 309622127 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_BYTES-eng: 309622127 20:01:46.552 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_APP: mkvmerge v9.0.0 ('Power to progress') 64bit 20:01:46.553 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_APP-eng: mkvmerge v9.0.0 ('Power to progress') 64bit 20:01:46.553 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_DATE_UTC: 2016-08-28 08:20:48 20:01:46.553 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_DATE_UTC-eng: 2016-08-28 08:20:48 20:01:46.553 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES 20:01:46.553 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES 20:01:46.553 T:3594679200 INFO: ffmpeg[D64273A0]: Stream #0:1(ger): Audio: aac (LC), 48000 Hz, stereo, fltp (default) 20:01:46.554 T:3594679200 INFO: ffmpeg[D64273A0]: Metadata: 20:01:46.554 T:3594679200 INFO: ffmpeg[D64273A0]: BPS : 116083 20:01:46.554 T:3594679200 INFO: ffmpeg[D64273A0]: BPS-eng : 116083 20:01:46.554 T:3594679200 INFO: ffmpeg[D64273A0]: DURATION : 00:44:08.299000000 20:01:46.554 T:3594679200 INFO: ffmpeg[D64273A0]: DURATION-eng : 00:44:08.299000000 20:01:46.554 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_FRAMES: 124139 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_FRAMES-eng: 124139 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_BYTES : 38427904 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: NUMBER_OF_BYTES-eng: 38427904 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_APP: mkvmerge v9.0.0 ('Power to progress') 64bit 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_APP-eng: mkvmerge v9.0.0 ('Power to progress') 64bit 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_DATE_UTC: 2016-08-28 08:20:48 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_WRITING_DATE_UTC-eng: 2016-08-28 08:20:48 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES 20:01:46.555 T:3594679200 INFO: ffmpeg[D64273A0]: _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES 20:01:46.556 T:3594679200 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 0 20:01:46.556 T:3594679200 DEBUG: CDVDDemuxFFmpeg::AddStream ID: 1 20:01:46.556 T:3594679200 DEBUG: CDVDInputStreamFile::SetReadRate - set cache throttle rate to 144884 bytes per second 20:01:46.556 T:3594679200 NOTICE: Opening stream: 0 source: 256 20:01:46.557 T:3594679200 NOTICE: Creating video codec with codec id: 28 20:01:46.557 T:3594679200 DEBUG: FactoryCodec - Video: amcodec - Opening 20:01:46.557 T:3594679200 INFO: CBitstreamConverter::Open bitstream to annexb init 20:01:46.557 T:3594679200 DEBUG: SECTION:LoadDLL(libamplayer.so) 20:01:46.561 T:3594679200 DEBUG: Loading: libamplayer.so 20:01:46.565 T:3594679200 INFO: DVDVideoCodecAmlogic: Opened Amlogic Codec 20:01:46.566 T:3594679200 DEBUG: FactoryCodec - Video: am-h264 - Opened 20:01:46.566 T:3594679200 DEBUG: CVideoPlayerVideo::OpenStream - open stream with codec id: 28 20:01:46.566 T:3594679200 NOTICE: Creating video thread 20:01:46.566 T:3594679200 NOTICE: Opening stream: 1 source: 256 20:01:46.566 T:3594679200 NOTICE: Finding audio codec for: 86018 20:01:46.566 T:3633312672 DEBUG: Thread VideoPlayerVideo start, auto delete: false 20:01:46.566 T:3633312672 NOTICE: running thread: video_thread 20:01:46.566 T:3594679200 DEBUG: FactoryCodec - Audio: passthrough - Opening 20:01:46.566 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(1000) 20:01:46.566 T:3594679200 DEBUG: FactoryCodec - Audio: passthrough - Failed 20:01:46.566 T:3594679200 DEBUG: FactoryCodec - Audio: FFmpeg - Opening 20:01:46.569 T:3594679200 DEBUG: FactoryCodec - Audio: FFmpeg - Opened 20:01:46.569 T:3594679200 NOTICE: Creating audio thread 20:01:46.569 T:3509105568 DEBUG: Thread VideoPlayerAudio start, auto delete: false 20:01:46.569 T:3509105568 NOTICE: running thread: CVideoPlayerAudio::Process() 20:01:46.570 T:3594679200 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: smb://test.mkv 20:01:46.571 T:3594679200 DEBUG: Process - Start position set to last stopped position: 1130000 20:01:46.584 T:3492295584 INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?) 20:01:46.585 T:3594679200 DEBUG: Seek - waiting for position 348797594. 20:01:46.603 T:3594679200 DEBUG: SeekTime - seek ended up on time 1128760 20:01:46.603 T:3594679200 DEBUG: Process - starting demuxer from: 1130000 20:01:46.604 T:3594679200 DEBUG: OnPlayBackStarted: play state was 1, starting 1 20:01:46.604 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 1 20:01:46.604 T:4146888640 DEBUG: PlayFile: OpenFile succeed, play state 2 20:01:46.604 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(0) 20:01:46.604 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:46.604 T:4146888640 DEBUG: OnPlayBackStarted: play state was 2, starting 0 20:01:46.610 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:46.623 T:3633312672 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback 20:01:46.624 T:3633312672 DEBUG: codecid_to_vformat, id(28) -> vformat(2) 20:01:46.624 T:3633312672 DEBUG: codec_tag_to_vdec_type, codec_tag(28) -> vdec_type(4) 20:01:46.624 T:3633312672 DEBUG: CAMLCodec::OpenDecoder hints.width(718), hints.height(402), hints.codec(28), hints.codec_tag(0) 20:01:46.624 T:3633312672 DEBUG: CAMLCodec::OpenDecoder hints.fpsrate(25), hints.fpsscale(1), video_rate(3840) 20:01:46.624 T:3633312672 DEBUG: CAMLCodec::OpenDecoder hints.aspect(1.786070), video_ratio.num(1), video_ratio.den(1) 20:01:46.624 T:3633312672 DEBUG: CAMLCodec::OpenDecoder hints.orientation(0), hints.forced_aspect(1), hints.extrasize(41) 20:01:46.633 T:3509105568 NOTICE: Creating audio stream (codec id: 86018, channels: 2, sample rate: 48000, no pass-through) 20:01:46.633 T:3509105568 DEBUG: CVideoPlayerAudio:: synctype set to 0: clock feedback 20:01:46.638 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 2 20:01:46.638 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:46.645 T:3500684192 DEBUG: CGUIInfoManager::SetCurrentMovie(smb://test.mkv) 20:01:46.647 T:4115710880 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc 20:01:46.647 T:4115710880 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay 20:01:46.648 T:4115710880 DEBUG: UPnP: Building didl for object 'smb://test.mkv' 20:01:46.669 T:3633312672 NOTICE: CAMLCodec::OpenDecoder - using V4L2 pts format: 64Bit 20:01:46.670 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(0) 20:01:46.670 T:3633312672 DEBUG: DVDVideoCodecAmlogic: detected new framerate(25.000000), video_rate(3840) 20:01:46.674 T:4084200352 INFO: CActiveAESink::OpenSink - initialize sink 20:01:46.692 T:3633312672 DEBUG: CRenderManager::Configure - change configuration. 718x402. display: 718x402. framerate: 25.00. format: AMLCODEC 20:01:46.706 T:4146888640 DEBUG: DeleteRenderer - deleting renderer 20:01:46.706 T:4146888640 DEBUG: LinuxRendererGL: Cleaning up GL resources 20:01:46.706 T:4146888640 DEBUG: CRenderManager::Configure - 4 20:01:46.707 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 2 20:01:46.717 T:4146888640 INFO: CAMLCodec::SetVideo3dMode: ppmgr_3d support not found in kernel. 20:01:46.717 T:4146888640 DEBUG: CAMLCodec::SetVideoRect:display(0,0,1920,1080) 20:01:46.717 T:4146888640 DEBUG: CAMLCodec::SetVideoRect:gui(0,0,1920,1080) 20:01:46.717 T:4146888640 DEBUG: CAMLCodec::SetVideoRect:m_dst_rect(0,3,1920,1075) 20:01:46.717 T:4146888640 DEBUG: CAMLCodec::SetVideoRect:dst_rect(0,3,1920,1075) 20:01:46.718 T:4146888640 DEBUG: CAMLCodec::SetVideoRect:m_stereo_mode(0) 20:01:46.718 T:4146888640 DEBUG: CAMLCodec::SetVideoRect:m_stereo_view(0) 20:01:46.718 T:4146888640 DEBUG: Activating window ID: 12005 20:01:46.719 T:4146888640 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------ 20:01:46.720 T:4146888640 DEBUG: ------ Window Init (VideoFullScreen.xml) ------ 20:01:46.722 T:4146888640 NOTICE: Display resolution ADJUST : 1920x1080 @ 50.00 - Full Screen (22) (weight: 0.000) 20:01:46.725 T:3500684192 DEBUG: GetMovieId (smb://test.mkv), query = select idMovie from movie where idFile=752 20:01:46.740 T:3500684192 DEBUG: GetEpisodeId (smb://test.mkv), query = select idEpisode from episode where idFile=752 20:01:47.045 T:4084200352 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=AMLM8AUDIO,DEV=0 20:01:47.046 T:4084200352 INFO: CAESinkALSA::Initialize - Attempting to open device "@:CARD=AMLM8AUDIO,DEV=0" 20:01:47.050 T:4084200352 INFO: CAESinkALSA::Initialize - Opened device "sysdefault:CARD=AMLM8AUDIO" 20:01:47.051 T:4084200352 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats 20:01:47.051 T:4084200352 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE 20:01:47.051 T:4084200352 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 4096, bufferSize 16384 20:01:47.052 T:4084200352 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 4096, bufferSize 16384 20:01:47.052 T:4084200352 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 342 ms 20:01:47.052 T:4084200352 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2 20:01:47.052 T:4084200352 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR 20:01:47.052 T:4084200352 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: none) 20:01:47.052 T:4084200352 DEBUG: CActiveAESink::OpenSink - ALSA Initialized: 20:01:47.052 T:4084200352 DEBUG: Output Device : AML-M8AUDIO 20:01:47.052 T:4084200352 DEBUG: Sample Rate : 48000 20:01:47.052 T:4084200352 DEBUG: Sample Format : AE_FMT_S32NE 20:01:47.052 T:4084200352 DEBUG: Channel Count : 2 20:01:47.052 T:4084200352 DEBUG: Channel Layout: FL,FR 20:01:47.052 T:4084200352 DEBUG: Frames : 4096 20:01:47.052 T:4084200352 DEBUG: Frame Size : 8 20:01:47.054 T:4094133152 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted 20:01:47.055 T:3509105568 DEBUG: Previous line repeats 1 times. 20:01:47.055 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:47.064 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 1 20:01:47.065 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 3 20:01:47.065 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:47.065 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 0 20:01:47.065 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:47.065 T:3594679200 DEBUG: VideoPlayer::Sync - Audio - pts: 1128798000.000000, cache: 381294.458543, totalcache: 741333.305836 20:01:47.065 T:3594679200 DEBUG: VideoPlayer::Sync - Video - pts: 1128760000.000000, cache: 50000.000000, totalcache: 100000.000000 20:01:47.066 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(1000) 20:01:47.066 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1128416705.541457) 20:01:47.066 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1128416705.541457) 20:01:47.066 T:3509105568 DEBUG: CDVDAudio::Resume - resume audio stream 20:01:47.074 T:4094133152 DEBUG: ActiveAE - start sync of audio stream 20:01:47.224 T:4094133152 DEBUG: ActiveAE::SyncStream - average error of 2.047028, start adjusting 20:01:47.224 T:4094133152 DEBUG: ActiveAE::SyncStream - average error 0.047028 below threshold of 30.000000 20:01:48.250 T:3509105568 DEBUG: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-56970.021816, adjusted:-56970.021816 20:01:49.789 T:3972010912 DEBUG: PushCecKeypress - received key a9 duration 0 20:01:49.802 T:4146888640 DEBUG: OnKey: 169 (0xa9, obc86) pressed, action is StepBack 20:01:49.804 T:4146888640 DEBUG: ------ Window Init (DialogSeekBar.xml) ------ 20:01:49.808 T:4146888640 DEBUG: ------ Window Init (Custom_1109_TopBarOverlay.xml) ------ 20:01:50.129 T:3972010912 DEBUG: PushCecKeypress - received key a9 duration 341 20:01:50.562 T:4115710880 DEBUG: CAnnouncementManager - Announcement: OnSeek from xbmc 20:01:50.562 T:4115710880 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnSeek 20:01:50.562 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 1 20:01:50.562 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:50.562 T:3594679200 DEBUG: demuxer seek to: 1121856.000000 20:01:50.576 T:3594679200 DEBUG: SeekTime - seek ended up on time 1120080 20:01:50.576 T:3594679200 DEBUG: demuxer seek to: 1121856.000000, success 20:01:50.576 T:3594679200 DEBUG: CVideoPlayer::FlushBuffers - flushing buffers 20:01:50.638 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:50.808 T:3509105568 DEBUG: CDVDAudio::Flush - flush audio stream 20:01:50.808 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:51.101 T:3633312672 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 20:01:51.101 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(0) 20:01:51.101 T:3633312672 DEBUG: CAMLCodec::Reset 20:01:51.148 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE 20:01:51.148 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 2 20:01:51.148 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:51.151 T:3633312672 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback 20:01:51.152 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE 20:01:51.152 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:51.153 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 1 20:01:51.172 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 2 20:01:51.172 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 3 20:01:51.174 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:51.174 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(1000) 20:01:51.177 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 0 20:01:51.177 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:51.177 T:3594679200 DEBUG: VideoPlayer::Sync - Audio - pts: 1120116000.000000, cache: 379945.791543, totalcache: 741333.305836 20:01:51.177 T:3594679200 DEBUG: VideoPlayer::Sync - Video - pts: 1120080000.000000, cache: 50000.000000, totalcache: 100000.000000 20:01:51.177 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1119736054.208457) 20:01:51.177 T:3509105568 DEBUG: CDVDAudio::Resume - resume audio stream 20:01:51.178 T:4094133152 DEBUG: ActiveAE - start sync of audio stream 20:01:51.188 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1119736054.208457) 20:01:51.320 T:4094133152 DEBUG: ActiveAE::SyncStream - average error of 12.174367, start adjusting 20:01:51.320 T:4094133152 DEBUG: ActiveAE::SyncStream - average error 0.174367 below threshold of 30.000000 20:01:52.347 T:3509105568 DEBUG: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-57342.977311, adjusted:-40000.000000 20:01:52.428 T:3972010912 DEBUG: PushCecKeypress - received key a9 duration 0 20:01:52.441 T:4146888640 DEBUG: OnKey: 169 (0xa9, obc86) pressed, action is StepBack 20:01:52.773 T:3972010912 DEBUG: PushCecKeypress - received key a9 duration 345 20:01:53.203 T:4115710880 DEBUG: CAnnouncementManager - Announcement: OnSeek from xbmc 20:01:53.203 T:4115710880 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnSeek 20:01:53.207 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 1 20:01:53.207 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:53.207 T:3594679200 DEBUG: demuxer seek to: 1111726.000000 20:01:53.221 T:3594679200 DEBUG: SeekTime - seek ended up on time 1110040 20:01:53.221 T:3594679200 DEBUG: demuxer seek to: 1111726.000000, success 20:01:53.221 T:3594679200 DEBUG: CVideoPlayer::FlushBuffers - flushing buffers 20:01:53.284 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:53.454 T:3509105568 DEBUG: CDVDAudio::Flush - flush audio stream 20:01:53.454 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:53.761 T:3633312672 WARNING: CRenderManager::WaitForBuffer - timeout waiting for buffer 20:01:54.228 T:3509105568 DEBUG: CDVDMsgGeneralSynchronize - global timeout 20:01:54.228 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE 20:01:54.228 T:3594679200 DEBUG: CDVDMsgGeneralSynchronize - global timeout 20:01:54.229 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 2 20:01:54.229 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:54.238 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:54.240 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 1 20:01:54.767 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(0) 20:01:54.767 T:3633312672 DEBUG: CAMLCodec::Reset 20:01:54.809 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE 20:01:54.810 T:3633312672 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback 20:01:54.843 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 2 20:01:54.843 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 3 20:01:54.843 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:54.844 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(1000) 20:01:54.844 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 0 20:01:54.844 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:54.844 T:3594679200 DEBUG: VideoPlayer::Sync - Audio - pts: 1110089000.000000, cache: 386516.836707, totalcache: 741333.305836 20:01:54.844 T:3594679200 DEBUG: VideoPlayer::Sync - Video - pts: 1110040000.000000, cache: 50000.000000, totalcache: 100000.000000 20:01:54.844 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1109702483.163294) 20:01:54.845 T:3509105568 DEBUG: CDVDAudio::Resume - resume audio stream 20:01:54.848 T:4094133152 DEBUG: ActiveAE - start sync of audio stream 20:01:54.851 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1109702483.163294) 20:01:54.989 T:4094133152 DEBUG: ActiveAE::SyncStream - average error of -10.847193, start adjusting 20:01:54.989 T:4094133152 DEBUG: ActiveAE::SyncStream - average error -0.847193 below threshold of 30.000000 20:01:56.015 T:3509105568 DEBUG: CDVDClock::ErrorAdjust - CVideoPlayerAudio::OutputPacket - error:-56731.578623, adjusted:-40000.000000 20:01:57.029 T:4146888640 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------ 20:01:57.030 T:4146888640 DEBUG: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------ 20:01:57.773 T:3972010912 DEBUG: PushCecKeypress - received key a9 duration 0 20:01:57.782 T:4146888640 DEBUG: OnKey: 169 (0xa9, obc86) pressed, action is StepBack 20:01:57.783 T:4146888640 DEBUG: ------ Window Init (DialogSeekBar.xml) ------ 20:01:57.787 T:4146888640 DEBUG: ------ Window Init (Custom_1109_TopBarOverlay.xml) ------ 20:01:58.114 T:3972010912 DEBUG: PushCecKeypress - received key a9 duration 341 20:01:58.543 T:4115710880 DEBUG: CAnnouncementManager - Announcement: OnSeek from xbmc 20:01:58.543 T:4115710880 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnSeek 20:01:58.545 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 1 20:01:58.545 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:58.545 T:3594679200 DEBUG: demuxer seek to: 1103363.000000 20:01:58.546 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(0) 20:01:58.559 T:3594679200 DEBUG: SeekTime - seek ended up on time 1101560 20:01:58.559 T:3594679200 DEBUG: demuxer seek to: 1103363.000000, success 20:01:58.559 T:3594679200 DEBUG: CVideoPlayer::FlushBuffers - flushing buffers 20:01:58.567 T:3633312672 DEBUG: CAMLCodec::Reset 20:01:58.575 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:58.659 T:3509105568 DEBUG: CDVDAudio::Flush - flush audio stream 20:01:58.659 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:58.659 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE 20:01:58.660 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE 20:01:58.660 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 2 20:01:58.660 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:58.662 T:3633312672 INFO: CVideoPlayerVideo - Stillframe left, switching to normal playback 20:01:58.670 T:3509105568 DEBUG: CDVDAudio::Pause - pausing audio stream 20:01:58.675 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 1 20:01:58.714 T:3594679200 DEBUG: CVideoPlayer::HandleMessages - player started 2 20:01:58.714 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 3 20:01:58.714 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:58.714 T:3633312672 DEBUG: CAMLCodec::SetSpeed, speed(1000) 20:01:58.715 T:3594679200 DEBUG: CVideoPlayer::SetCaching - caching state 0 20:01:58.715 T:3594679200 DEBUG: CDVDClock::SetSpeedAdjust - adjusted:0.000000 20:01:58.715 T:3594679200 DEBUG: VideoPlayer::Sync - Audio - pts: 1101940000.000000, cache: 384000.033140, totalcache: 741333.305836 20:01:58.715 T:3594679200 DEBUG: VideoPlayer::Sync - Video - pts: 1101560000.000000, cache: 50000.000000, totalcache: 100000.000000 20:01:58.715 T:3633312672 DEBUG: CVideoPlayerVideo - CDVDMsg::GENERAL_RESYNC(1101460000.000000) 20:01:58.715 T:3509105568 DEBUG: CVideoPlayerAudio - CDVDMsg::GENERAL_RESYNC(1101460000.000000) 20:01:58.715 T:3509105568 DEBUG: CDVDAudio::Resume - resume audio stream 20:01:58.745 T:4094133152 DEBUG: ActiveAE - start sync of audio stream 20:01:58.915 T:4094133152 DEBUG: ActiveAE::SyncStream - average error of -101.351460, start adjusting 20:01:58.915 T:4094133152 DEBUG: ActiveAE::SyncStream - average error -16.351460 below threshold of 30.000000 20:01:59.939 T:4094133152 DEBUG: ActiveAE::SyncStream - average error -184.564385 above threshold of 100.000000 20:01:59.939 T:4094133152 DEBUG: ActiveAE::SyncStream - average error -14.564385 below threshold of 30.000000 20:02:01.450 T:4146888640 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------ 20:02:01.450 T:4146888640 DEBUG: ------ Window Deinit (Custom_1109_TopBarOverlay.xml) ------ 20:02:03.450 T:3633312672 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000 20:02:16.652 T:3546993568 DEBUG: Thread JobWorker 3546993568 terminating (autodelete) 20:02:16.652 T:3718247328 DEBUG: Thread JobWorker 3718247328 terminating (autodelete) 20:02:16.652 T:3661632416 DEBUG: Thread JobWorker 3661632416 terminating (autodelete) 20:02:16.758 T:3500684192 DEBUG: Thread JobWorker 3500684192 terminating (autodelete) 20:11:53.921 T:3633312672 DEBUG: CPullupCorrection: pattern lost on diff 120000.000000, number of losses 1 20:11:54.197 T:4146888640 DEBUG: CRenderManager::PrepareNextRender m_QueueSkip:0 iter.pts:1697.000 front.pts:1697.040 renderPts:1697.051 latency:0.080 20:11:58.881 T:3633312672 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000 20:13:14.929 T:3492295584 INFO: CFileCache::Process - Source read didn't return any data! Hit eof(?) 20:20:36.511 T:3633312672 DEBUG: CPullupCorrection: pattern lost on diff 80000.000000, number of losses 2 20:20:41.394 T:3633312672 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000 20:27:30.441 T:3770684320 DEBUG: JSONRPC Server: New connection detected 20:27:30.441 T:3770684320 INFO: JSONRPC Server: New connection added 20:27:31.499 T:3546993568 DEBUG: CWebServer[8080]: request received for /jsonrpc 20:27:31.524 T:4146888640 DEBUG: Previous line repeats 1 times. 20:27:31.524 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate 20:27:31.524 T:4146888640 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------ 20:27:31.553 T:4146888640 DEBUG: CGUIWindowManager::PreviousWindow: Activate new 20:27:31.571 T:4146888640 DEBUG: ------ Window Init (MyVideoNav.xml) ------