Project

General

Profile

Bug #336 ยป xbmc.log

Thrung, 20/11/2014 10:25 PM

 
22:16:56 M: 55484416 NOTICE: -----------------------------------------------------------------------
22:16:56 M: 55463936 NOTICE: Starting XBMC4Xbox 3.5-r32977 (SVN:32977, compiler 1310). Built on Oct 14 2014
22:16:56 M: 55463936 NOTICE: special://xbmc/ is mapped to: Q:\
22:16:56 M: 55463936 NOTICE: special://masterprofile/ is mapped to: Q:\UserData
22:16:56 M: 55463936 NOTICE: special://home/ is mapped to: Q:\
22:16:56 M: 55463936 NOTICE: special://temp/ is mapped to: Z:\
22:16:56 M: 55463936 NOTICE: The executable running is: F:\Apps\XBMC_3.5\default.xbe
22:16:56 M: 55463936 NOTICE: Log File is located: Q:\xbmc.log
22:16:56 M: 55463936 NOTICE: -----------------------------------------------------------------------
22:16:56 M: 55463936 NOTICE: Unmapped drive T
22:16:56 M: 55463936 NOTICE: Mapping drive T to Harddisk0\Partition6\Apps\XBMC_3.5\UserData\
22:16:56 M: 55463936 NOTICE: Setup DirectX
22:16:57 M: 55439360 NOTICE: Mapping drive C to Harddisk0\Partition2
22:16:57 M: 55439360 NOTICE: Mapping drive E to Harddisk0\Partition1
22:16:57 M: 55439360 NOTICE: Unmapped drive D
22:16:57 M: 55439360 NOTICE: Mapping drive D to Cdrom0
22:16:57 M: 55439360 NOTICE: Mapping drive F to Harddisk0\Partition6
22:16:57 M: 55439360 NOTICE: Mapping drive X to Harddisk0\Partition3
22:16:57 M: 55439360 NOTICE: Mapping drive Y to Harddisk0\Partition4
22:16:57 M: 55435264 NOTICE: Unmapped drive Z
22:16:57 M: 55435264 NOTICE: Mapping drive Z to Harddisk0\Partition5
22:16:57 M: 55435264 NOTICE: load settings...
22:16:57 M: 55435264 NOTICE: Mapping drive P to Harddisk0\Partition6\Apps\XBMC_3.5\UserData\
22:16:57 M: 55435264 NOTICE: special://profile/ is mapped to: special://masterprofile/
22:16:57 M: 55435264 NOTICE: loading special://masterprofile/guisettings.xml
22:16:57 M: 55177216 NOTICE: Getting hardware information now...
22:16:57 M: 55177216 NOTICE: Checking resolution 1
22:16:57 M: 55177216 NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
22:16:57 M: 55156736 NOTICE: Loaded playercorefactory configuration
22:16:57 M: 55152640 NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
22:16:57 M: 55152640 NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
22:16:57 M: 55152640 NOTICE: No advancedsettings.xml to load (special://masterprofile/advancedsettings.xml)
22:16:57 M: 55152640 NOTICE: Default Video Player: dvdplayer
22:16:57 M: 55152640 NOTICE: Default Audio Player: paplayer
22:16:57 M: 55152640 NOTICE: Log level changed to 2
22:16:57 M: 55152640 NOTICE: Enabled debug logging due to GUI setting (2)
22:16:57 M: 55152640 NOTICE: Per AV pack settings are off
22:16:57 M: 55361536 NOTICE: special://masterprofile/sources.xml
22:16:57 M: 55361536 ERROR: Missing or invalid <name> and/or <path> in source
22:16:57 M: 55361536 INFO: load language info file:special://xbmc/language/English/langinfo.xml
22:16:57 M: 55361536 INFO: load keyboard layout configuration info file: Q:\language\english\keyboardmap.xml
22:16:57 M: 55361536 INFO: unable to load Q:\language\english\keyboardmap.xml: Failed to open file at line 0
22:16:57 M: 55361536 INFO: load English language file, from path: special://xbmc/language/
22:16:57 M: 55050240 DEBUG: POParser: loaded 2069 strings from file Q:\language\English\strings.po
22:16:57 M: 55144448 INFO: load keymapping
22:16:57 M: 55144448 DEBUG: CFileItemList::Sort, sorting took 0 millis
22:16:57 M: 55123968 INFO: Loading special://xbmc/system/keymaps/gamepad.xml
22:16:57 M: 55078912 INFO: Loading special://xbmc/system/keymaps/keyboard.xml
22:16:57 M: 55062528 INFO: Loading special://xbmc/system/keymaps/remote.xml
22:16:57 M: 55050240 INFO: Checking skin version of: Project Mayhem III
22:16:57 M: 55066624 INFO: Default 4:3 resolution directory is special://xbmc/skin/Project Mayhem III/PAL
22:16:57 M: 55046144 INFO: Default 16:9 resolution directory is special://xbmc/skin/Project Mayhem III/PAL16x9
22:16:57 M: 55046144 DEBUG: We set resolution 1
22:16:57 M: 46039040 INFO: GUI format 1280x720 720p 16:9
22:16:57 M: 46039040 INFO: install unhandled exception filter
22:16:57 M: 46018560 INFO: creating subdirectories
22:16:57 M: 46018560 INFO: userdata folder: special://masterprofile/
22:16:57 M: 46018560 INFO: recording folder:
22:16:57 M: 46018560 INFO: screenshots folder:
22:16:57 M: 46018560 INFO: thumbnails folder: special://masterprofile/Thumbnails
22:16:57 M: 46014464 DEBUG: CNetwork::SetupNetwork - Setting up network...
22:16:57 M: 46014464 NOTICE: Network: Using dashboard IP settings
22:16:57 M: 45699072 NOTICE: Using idle thread with HLT (power saving)
22:16:57 M: 45686784 NOTICE: Checking the Date!
22:16:57 M: 45686784 INFO: Current Date is: 20-11-2014
22:16:57 M: 45686784 NOTICE: start dvd mediatype detection
22:16:57 M: 45621248 NOTICE: initializing playlistplayer
22:16:57 M: 45621248 DEBUG: Compiled with libcdio Version 0.72
22:16:57 M: 45621248 NOTICE: DONE initializing playlistplayer
22:16:57 M: 45621248 INFO: lcd not used
22:16:57 M: 45621248 NOTICE: start fancontroller
22:16:58 M: 45088768 NOTICE: load default skin:[Project Mayhem III]
22:16:58 M: 45088768 INFO: load skin from:Q:\skin\Project Mayhem III
22:16:58 M: 45088768 INFO: delete old skin...
22:16:58 M: 45088768 DEBUG: ------ Window Deinit (Pointer.xml) ------
22:16:58 M: 45088768 DEBUG: ------ Window Deinit (DialogMuteBug.xml) ------
22:16:58 M: 45088768 INFO: Default 4:3 resolution directory is Q:\skin\Project Mayhem III\PAL
22:16:58 M: 45088768 INFO: Default 16:9 resolution directory is Q:\skin\Project Mayhem III\PAL16x9
22:16:58 M: 45088768 INFO: Loading skin includes from Q:\skin\Project Mayhem III\PAL\includes.xml
22:16:58 M: 43597824 INFO: load fonts for skin...
22:16:58 M: 43626496 INFO: Loading fonts from Q:\skin\Project Mayhem III\720p\Font.xml
22:16:58 M: 43159552 DEBUG: LocalizeStrings: no translation available in currently set gui language, at path Q:\skin\Project Mayhem III\language\english
22:16:58 M: 43139072 INFO: load new skin...
22:16:58 M: 43139072 INFO: Default 4:3 resolution directory is Q:\skin\Project Mayhem III\PAL
22:16:58 M: 43139072 INFO: Default 16:9 resolution directory is Q:\skin\Project Mayhem III\PAL16x9
22:16:58 M: 43139072 INFO: Loading skin file: Home.xml
22:16:58 M: 42229760 INFO: Loading user windows, path Q:\skin\Project Mayhem III\PAL16x9
22:16:58 M: 42229760 INFO: Loading user windows, path Q:\skin\Project Mayhem III\PAL
22:16:58 M: 42229760 INFO: Loading skin file: Q:\skin\Project Mayhem III\PAL\custom2_SkinSettings.xml
22:16:58 M: 42229760 DEBUG: Load Skin XML: 92.76ms
22:16:58 M: 42229760 INFO: initialize new skin...
22:16:58 M: 42229760 INFO: Loading skin file: Pointer.xml
22:16:58 M: 42196992 INFO: Loading skin file: DialogVolumeBar.xml
22:16:58 M: 42188800 INFO: Loading skin file: DialogSeekBar.xml
22:16:58 M: 42151936 INFO: Loading skin file: DialogKaiToast.xml
22:16:58 M: 42151936 INFO: Loading skin file: DialogMuteBug.xml
22:16:58 M: 41758720 INFO: skin loaded...
22:16:58 M: 40792064 DEBUG: kernel32.dll fake function DisableThreadLibraryCalls called
22:16:58 M: 40779776 INFO: Loading skin file: DialogBusy.xml
22:16:58 M: 41312256 DEBUG: Activating window ID: 12999
22:16:58 M: 41312256 DEBUG: Checking if window ID 12999 is locked.
22:16:58 M: 41312256 DEBUG: ------ Window Init (Startup.xml) ------
22:16:58 M: 41312256 INFO: Loading skin file: Startup.xml
22:16:58 M: 41312256 INFO: removing tempfiles
22:16:58 M: 41312256 NOTICE: initialize done
22:16:58 M: 41291776 NOTICE: Running the application...
22:16:58 M: 41291776 DEBUG: XBPython::Process - no system autoexec.py (Q:\scripts\autoexec.py) found, skipping
22:16:59 M: 38285312 DEBUG: CApplication::ExecuteXBMCAction : Translating ReplaceWindow(Home)
22:16:59 M: 38285312 DEBUG: CApplication::ExecuteXBMCAction : To ReplaceWindow(Home)
22:16:59 M: 38285312 DEBUG: Activating window ID: 10000
22:16:59 M: 38285312 DEBUG: Checking if window ID 10000 is locked.
22:16:59 M: 38285312 DEBUG: ------ Window Deinit (Startup.xml) ------
22:16:59 M: 41291776 DEBUG: ------ Window Init (Home.xml) ------
22:16:59 M: 41078784 DEBUG: CNetwork::NetworkUp - Network service is up
22:16:59 M: 41078784 DEBUG: CRecentlyAddedJob::UpdateMusic() - Running RecentlyAdded home screen update
22:16:59 M: 41078784 INFO: CNetwork::LogState - Link: full duplex
22:16:59 M: 41078784 INFO: CNetwork::LogState - Link: 100 mbps
22:16:59 M: 41058304 INFO: CNetwork::LogState - State: dns
22:16:59 M: 41058304 INFO: CNetwork::LogState - State: static
22:16:59 M: 41058304 INFO: CNetwork::LogState - ip: 192.168.0.50
22:16:59 M: 41058304 INFO: CNetwork::LogState - subnet: 255.255.255.0
22:16:59 M: 41058304 INFO: CNetwork::LogState - gateway: 192.168.0.1
22:16:59 M: 41058304 INFO: CNetwork::LogState - dns: 192.168.0.1, 217.151.105.9
22:16:59 M: 37920768 DEBUG: GetRecentlyAddedAlbumSongs() query: SELECT songview.* FROM (SELECT idAlbum FROM albumview ORDER BY idAlbum DESC LIMIT 10) AS recentalbums JOIN songview ON songview.idAlbum=recentalbums.idAlbum
22:16:59 M: 37810176 DEBUG: CNetwork::NetworkMessage - Starting network services
22:16:59 M: 37810176 DEBUG: SECTION:Section SNTP loaded count:1 size:7036
22:16:59 M: 37810176 NOTICE: start timeserver client
22:16:59 M: 37744640 NOTICE: Webserver: Starting...
22:17:00 M: 37666816 DEBUG: SECTION:Section LIBHTTP loaded count:1 size:80300
22:17:00 M: 37646336 DEBUG: xbmcHttpShim starts
22:17:00 M: 37515264 INFO: WebServer: Server starting using Q:\web on 192.168.0.50:80
22:17:00 M: 37515264 DEBUG: DB: Registering database table <users>
22:17:00 M: 37515264 DEBUG: DB: Registering database table <groups>
22:17:00 M: 37515264 DEBUG: DB: Registering database table <access>
22:17:00 M: 37515264 DEBUG: UM: Loading User Configuration from file <umconfig.txt>
22:17:00 M: 37515264 DEBUG: DB: About to read data file <Q:\web\umconfig.txt>
22:17:00 M: 37515264 DEBUG: webs: Listening for HTTP requests at address 192.168.0.50
22:17:00 M: 37515264 NOTICE: Webserver: Started
22:17:00 M: 37515264 DEBUG: UM: Writing User Configuration to file <umconfig.txt>
22:16:59 M: 37580800 DEBUG: DB: About to save database to file
22:16:59 M: 37580800 NOTICE: XBFileZilla: Starting...
22:16:59 M: 37515264 NOTICE: starting upnp server
22:16:59 M: 37208064 NOTICE: starting upnp renderer
22:16:59 M: 37023744 NOTICE: ES: Starting event server
22:16:59 M: 36478976 DEBUG: CLastfmScrobbler: Clearing session.
22:16:59 M: 36478976 NOTICE: ES: Starting UDP Event server on 0.0.0.0:9777
22:16:59 M: 36478976 DEBUG: CLibrefmScrobbler: Clearing session.
22:16:59 M: 36454400 NOTICE: UDP: Listening on port 9777
22:16:59 M: 35938304 INFO: WEATHER: Downloading weather
22:17:00 M: 35966976 DEBUG: CurlFile::Open(D0450934) http://xml.weather.com/weather/local/UKXX0802?cc=*&unit=m&dayf=7&prod=xoap&link=xoap&par=1004124588&key=079f24145f208494
22:17:00 M: 35848192 INFO: XCURL::DllLibCurlGlobal::easy_aquire - Created session to http://xml.weather.com
22:17:00 M: 34967552 NOTICE: XBFileZilla: Started
22:17:00 M: 34811904 INFO: WEATHER: Weather download successful
22:17:02 M: 30187520 DEBUG: CApplication::OnKey: 273 pressed, action is Right
22:17:02 M: 30113792 DEBUG: CApplication::OnKey: 256 pressed, action is Select
22:17:02 M: 30380032 DEBUG: CApplication::ExecuteXBMCAction : Translating ActivateWindow(Favourites)
22:17:02 M: 30380032 DEBUG: CApplication::ExecuteXBMCAction : To ActivateWindow(Favourites)
22:17:02 M: 30380032 DEBUG: Activating window ID: 10134
22:17:02 M: 30380032 DEBUG: Checking if window ID 10134 is locked.
22:17:02 M: 30380032 DEBUG: ------ Window Init (DialogFavourites.xml) ------
22:17:02 M: 30380032 INFO: Loading skin file: DialogFavourites.xml
22:17:02 M: 30113792 DEBUG: CFavourites::Load - no system favourites found, skipping
22:17:03 M: 29450240 DEBUG: CApplication::OnKey: 256 pressed, action is Select
22:17:03 M: 29716480 DEBUG: ------ Window Deinit (DialogFavourites.xml) ------
22:17:03 M: 30339072 DEBUG: CApplication::ExecuteXBMCAction : Translating PlayMedia("smb://MININAS/MiniNAS/AC3test.ac3")
22:17:03 M: 30343168 DEBUG: CApplication::ExecuteXBMCAction : To PlayMedia("smb://MININAS/MiniNAS/AC3test.ac3")
22:17:04 M: 30060544 DEBUG: CPlayerCoreFactory::GetPlayers(smb://MININAS/MiniNAS/AC3test.ac3)
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: un-named
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: un-named
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/rtmp/mms/udp
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
22:17:04 M: 30060544 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
22:17:04 M: 30318592 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdfile
22:17:04 M: 30314496 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
22:17:04 M: 30318592 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: ogv/flv/mov
22:17:04 M: 30318592 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: adding audiodefaultplayer (3)
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: for video=0, audio=1
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: PAPlayer (3)
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: MODPlayer (4)
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: MPlayer (2)
22:17:04 M: 30318592 DEBUG: CPlayerCoreFactory::GetPlayers: added 4 players
22:17:04 M: 28594176 DEBUG: CSmbFile::Open - opened MiniNAS/AC3test.ac3, fd=10000
22:17:05 M: 28614656 DEBUG: GetModuleHandleA('libgcc_s_dw2-1.dll') failed
Previous line repeats 1 times.
22:17:05 M: 19111936 DEBUG: ------ Window Init (DialogBusy.xml) ------
22:17:05 M: 18243584 INFO: Loading skin file: DialogBusy.xml
22:17:06 M: 17895424 DEBUG: GetModuleHandleA('libgcc_s_dw2-1.dll') failed
22:17:06 M: 17854464 DEBUG: CDVDDemuxFFmpeg::Open - probing detected format [ac3]
22:17:06 M: 17854464 DEBUG: CDVDDemuxFFmpeg::Open - avformat_find_stream_info starting
22:17:06 M: 17731584 DEBUG: Unable to resolve: kernel32.dll InitializeConditionVariable
22:17:06 M: 17731584 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'InitializeConditionVariable') => 00000000
22:17:06 M: 17731584 DEBUG: Unable to resolve: kernel32.dll WakeAllConditionVariable
22:17:06 M: 17731584 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeAllConditionVariable') => 00000000
22:17:06 M: 17731584 DEBUG: Unable to resolve: kernel32.dll WakeConditionVariable
22:17:06 M: 17731584 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeConditionVariable') => 00000000
22:17:06 M: 17731584 DEBUG: Unable to resolve: kernel32.dll SleepConditionVariableCS
22:17:06 M: 17731584 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'SleepConditionVariableCS') => 00000000
22:17:09 M: 17092608 DEBUG: ffmpeg[8]: [ac3] max_analyze_duration 5000000 reached at 5024000 microseconds
22:17:09 M: 17170432 DEBUG: ffmpeg[8]: [ac3] Estimating duration from bitrate, this may be inaccurate
22:17:09 M: 17444864 DEBUG: CDVDDemuxFFmpeg::Open - av_find_stream_info finished
22:17:09 M: 17444864 INFO: ffmpeg[8]: Input #0, ac3, from 'smb://MININAS/MiniNAS/AC3test.ac3':
22:17:09 M: 17444864 INFO: ffmpeg[8]: Duration: 00:00:15.01, start: 0.000000, bitrate: 448 kb/s
22:17:09 M: 17444864 INFO: ffmpeg[8]: Stream #0:0: Audio: ac3, 48000 Hz, 5.1(side), fltp, 448 kb/s
22:17:09 M: 17252352 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
22:17:09 M: 16855040 DEBUG: GetModuleHandleA('libgcc_s_dw2-1.dll') failed
22:17:09 M: 16748544 DEBUG: Unable to resolve: kernel32.dll InitializeConditionVariable
22:17:09 M: 16748544 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'InitializeConditionVariable') => 00000000
22:17:09 M: 16748544 DEBUG: Unable to resolve: kernel32.dll WakeAllConditionVariable
22:17:09 M: 16748544 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeAllConditionVariable') => 00000000
22:17:09 M: 16748544 DEBUG: Unable to resolve: kernel32.dll WakeConditionVariable
22:17:09 M: 16748544 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeConditionVariable') => 00000000
22:17:09 M: 16748544 DEBUG: Unable to resolve: kernel32.dll SleepConditionVariableCS
22:17:09 M: 16748544 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'SleepConditionVariableCS') => 00000000
22:17:09 M: 16748544 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
22:17:09 M: 16957440 INFO: PAPlayer: Playing smb://MININAS/MiniNAS/AC3test.ac3
22:17:09 M: 16355328 DEBUG: CApplication::OnPlayBackStarted - Playback has started
22:17:09 M: 16355328 DEBUG: PAPlayer: Thread started
22:17:09 M: 16355328 DEBUG: CApplication::OnPlayBackStarted - Playback has started
22:17:09 M: 16293888 INFO: AudioDecoder: File is queued
22:17:09 M: 16343040 DEBUG: CGUIInfoManager::SetCurrentSong(smb://MININAS/MiniNAS/AC3test.ac3)
22:17:11 M: 20221952 DEBUG: POParser: loaded 51 weather tokens
22:17:11 M: 20295680 DEBUG: ------ Window Init (DialogBusy.xml) ------
22:17:14 M: 19890176 DEBUG: CMusicDatabase::GetRecentlyAddedAlbums query: select * from albumview order by idAlbum desc limit 10
22:17:14 M: 19906560 DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update
22:17:14 M: 19886080 DEBUG: CVideoDatabase::RunQuery took 8 ms for 0 items query: select * from movieview order by idMovie desc limit 10
22:17:15 M: 19853312 DEBUG: CVideoDatabase::RunQuery took 75 ms for 0 items query: select * from episodeview order by idEpisode desc limit 10
22:17:15 M: 19853312 DEBUG: CVideoDatabase::GetMusicVideosByWhere query = select * from musicvideoview order by idMVideo desc limit 10
22:17:15 M: 19824640 DEBUG: CVideoDatabase::GetMusicVideosByWhere time for actual SQL query = 11
22:17:15 M: 19824640 DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update
22:17:18 M: 17920000 DEBUG: CFileItem::LoadMusicTag: loading tag information for file: smb://MININAS/MiniNAS/AC3test.ac3
22:17:18 M: 17920000 DEBUG: Loading additional tag info for file smb://MININAS/MiniNAS/AC3test.ac3
22:17:18 M: 17920000 DEBUG: CGUIInfoManager::SetCurrentSong(smb://MININAS/MiniNAS/AC3test.ac3)
22:17:19 M: 17879040 DEBUG: Player has asked for the next item
22:17:23 M: 15441920 DEBUG: CFileItem::LoadMusicTag: loading tag information for file: smb://MININAS/MiniNAS/AC3test.ac3
22:17:23 M: 15441920 DEBUG: Loading additional tag info for file smb://MININAS/MiniNAS/AC3test.ac3
22:17:23 M: 15441920 INFO: XCURL::DllLibCurlGlobal::CheckIdle - Closing session to http://xml.weather.com (easy=00C08010, multi=00B7B100)
22:17:23 M: 15712256 DEBUG: Building didl for object 'smb://MININAS/MiniNAS/AC3test.ac3'
22:17:23 M: 15712256 ERROR: Incorrect movie stacking regexp format:[(.*?)([ ._-]*[a-d])(.*?)(\.[^.]+)$]
22:17:23 M: 15732736 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
22:17:24 M: 15872000 INFO: CAudioDecoder::GetData() ending track - only have 2688 samples left
22:17:24 M: 15872000 INFO: PAPlayer: End of playback reached
22:17:24 M: 15872000 DEBUG: CApplication::OnPlayBackEnded - Playback has finished
22:17:24 M: 17203200 DEBUG: CSmbFile::Close closing fd 10000
22:17:24 M: 17756160 DEBUG: CApplication::SaveFileState - Saving file state for audio item smb://MININAS/MiniNAS/AC3test.ac3
22:17:24 M: 17756160 DEBUG: CApplication::SaveFileState - Marking audio item smb://MININAS/MiniNAS/AC3test.ac3 as listened
22:17:25 M: 17756160 DEBUG: CApplication::OnKey: 256 pressed, action is Select
22:17:25 M: 17756160 DEBUG: CApplication::ExecuteXBMCAction : Translating ActivateWindow(Favourites)
22:17:25 M: 17756160 DEBUG: CApplication::ExecuteXBMCAction : To ActivateWindow(Favourites)
22:17:25 M: 17756160 DEBUG: Activating window ID: 10134
22:17:25 M: 17756160 DEBUG: Checking if window ID 10134 is locked.
22:17:25 M: 17756160 DEBUG: ------ Window Init (DialogFavourites.xml) ------
22:17:25 M: 17756160 INFO: Loading skin file: DialogFavourites.xml
22:17:25 M: 17756160 DEBUG: CFavourites::Load - no system favourites found, skipping
22:17:26 M: 17125376 DEBUG: CApplication::OnKey: 271 pressed, action is Down
22:17:26 M: 17125376 DEBUG: CApplication::OnKey: 256 pressed, action is Select
22:17:26 M: 17125376 DEBUG: ------ Window Deinit (DialogFavourites.xml) ------
22:17:26 M: 17752064 DEBUG: CApplication::ExecuteXBMCAction : Translating PlayMedia("smb://MININAS/MiniNAS/Test AC3 v2.0.ac3")
22:17:26 M: 17752064 DEBUG: CApplication::ExecuteXBMCAction : To PlayMedia("smb://MININAS/MiniNAS/Test AC3 v2.0.ac3")
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers(smb://MININAS/MiniNAS/Test AC3 v2.0.ac3)
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: un-named
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: un-named
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/rtmp/mms/udp
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdfile
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: ogv/flv/mov
22:17:26 M: 17752064 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: adding audiodefaultplayer (3)
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: for video=0, audio=1
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: PAPlayer (3)
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: MODPlayer (4)
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: MPlayer (2)
22:17:26 M: 17752064 DEBUG: CPlayerCoreFactory::GetPlayers: added 4 players
22:17:26 M: 16920576 DEBUG: CSmbFile::Open - opened MiniNAS/Test AC3 v2.0.ac3, fd=10000
22:17:26 M: 16883712 DEBUG: CDVDDemuxFFmpeg::Open - probing detected format [ac3]
22:17:26 M: 16883712 DEBUG: CDVDDemuxFFmpeg::Open - avformat_find_stream_info starting
22:17:26 M: 16760832 DEBUG: Unable to resolve: kernel32.dll InitializeConditionVariable
22:17:26 M: 16760832 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'InitializeConditionVariable') => 00000000
22:17:26 M: 16760832 DEBUG: Unable to resolve: kernel32.dll WakeAllConditionVariable
22:17:26 M: 16760832 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeAllConditionVariable') => 00000000
22:17:26 M: 16760832 DEBUG: Unable to resolve: kernel32.dll WakeConditionVariable
22:17:26 M: 16760832 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeConditionVariable') => 00000000
22:17:26 M: 16760832 DEBUG: Unable to resolve: kernel32.dll SleepConditionVariableCS
22:17:26 M: 16760832 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'SleepConditionVariableCS') => 00000000
22:17:27 M: 16736256 DEBUG: ffmpeg[8]: [ac3] max_analyze_duration 5000000 reached at 5024000 microseconds
22:17:27 M: 16855040 DEBUG: ffmpeg[8]: [ac3] Estimating duration from bitrate, this may be inaccurate
22:17:27 M: 16875520 DEBUG: CDVDDemuxFFmpeg::Open - av_find_stream_info finished
22:17:27 M: 16875520 INFO: ffmpeg[8]: Input #0, ac3, from 'smb://MININAS/MiniNAS/Test AC3 v2.0.ac3':
22:17:27 M: 16875520 INFO: ffmpeg[8]: Duration: 00:00:33.38, start: 0.000000, bitrate: 384 kb/s
22:17:27 M: 16875520 INFO: ffmpeg[8]: Stream #0:0: Audio: ac3, 48000 Hz, 5.1(side), fltp, 384 kb/s
22:17:27 M: 16683008 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
22:17:27 M: 16560128 DEBUG: Unable to resolve: kernel32.dll InitializeConditionVariable
22:17:27 M: 16560128 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'InitializeConditionVariable') => 00000000
22:17:27 M: 16560128 DEBUG: Unable to resolve: kernel32.dll WakeAllConditionVariable
22:17:27 M: 16560128 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeAllConditionVariable') => 00000000
22:17:27 M: 16560128 DEBUG: Unable to resolve: kernel32.dll WakeConditionVariable
22:17:27 M: 16560128 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'WakeConditionVariable') => 00000000
22:17:27 M: 16560128 DEBUG: Unable to resolve: kernel32.dll SleepConditionVariableCS
22:17:27 M: 16560128 DEBUG: dllGetProcAddress(00893758(kernel32.dll), 'SleepConditionVariableCS') => 00000000
22:17:27 M: 16560128 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
22:17:27 M: 16502784 INFO: PAPlayer: Playing smb://MININAS/MiniNAS/Test AC3 v2.0.ac3
22:17:27 M: 15904768 DEBUG: CApplication::OnPlayBackStarted - Playback has started
22:17:27 M: 15904768 DEBUG: PAPlayer: Thread started
22:17:27 M: 15835136 DEBUG: CApplication::OnPlayBackStarted - Playback has started
22:17:27 M: 15835136 DEBUG: CGUIInfoManager::SetCurrentSong(smb://MININAS/MiniNAS/Test AC3 v2.0.ac3)
22:17:27 M: 15818752 INFO: AudioDecoder: File is queued
22:17:29 M: 18518016 DEBUG: ------ Window Init (DialogBusy.xml) ------
22:17:29 M: 18518016 INFO: Loading skin file: DialogBusy.xml
22:17:32 M: 17768448 DEBUG: CFileItem::LoadMusicTag: loading tag information for file: smb://MININAS/MiniNAS/Test AC3 v2.0.ac3
22:17:32 M: 17772544 DEBUG: Loading additional tag info for file smb://MININAS/MiniNAS/Test AC3 v2.0.ac3
22:17:32 M: 17805312 DEBUG: CGUIInfoManager::SetCurrentSong(smb://MININAS/MiniNAS/Test AC3 v2.0.ac3)
22:17:34 M: 17772544 DEBUG: ------ Window Init (DialogBusy.xml) ------
22:17:37 M: 15671296 DEBUG: CFileItem::LoadMusicTag: loading tag information for file: smb://MININAS/MiniNAS/Test AC3 v2.0.ac3
22:17:37 M: 15695872 DEBUG: Loading additional tag info for file smb://MININAS/MiniNAS/Test AC3 v2.0.ac3
22:17:37 M: 15716352 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
22:17:55 M: 21159936 DEBUG: Player has asked for the next item
22:18:00 M: 21168128 INFO: CAudioDecoder::GetData() ending track - only have 3072 samples left
22:18:00 M: 21168128 INFO: PAPlayer: End of playback reached
22:18:00 M: 21168128 DEBUG: CApplication::OnPlayBackEnded - Playback has finished
22:18:00 M: 22573056 DEBUG: CSmbFile::Close closing fd 10000
22:18:00 M: 23236608 DEBUG: CApplication::SaveFileState - Saving file state for audio item smb://MININAS/MiniNAS/Test AC3 v2.0.ac3
22:18:00 M: 23236608 DEBUG: CApplication::SaveFileState - Marking audio item smb://MININAS/MiniNAS/Test AC3 v2.0.ac3 as listened
22:18:01 M: 23236608 DEBUG: CApplication::OnKey: 273 pressed, action is Right
22:18:01 M: 23240704 DEBUG: CApplication::OnKey: 256 pressed, action is Select
22:18:01 M: 23240704 DEBUG: CApplication::ExecuteXBMCAction : Translating ActivateWindow(ShutdownMenu)
22:18:01 M: 23240704 DEBUG: CApplication::ExecuteXBMCAction : To ActivateWindow(ShutdownMenu)
22:18:01 M: 23240704 DEBUG: Activating window ID: 10111
22:18:01 M: 23240704 DEBUG: Checking if window ID 10111 is locked.
22:18:01 M: 23240704 DEBUG: ------ Window Init (DialogButtonMenu.xml) ------
22:18:01 M: 23240704 INFO: Loading skin file: DialogButtonMenu.xml
22:18:03 M: 22818816 DEBUG: CApplication::OnKey: 273 pressed, action is Right
Previous line repeats 1 times.
22:18:04 M: 22745088 DEBUG: CApplication::OnKey: 256 pressed, action is Select
22:18:04 M: 22745088 DEBUG: CApplication::ExecuteXBMCAction : Translating XBMC.Reset()
22:18:04 M: 22745088 DEBUG: CApplication::ExecuteXBMCAction : To XBMC.Reset()
22:18:04 M: 22745088 NOTICE: Storing total System Uptime
22:18:04 M: 22745088 NOTICE: Saving settings
22:18:04 M: 22745088 NOTICE: stop all
22:18:04 M: 22745088 DEBUG: CNetwork::NetworkMessage - Stopping network services
22:18:04 M: 22745088 NOTICE: stop time server client
22:18:04 M: 22745088 NOTICE: Webserver: Stopping...
22:18:04 M: 22745088 DEBUG: WebServer:Exiting thread sockReady=0, sockSelect=0.
22:18:04 M: 22745088 DEBUG: WebServer:OnExit - Exit web server.
22:18:04 M: 22872064 DEBUG: xbmcHttpShim ends
22:18:04 M: 22872064 DEBUG: xbmcHttp ends
22:18:04 M: 22872064 NOTICE: Webserver: Stopped...
22:18:04 M: 22872064 INFO: XBFileZilla: Stopping...
22:18:04 M: 23068672 INFO: XBFileZilla: Stopped
22:18:04 M: 23068672 NOTICE: stopping upnp
22:18:04 M: 23003136 NOTICE: ES: Stopping event server
22:18:04 M: 23134208 NOTICE: ES: UDP Event server stopped
22:18:04 M: 23658496 DEBUG: CLastfmScrobbler: Journal with 0 entries saved to special://masterprofile/LastfmScrobbler.xml
22:18:05 M: 23658496 DEBUG: CLibrefmScrobbler: Journal with 0 entries saved to special://masterprofile/LibrefmScrobbler.xml
22:18:05 M: 23658496 NOTICE: stop dvd detect media
22:18:05 M: 23724032 NOTICE: stop fancontroller
22:18:05 M: 24338432 NOTICE: stop daap clients
22:18:05 M: 24338432 NOTICE: clean cached files!
22:18:05 M: 24338432 NOTICE: unload skin
22:18:05 M: 24862720 DEBUG: ------ Window Deinit (Home.xml) ------
22:18:05 M: 28905472 DEBUG: ------ Window Deinit (Pointer.xml) ------
22:18:05 M: 28938240 DEBUG: ------ Window Deinit (DialogMuteBug.xml) ------
22:18:05 M: 29425664 NOTICE: stop python
22:18:05 M: 29425664 NOTICE: stopped
22:18:05 M: 29995008 NOTICE: unload sections
22:18:05 M: 29995008 DEBUG: SECTION:UnloadAll(SECTION: SNTP)
22:18:05 M: 29995008 DEBUG: SECTION:UnloadAll(SECTION: LIBHTTP)
22:18:05 M: 30072832 DEBUG: SECTION:UnloadAll(DLL: Q:\system\libcurl.dll)
22:18:05 M: 30523392 DEBUG: SECTION:UnloadAll(DLL: Q:\system\players\dvdplayer\full\avutil-52.dll)
22:18:05 M: 30523392 DEBUG: SECTION:UnloadAll(DLL: Q:\system\players\dvdplayer\full\avcodec-54.dll)
22:18:05 M: 30523392 DEBUG: SECTION:UnloadAll(DLL: Q:\system\players\dvdplayer\full\avformat-54.dll)
22:18:05 M: 30523392 DEBUG: GetModuleHandleA('libgcc_s_dw2-1.dll') failed
Previous line repeats 1 times.
22:18:05 M: 41058304 DEBUG: SECTION:UnloadAll(DLL: Q:\system\players\dvdplayer\full\swresample-0.dll)
22:18:05 M: 41058304 DEBUG: GetModuleHandleA('libgcc_s_dw2-1.dll') failed
    (1-1/1)