· 9 years ago · Dec 26, 2016, 09:08 AM
102:14:45 T:140030437029952 NOTICE: special://profile/ is mapped to: special://masterprofile/
202:14:45 T:140030437029952 NOTICE: -----------------------------------------------------------------------
302:14:45 T:140030437029952 NOTICE: Starting Kodi (16.1 Git:c327c53). Platform: Linux x86 64-bit
402:14:45 T:140030437029952 NOTICE: Using Release Kodi x64 build
502:14:45 T:140030437029952 NOTICE: Kodi compiled Apr 24 2016 by GCC 4.8.4 for Linux x86 64-bit version 3.13.11 (199947)
602:14:45 T:140030437029952 NOTICE: Running on Ubuntu 14.04.5 LTS, kernel: Linux x86 64-bit version 3.13.0-105-generic
702:14:45 T:140030437029952 NOTICE: FFmpeg statically linked, version: 2.8.6-kodi-2.8.6-Jarvis-16.0
802:14:45 T:140030437029952 NOTICE: Host CPU: Intel(R) Atom(TM) CPU D525 @ 1.80GHz, 4 cores available
902:14:45 T:140030437029952 NOTICE: special://xbmc/ is mapped to: /usr/share/kodi
1002:14:45 T:140030437029952 NOTICE: special://xbmcbin/ is mapped to: /usr/lib/kodi
1102:14:45 T:140030437029952 NOTICE: special://masterprofile/ is mapped to: /home/jamesz/.kodi/userdata
1202:14:45 T:140030437029952 NOTICE: special://home/ is mapped to: /home/jamesz/.kodi
1302:14:45 T:140030437029952 NOTICE: special://temp/ is mapped to: /home/jamesz/.kodi/temp
1402:14:45 T:140030437029952 NOTICE: The executable running is: /usr/lib/kodi/kodi.bin
1502:14:45 T:140030437029952 NOTICE: Local hostname: JamesZ
1602:14:45 T:140030437029952 NOTICE: Log File is located: /home/jamesz/.kodi/temp/kodi.log
1702:14:45 T:140030437029952 NOTICE: -----------------------------------------------------------------------
1802:14:49 T:140030437029952 NOTICE: load settings...
1902:14:49 T:140030437029952 ERROR: PulseAudio: Failed to connect context
2002:14:49 T:140030437029952 NOTICE: PulseAudio might not be running. Context was not created.
2102:14:50 T:140030437029952 NOTICE: Found 1 Lists of Devices
2202:14:50 T:140030437029952 NOTICE: Enumerated ALSA devices:
2302:14:50 T:140030437029952 NOTICE: Device 1
2402:14:50 T:140030437029952 NOTICE: m_deviceName : default
2502:14:50 T:140030437029952 NOTICE: m_displayName : Default (HDA NVidia HDMI 0)
2602:14:50 T:140030437029952 NOTICE: m_displayNameExtra:
2702:14:50 T:140030437029952 NOTICE: m_deviceType : AE_DEVTYPE_PCM
2802:14:50 T:140030437029952 NOTICE: m_channels : FL,FR,BL,BR,FC,LFE,SL,SR
2902:14:50 T:140030437029952 NOTICE: m_sampleRates : 32000,44100,48000,88200,96000,176400,192000
3002:14:50 T:140030437029952 NOTICE: m_dataFormats : AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE
3102:14:50 T:140030437029952 NOTICE: Device 2
3202:14:50 T:140030437029952 NOTICE: m_deviceName : @:CARD=Intel,DEV=0
3302:14:50 T:140030437029952 NOTICE: m_displayName : HDA Intel
3402:14:50 T:140030437029952 NOTICE: m_displayNameExtra: ALC888 Analog
3502:14:50 T:140030437029952 NOTICE: m_deviceType : AE_DEVTYPE_PCM
3602:14:50 T:140030437029952 NOTICE: m_channels : FL,FR
3702:14:50 T:140030437029952 NOTICE: m_sampleRates : 48000
3802:14:50 T:140030437029952 NOTICE: m_dataFormats : AE_FMT_S32NE
3902:14:50 T:140030437029952 NOTICE: Device 3
4002:14:50 T:140030437029952 NOTICE: m_deviceName : iec958:CARD=Intel,DEV=0
4102:14:50 T:140030437029952 NOTICE: m_displayName : HDA Intel
4202:14:50 T:140030437029952 NOTICE: m_displayNameExtra: ALC888 Digital S/PDIF
4302:14:50 T:140030437029952 NOTICE: m_deviceType : AE_DEVTYPE_IEC958
4402:14:50 T:140030437029952 NOTICE: m_channels : FL,FR
4502:14:50 T:140030437029952 NOTICE: m_sampleRates : 44100,48000,88200,96000,192000
4602:14:50 T:140030437029952 NOTICE: m_dataFormats : AE_FMT_AC3,AE_FMT_DTS,AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE
4702:14:50 T:140030437029952 NOTICE: Device 4
4802:14:50 T:140030437029952 NOTICE: m_deviceName : hdmi:CARD=NVidia,DEV=0
4902:14:50 T:140030437029952 NOTICE: m_displayName : HDA NVidia
5002:14:50 T:140030437029952 NOTICE: m_displayNameExtra: PIO VSX-1122 on HDMI
5102:14:50 T:140030437029952 NOTICE: m_deviceType : AE_DEVTYPE_HDMI
5202:14:50 T:140030437029952 NOTICE: m_channels : FL,FR,LFE,FC,BL,BR,SL,SR
5302:14:50 T:140030437029952 NOTICE: m_sampleRates : 32000,44100,48000,88200,96000,176400,192000
5402:14:50 T:140030437029952 NOTICE: m_dataFormats : AE_FMT_LPCM,AE_FMT_AC3,AE_FMT_DTS,AE_FMT_EAC3,AE_FMT_DTSHD,AE_FMT_TRUEHD,AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE,AE_FMT_AAC
5502:14:50 T:140030437029952 NOTICE: No settings file to load (special://xbmc/system/advancedsettings.xml)
5602:14:50 T:140030437029952 NOTICE: Loaded settings file from special://profile/advancedsettings.xml
5702:14:50 T:140030437029952 NOTICE: Contents of special://profile/advancedsettings.xml are...
58 <advancedsettings>
59 <useddsfanart>true</useddsfanart>
60 <cputempcommand>cputemp</cputempcommand>
61 <gputempcommand>gputemp</gputempcommand>
62 <samba>
63 <clienttimeout>30</clienttimeout>
64 </samba>
65 <network>
66 <disableipv6>true</disableipv6>
67 </network>
68 <sorttokens>
69 <token>A</token>
70 </sorttokens>
71 </advancedsettings>
7202:14:50 T:140030437029952 NOTICE: Default DVD Player: dvdplayer
7302:14:50 T:140030437029952 NOTICE: Default Video Player: dvdplayer
7402:14:50 T:140030437029952 NOTICE: Default Audio Player: paplayer
7502:14:50 T:140030437029952 NOTICE: Enabled debug logging due to GUI setting (2)
7602:14:50 T:140030437029952 NOTICE: Log level changed to "LOG_LEVEL_DEBUG_FREEMEM"
7702:14:50 T:140030437029952 NOTICE: CMediaSourceSettings: loading media sources from special://masterprofile/sources.xml
7802:14:50 T:140030437029952 NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
7902:14:50 T:140030437029952 DEBUG: CPlayerCoreConfig::<ctor>: created player DVDPlayer for core 1
8002:14:50 T:140030437029952 DEBUG: CPlayerCoreConfig::<ctor>: created player oldmplayercore for core 1
8102:14:50 T:140030437029952 DEBUG: CPlayerCoreConfig::<ctor>: created player PAPlayer for core 3
8202:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: system rules
8302:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: mms/udp
8402:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: lastfm/shout
8502:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: rtmp
8602:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: rtsp
8702:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: streams
8802:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: aacp/sdp
8902:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: mp2
9002:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: dvd
9102:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: dvdimage
9202:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: sdp/asf
9302:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: nsv
9402:14:50 T:140030437029952 DEBUG: CPlayerSelectionRule::Initialize: creating rule: radio
9502:14:50 T:140030437029952 NOTICE: Loaded playercorefactory configuration
9602:14:50 T:140030437029952 NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
9702:14:50 T:140030437029952 NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
9802:14:50 T:140030437029952 INFO: creating subdirectories
9902:14:50 T:140030437029952 INFO: userdata folder: special://masterprofile/
10002:14:50 T:140030437029952 INFO: recording folder:
10102:14:50 T:140030437029952 INFO: screenshots folder:
10202:14:50 T:140029821093632 DEBUG: Thread ActiveAE start, auto delete: false
10302:14:50 T:140029812700928 DEBUG: Thread AESink start, auto delete: false
10402:14:50 T:140029812700928 INFO: CActiveAESink::OpenSink - initialize sink
10502:14:50 T:140029812700928 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=NVidia,DEV=0
10602:14:50 T:140029812700928 INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=NVidia,DEV=0"
10702:14:50 T:140029812700928 INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=NVidia,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
10802:14:50 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
10902:14:50 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
11002:14:50 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
11102:14:50 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
11202:14:50 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
11302:14:50 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
11402:14:50 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
11502:14:50 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
11602:14:50 T:140029812700928 DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
11702:14:50 T:140029812700928 DEBUG: Output Device : HDA NVidia
11802:14:50 T:140029812700928 DEBUG: Sample Rate : 44100
11902:14:50 T:140029812700928 DEBUG: Sample Format : AE_FMT_S32NE
12002:14:50 T:140029812700928 DEBUG: Channel Count : 2
12102:14:50 T:140029812700928 DEBUG: Channel Layout: FL,FR
12202:14:50 T:140029812700928 DEBUG: Frames : 2048
12302:14:50 T:140029812700928 DEBUG: Frame Samples : 4096
12402:14:50 T:140029812700928 DEBUG: Frame Size : 8
12502:14:51 T:140030437029952 NOTICE: Running database version Addons20
12602:14:51 T:140030437029952 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/libcpluff-x86_64-linux.so)
12702:14:51 T:140030437029952 DEBUG: Loading: /usr/lib/kodi/system/libcpluff-x86_64-linux.so
12802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.json has been installed.'
12902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.fanart.tv has been installed.'
13002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in resource.images.weathericons.default has been installed.'
13102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.audioencoder has been installed.'
13202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in plugin.audio.shoutcast has been installed.'
13302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in skin.titan.beta has been installed.'
13402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in kodi.audiodecoder has been installed.'
13502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in repository.xbmc.org has been installed.'
13602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in webinterface.default has been installed.'
13702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.thetvdb has been installed.'
13802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in weather.yahoo has been installed.'
13902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in screensaver.xbmc.builtin.black has been installed.'
14002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in kodi.guilib has been installed.'
14102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in resource.uisounds.rapier has been installed.'
14202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in plugin.video.tmz has been installed.'
14302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.t1mlib has been installed.'
14402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in audioencoder.xbmc.builtin.wma has been installed.'
14502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in kodi.adsp has been installed.'
14602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in repository.tknorris.release has been installed.'
14702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.simplejson has been installed.'
14802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.youtube.dl has been installed.'
14902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in screensaver.xbmc.builtin.dim has been installed.'
15002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.favourites has been installed.'
15102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.xmltodict has been installed.'
15202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.themoviedb.org has been installed.'
15302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.metadata has been installed.'
15402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in service.xbmc.versioncheck has been installed.'
15502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in repository.beta.emby.kodi has been installed.'
15602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in plugin.video.1channel has been installed.'
15702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in skin.confluence has been installed.'
15802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.myconnpy has been installed.'
15902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.addon.common has been installed.'
16002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.globalsearch has been installed.'
16102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in kodi.resource has been installed.'
16202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.randomandlastitems has been installed.'
16302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.image.resource.select has been installed.'
16402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.beautifulsoup has been installed.'
16502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.pil has been installed.'
16602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.gui has been installed.'
16702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.common.plugin.cache has been installed.'
16802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in service.skin.widgets has been installed.'
16902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in skin.rapier has been installed.'
17002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in plugin.video.hgtv has been installed.'
17102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.skinshortcuts has been installed.'
17202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.unidecode has been installed.'
17302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.musicvideos.theaudiodb.com has been installed.'
17402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.core has been installed.'
17502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in plugin.video.youtube has been installed.'
17602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.artistslideshow has been installed.'
17702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.requests has been installed.'
17802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.grab.fanart has been installed.'
17902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.artwork.downloader has been installed.'
18002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in plugin.video.crackler has been installed.'
18102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.pvr has been installed.'
18202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.urlresolver has been installed.'
18302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in audioencoder.xbmc.builtin.aac has been installed.'
18402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.album.universal has been installed.'
18502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.htbackdrops.com has been installed.'
18602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in resource.language.en_gb has been installed.'
18702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.musicbrainz has been installed.'
18802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.tvdb.com has been installed.'
18902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.allmusic.com has been installed.'
19002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.musicbrainz.org has been installed.'
19102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.xbmc.debug.log has been installed.'
19202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.local has been installed.'
19302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in resource.uisounds.titan.modern has been installed.'
19402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in skin.titan has been installed.'
19502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.skin.helper.service has been installed.'
19602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.webinterface has been installed.'
19702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.buggalo has been installed.'
19802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in resource.uisounds.confluence has been installed.'
19902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in resource.images.studios.white has been installed.'
20002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.themoviedb.org has been installed.'
20102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.theaudiodb.com has been installed.'
20202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.parsedom has been installed.'
20302:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.artists.universal has been installed.'
20402:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.python has been installed.'
20502:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.tv.show.next.aired has been installed.'
20602:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in metadata.common.imdb.com has been installed.'
20702:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.xbmcswift2 has been installed.'
20802:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.addon has been installed.'
20902:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in xbmc.codec has been installed.'
21002:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.addon.signals has been installed.'
21102:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Plug-in script.module.metahandler has been installed.'
21202:14:56 T:140030437029952 DEBUG: ADDON: cpluff: 'Not all directories were successfully scanned.'
21302:14:56 T:140030437029952 NOTICE: ADDONS: Using repository repository.xbmc.org
21402:14:56 T:140030437029952 NOTICE: ADDONS: Using repository repository.tknorris.release
21502:14:56 T:140030437029952 NOTICE: ADDONS: Using repository repository.beta.emby.kodi
21602:14:56 T:140029799859968 DEBUG: Thread RemoteControl start, auto delete: false
21702:14:56 T:140029799859968 INFO: LIRC Process: using: /dev/lircd
21802:14:56 T:140029799859968 INFO: LIRC Connect: successfully started
21902:14:56 T:140029799859968 DEBUG: Thread RemoteControl 140029799859968 terminating
22002:14:56 T:140030437029952 INFO: CKeyboardLayoutManager: loading keyboard layouts from special://xbmc/system/keyboardlayouts...
22102:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Hungarian QWERTZ" successfully loaded
22202:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Swedish QWERTY" successfully loaded
22302:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Romanian QWERTY" successfully loaded
22402:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Danish QWERTY" successfully loaded
22502:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Czech QWERTZ" successfully loaded
22602:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Turkish QWERTY" successfully loaded
22702:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Norwegian QWERTY" successfully loaded
22802:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Lithuanian AZERTY" successfully loaded
22902:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Lithuanian QWERTY" successfully loaded
23002:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Spanish QWERTY" successfully loaded
23102:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "French AZERTY" successfully loaded
23202:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Ukrainian ЙЦУКЕÐ" successfully loaded
23302:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Ukrainian ÐБВ" successfully loaded
23402:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Polish QWERTY" successfully loaded
23502:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Greek QWERTY" successfully loaded
23602:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Korean ㄱㄴㄷ" successfully loaded
23702:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Arabic QWERTY" successfully loaded
23802:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Russian ЙЦУКЕÐ" successfully loaded
23902:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Russian ÐБВ" successfully loaded
24002:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Hebrew QWERTY" successfully loaded
24102:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Hebrew ABC" successfully loaded
24202:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "German QWERTZ" successfully loaded
24302:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Chinese BasePY" successfully loaded
24402:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Chinese BaiduPY" successfully loaded
24502:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Bulgarian ЯВЕРТЪ" successfully loaded
24602:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Bulgarian ÐБВ" successfully loaded
24702:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "English QWERTY" successfully loaded
24802:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "English AZERTY" successfully loaded
24902:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "English ABC" successfully loaded
25002:14:56 T:140030437029952 DEBUG: CKeyboardLayoutManager: keyboard layout "Portuguese (Portugal) QWERTY" successfully loaded
25102:14:56 T:140030437029952 DEBUG: Selected UDisks as storage provider
25202:14:56 T:140030437029952 DEBUG: UDisks: DaemonVersion 1
25302:14:56 T:140030437029952 DEBUG: UDisks: Querying available devices
25402:14:56 T:140030437029952 DEBUG: UDisks: Is not able to mount DeviceUDI /org/freedesktop/UDisks/devices/sda: IsFileSystem false HasFileSystem IsSystemInternal true IsMounted false IsRemovable false IsPartition false IsOptical false
25502:14:56 T:140030437029952 DEBUG: UDisks: Is not able to mount DeviceUDI /org/freedesktop/UDisks/devices/sda1: IsFileSystem true HasFileSystem ext4 IsSystemInternal true IsMounted true IsRemovable false IsPartition true IsOptical false
25602:14:56 T:140030437029952 DEBUG: UDisks: Is not able to mount DeviceUDI /org/freedesktop/UDisks/devices/sda2: IsFileSystem false HasFileSystem IsSystemInternal true IsMounted false IsRemovable false IsPartition true IsOptical false
25702:14:56 T:140030437029952 DEBUG: UDisks: Is not able to mount DeviceUDI /org/freedesktop/UDisks/devices/sr0: IsFileSystem false HasFileSystem IsSystemInternal false IsMounted false IsRemovable true IsPartition false IsOptical false
25802:14:56 T:140030437029952 DEBUG: UDisks: Is not able to mount DeviceUDI /org/freedesktop/UDisks/devices/sda5: IsFileSystem false HasFileSystem IsSystemInternal true IsMounted false IsRemovable false IsPartition true IsOptical false
25902:14:56 T:140030437029952 NOTICE: Setup SDL
26002:14:57 T:140030437029952 INFO: Available videomodes (xrandr):
26102:14:57 T:140030437029952 INFO: Output 'HDMI-0' has 12 modes
26202:14:57 T:140030437029952 INFO: ID:0x24e Name:1280x720 Refresh:60.000000 Width:1280 Height:720
26302:14:57 T:140030437029952 INFO: Pixel Ratio: 0.999035
26402:14:57 T:140030437029952 INFO: ID:0x253 Name:1280x720 Refresh:59.943432 Width:1280 Height:720
26502:14:57 T:140030437029952 INFO: Pixel Ratio: 0.999035
26602:14:57 T:140030437029952 INFO: ID:0x24f Name:1920x1080 Refresh:59.939388 Width:1920 Height:1080
26702:14:57 T:140030437029952 INFO: Pixel Ratio: 0.999035
26802:14:57 T:140030437029952 INFO: ID:0x250 Name:1920x1080 Refresh:30.026690 Width:1920 Height:1080
26902:14:57 T:140030437029952 INFO: Pixel Ratio: 0.999035
27002:14:57 T:140030437029952 INFO: ID:0x251 Name:1920x1080 Refresh:29.998381 Width:1920 Height:1080
27102:14:57 T:140030437029952 INFO: Pixel Ratio: 0.999035
27202:14:57 T:140030437029952 INFO: ID:0x252 Name:1440x480 Refresh:30.027220 Width:1440 Height:480
27302:14:57 T:140030437029952 INFO: Pixel Ratio: 0.592021
27402:14:57 T:140030437029952 INFO: ID:0x254 Name:720x480 Refresh:59.940060 Width:720 Height:480
27502:14:57 T:140030437029952 INFO: Pixel Ratio: 1.184041
27602:14:57 T:140030437029952 INFO: ID:0x255 Name:720x480 Refresh:30.027220 Width:720 Height:480
27702:14:57 T:140030437029952 INFO: Pixel Ratio: 1.184041
27802:14:57 T:140030437029952 INFO: ID:0x256 Name:640x480 Refresh:59.928570 Width:640 Height:480
27902:14:57 T:140030437029952 INFO: Pixel Ratio: 1.332046
28002:14:57 T:140030437029952 INFO: ID:0x257 Name:480x480 Refresh:59.940060 Width:480 Height:480
28102:14:57 T:140030437029952 INFO: Pixel Ratio: 1.776062
28202:14:57 T:140030437029952 INFO: ID:0x258 Name:411x480 Refresh:59.972790 Width:411 Height:480
28302:14:57 T:140030437029952 INFO: Pixel Ratio: 2.074233
28402:14:57 T:140030437029952 INFO: ID:0x259 Name:3x480 Refresh:35.305340 Width:3 Height:480
28502:14:57 T:140030437029952 INFO: Pixel Ratio: 284.169891
28602:14:57 T:140030437029952 NOTICE: Checking resolution 16
28702:14:57 T:140030437029952 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/ImageLib-x86_64-linux.so)
28802:14:57 T:140030437029952 DEBUG: Loading: /usr/lib/kodi/system/ImageLib-x86_64-linux.so
28902:14:57 T:140030437029952 NOTICE: Using visual 0x28
29002:14:58 T:140030437029952 INFO: GL: Maximum texture width: 8192
29102:14:58 T:140030437029952 DEBUG: GLX_EXTENSIONS: GLX_EXT_visual_info GLX_EXT_visual_rating GLX_SGIX_fbconfig GLX_SGIX_pbuffer GLX_SGI_video_sync GLX_SGI_swap_control GLX_EXT_swap_control GLX_EXT_swap_control_tear GLX_EXT_texture_from_pixmap GLX_ARB_create_context GLX_ARB_create_context_profile GLX_EXT_create_context_es2_profile GLX_ARB_create_context_robustness GLX_ARB_multisample GLX_NV_float_buffer GLX_ARB_fbconfig_float GLX_EXT_framebuffer_sRGB GLX_NV_multisample_coverage GLX_ARB_get_proc_address
29202:14:58 T:140030437029952 NOTICE: GL_VENDOR = NVIDIA Corporation
29302:14:58 T:140030437029952 NOTICE: GL_RENDERER = ION/PCIe/SSE2
29402:14:58 T:140030437029952 NOTICE: GL_VERSION = 2.1.2 NVIDIA 304.132
29502:14:58 T:140030437029952 NOTICE: GL_SHADING_LANGUAGE_VERSION = 1.20 NVIDIA via Cg compiler
29602:14:58 T:140030437029952 NOTICE: GL_GPU_MEMORY_INFO_TOTAL_AVAILABLE_MEMORY_NVX = 0
29702:14:58 T:140030437029952 NOTICE: GL_GPU_MEMORY_INFO_DEDICATED_VIDMEM_NVX = 0
29802:14:58 T:140030437029952 NOTICE: GL_EXTENSIONS = GL_ARB_blend_func_extended GL_ARB_color_buffer_float GL_ARB_compatibility GL_ARB_conservative_depth GL_ARB_depth_buffer_float GL_ARB_depth_clamp GL_ARB_depth_texture GL_ARB_draw_buffers GL_ARB_explicit_attrib_location GL_ARB_fragment_coord_conventions GL_ARB_fragment_program GL_ARB_fragment_program_shadow GL_ARB_fragment_shader GL_ARB_framebuffer_object GL_ARB_framebuffer_sRGB GL_ARB_geometry_shader4 GL_ARB_half_float_pixel GL_ARB_half_float_vertex GL_ARB_imaging GL_ARB_map_buffer_alignment GL_ARB_multisample GL_ARB_multitexture GL_ARB_occlusion_query GL_ARB_point_parameters GL_ARB_point_sprite GL_ARB_provoking_vertex GL_ARB_shader_objects GL_ARB_shader_texture_lod GL_ARB_shading_language_100 GL_ARB_shading_language_420pack GL_ARB_shading_language_packing GL_ARB_shadow GL_ARB_texture_border_clamp GL_ARB_texture_compression GL_ARB_texture_compression_rgtc GL_ARB_texture_cube_map GL_ARB_texture_env_add GL_ARB_texture_env_combine GL_ARB_texture_env_crossbar GL_ARB_texture_env_dot3 GL_ARB_texture_float GL_ARB_texture_gather GL_ARB_texture_mirrored_repeat GL_ARB_texture_non_power_of_two GL_ARB_texture_rectangle GL_ARB_texture_rg GL_ARB_texture_swizzle GL_ARB_timer_query GL_ARB_transpose_matrix GL_ARB_vertex_buffer_object GL_ARB_vertex_program GL_ARB_vertex_shader GL_ARB_window_pos GL_ATI_draw_buffers GL_ATI_texture_float GL_ATI_texture_mirror_once GL_S3_s3tc GL_EXT_texture_env_add GL_EXT_abgr GL_EXT_bgra GL_EXT_blend_color GL_EXT_blend_equation_separate GL_EXT_blend_func_separate GL_EXT_blend_minmax GL_EXT_blend_subtract GL_EXT_Cg_shader GL_EXT_depth_bounds_test GL_EXT_draw_range_elements GL_EXT_fog_coord GL_EXT_framebuffer_blit GL_EXT_framebuffer_multisample GL_EXTX_framebuffer_mixed_formats GL_EXT_framebuffer_object GL_EXT_framebuffer_sRGB GL_EXT_geometry_shader4 GL_EXT_gpu_program_parameters GL_EXT_gpu_shader4 GL_EXT_multi_draw_arrays GL_EXT_packed_depth_stencil GL_EXT_packed_float GL_EXT_packed_pixels GL_EXT_point_parameters GL_EXT_provoking_vertex GL_EXT_rescale_normal GL_EXT_secondary_color GL_EXT_separate_specular_color GL_EXT_shadow_funcs GL_EXT_stencil_two_side GL_EXT_stencil_wrap GL_EXT_texture3D GL_EXT_texture_array GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_latc GL_EXT_texture_compression_rgtc GL_EXT_texture_compression_s3tc GL_EXT_texture_cube_map GL_EXT_texture_edge_clamp GL_EXT_texture_env_combine GL_EXT_texture_env_dot3 GL_EXT_texture_filter_anisotropic GL_EXT_texture_format_BGRA8888 GL_EXT_texture_lod GL_EXT_texture_lod_bias GL_EXT_texture_mirror_clamp GL_EXT_texture_object GL_EXT_texture_shared_exponent GL_EXT_texture_sRGB GL_EXT_texture_swizzle GL_EXT_texture_type_2_10_10_10_REV GL_EXT_timer_query GL_EXT_vertex_array GL_EXT_vertex_array_bgra GL_EXT_x11_sync_object GL_IBM_rasterpos_clip GL_IBM_texture_mirrored_repeat GL_KTX_buffer_region GL_NV_alpha_test GL_NV_blend_minmax GL_NV_blend_square GL_NV_complex_primitives GL_NV_copy_depth_to_color GL_NV_copy_image GL_NV_depth_buffer_float GL_NV_depth_clamp GL_NV_fbo_color_attachments GL_NV_fence GL_NV_float_buffer GL_NV_fog_distance GL_NV_fragdepth GL_NV_fragment_program GL_NV_fragment_program_option GL_NV_fragment_program2 GL_NV_framebuffer_multisample_coverage GL_NV_geometry_shader4 GL_NV_gpu_program4 GL_NV_gpu_program4_1 GL_NV_half_float GL_NV_light_max_exponent GL_NV_multisample_coverage GL_NV_multisample_filter_hint GL_NV_occlusion_query GL_NV_packed_depth_stencil GL_NV_parameter_buffer_object GL_NV_parameter_buffer_object2 GL_NV_point_sprite GL_NV_register_combiners GL_NV_register_combiners2 GL_NV_texgen_reflection GL_NV_texture_barrier GL_NV_texture_compression_vtc GL_NV_texture_env_combine4 GL_NV_texture_expand_normal GL_NV_texture_lod_clamp GL_NV_texture_rectangle GL_NV_texture_shader GL_NV_texture_shader2 GL_NV_texture_shader3 GL_NV_vertex_program GL_NV_vertex_program1_1 GL_NV_vertex_program2 GL_NV_vertex_program2_option GL_NV_vertex_program3 GL_NVX_gpu_memory_info GL_OES_compressed_paletted_texture GL_OES_depth24 GL_OES_depth32 GL_OES_depth_texture GL_OES_element_index_uint GL_OES_fbo_render_mipmap GL_OES_packed_depth_stencil GL_OES_point_sprite GL_OES_rgb8_rgba8 GL_OES_read_format GL_OES_standard_derivatives GL_OES_texture_float GL_OES_texture_float_linear GL_OES_texture_half_float GL_OES_texture_half_float_linear GL_OES_texture_npot GL_OES_vertex_half_float GL_SGIS_generate_mipmap GL_SGIS_texture_lod GL_SGIX_depth_texture GL_SGIX_shadow GL_SUN_slice_accum
29902:14:58 T:140030437029952 INFO: GL: Maximum texture width: 8192
30002:14:58 T:140030437029952 DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
30102:14:58 T:140030437029952 INFO: load keymapping
30202:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/appcommand.xml
30302:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/gamepad.xml
30402:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Alienware.Dual.Compatible.Controller.xml
30502:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.AppleRemote.xml
30602:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Harmony.xml
30702:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Interact.AxisPad.xml
30802:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Logitech.RumblePad.2.xml
30902:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.360.Controller.xml
31002:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.Controller.S.xml
31102:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Nintendo.Wii.U.Pro.Controller.xml
31202:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Ouya.Controller.xml
31302:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.PS3.Remote.Keyboard.xml
31402:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.PS4.Controller.xml
31502:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.Sony.PLAYSTATION(R)3.Controller.xml
31602:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/joystick.WiiRemote.xml
31702:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/keyboard.xml
31802:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/mouse.xml
31902:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/remote.xml
32002:14:59 T:140030437029952 INFO: Loading special://xbmc/system/keymaps/touchscreen.xml
32102:14:59 T:140030437029952 INFO: Loading special://masterprofile/keymaps/noBS.xml
32202:14:59 T:140030437029952 INFO: Loading special://profile/keymaps/noBS.xml
32302:14:59 T:140030437029952 INFO: Loading special://xbmc/system/Lircmap.xml
32402:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'mceusb'
32502:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'XboxDVDDongle'
32602:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'Microsoft_Xbox'
32702:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'PinnacleSysPCTVRemote'
32802:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'anysee'
32902:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'iMON-PAD'
33002:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'Antec_Veris_RM200'
33102:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'MCE_via_iMON'
33202:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'TwinHanRemote'
33302:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'linux-input-layer'
33402:14:59 T:140030437029952 INFO: * Linking remote mapping for 'linux-input-layer' to 'cx23885_remote'
33502:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'mediacenter'
33602:14:59 T:140030437029952 INFO: * Adding remote mapping for device 'devinput'
33702:14:59 T:140030437029952 DEBUG: CButtonTranslator::Load - no userdata Lircmap.xml found, skipping
33802:14:59 T:140030437029952 INFO: GUI format 1280x720, Display 1280x720@ 60.00 - Full Screen
33902:14:59 T:140030437029952 DEBUG: guilib: Fill viewport on change for solving rendering passes
34002:14:59 T:140030437029952 INFO: CLangInfo: loading resource.language.en_gb language information...
34102:14:59 T:140030437029952 DEBUG: trying to set locale to en_US.UTF-8
34202:14:59 T:140030437029952 INFO: global locale set to en_US.UTF-8
34302:14:59 T:140030437029952 INFO: CLangInfo: loading resource.language.en_gb language strings...
34402:14:59 T:140030437029952 DEBUG: POParser: loaded 3535 strings from file resource://resource.language.en_gb/strings.po
34502:14:59 T:140030437029952 DEBUG: LoadMappings - loaded node "Motorola Nyxboard Hybrid"
34602:14:59 T:140030437029952 DEBUG: LoadMappings - loaded node "CEC Adapter"
34702:14:59 T:140030437029952 DEBUG: LoadMappings - loaded node "Pulse-Eight CEC Adapter"
34802:14:59 T:140030437029952 DEBUG: LoadMappings - loaded node "iMON HID device"
34902:14:59 T:140030437029952 DEBUG: CPeripheralBusUSB - initialised udev monitor
35002:14:59 T:140030437029952 DEBUG: SECTION:LoadDLL(libcec.so.3.0)
35102:14:59 T:140030437029952 DEBUG: Loading: libcec.so.3.0
35202:14:59 T:140029772076800 DEBUG: Thread PeripBusCEC start, auto delete: false
35302:14:59 T:140029556946688 DEBUG: Thread PeripBusUSBUdev start, auto delete: false
35402:14:59 T:140030437029952 DEBUG: SECTION:LoadDLL(libcurl.so.4)
35502:14:59 T:140030437029952 DEBUG: Loading: libcurl.so.4
35602:15:00 T:140030437029952 NOTICE: Running database version Addons20
35702:15:00 T:140030437029952 DEBUG: Initialize, updating databases...
35802:15:00 T:140030437029952 NOTICE: Running database version ViewModes6
35902:15:00 T:140030437029952 NOTICE: Running database version Textures13
36002:15:00 T:140030437029952 NOTICE: Running database version MyMusic56
36102:15:00 T:140030437029952 NOTICE: Running database version MyVideos99
36202:15:00 T:140030437029952 NOTICE: Running database version TV29
36302:15:00 T:140030437029952 NOTICE: Running database version Epg11
36402:15:00 T:140030437029952 DEBUG: Initialize, updating databases... DONE
36502:15:00 T:140030437029952 NOTICE: start dvd mediatype detection
36602:15:00 T:140030436771584 DEBUG: Thread DetectDVDMedia start, auto delete: false
36702:15:00 T:140030436771584 DEBUG: Compiled with libcdio Version 0.83
36802:15:00 T:140030437029952 DEBUG: DPMS: supported power-saving modes: SUSPEND OFF STANDBY
36902:15:00 T:140030437029952 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
37002:15:00 T:140030437029952 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
37102:15:00 T:140030437029952 DEBUG: Activating window ID: 12997
37202:15:00 T:140030437029952 DEBUG: ------ Window Init () ------
37302:15:00 T:140030437029952 INFO: load splash image: /usr/share/kodi/media/Splash.png
37402:15:00 T:140030437029952 INFO: Unloading old skin ...
37502:15:00 T:140030437029952 INFO: load skin from: /home/jamesz/.kodi/addons/skin.titan (version: 3.6.78)
37602:15:00 T:140030437029952 INFO: load fonts for skin...
37702:15:00 T:140030437029952 INFO: Loading fonts from /home/jamesz/.kodi/addons/skin.titan/1080i/Font.xml
37802:15:00 T:140030437029952 DEBUG: POParser: loaded 679 strings from file /home/jamesz/.kodi/addons/skin.titan/language/resource.language.en_gb/strings.po
37902:15:00 T:140030437029952 INFO: Loading skin includes from /home/jamesz/.kodi/addons/skin.titan/1080i/Includes.xml
38002:15:01 T:140030437029952 INFO: load new skin...
38102:15:01 T:140030437029952 INFO: Loading user windows, path /home/jamesz/.kodi/addons/skin.titan/1080i
38202:15:01 T:140030437029952 DEBUG: Load Skin XML: 49.40ms
38302:15:01 T:140030437029952 INFO: initialize new skin...
38402:15:01 T:140030437029952 DEBUG: guilib: Fill viewport on change for solving rendering passes
38502:15:01 T:140030437029952 INFO: Loading skin file: Pointer.xml, load type: LOAD_ON_GUI_INIT
38602:15:02 T:140030437029952 DEBUG: OpenBundle - Opened bundle /home/jamesz/.kodi/addons/skin.titan/media/Textures.xbt
38702:15:02 T:140030437029952 INFO: Loading skin file: DialogVolumeBar.xml, load type: LOAD_ON_GUI_INIT
38802:15:02 T:140030437029952 INFO: Loading skin file: DialogKaiToast.xml, load type: LOAD_ON_GUI_INIT
38902:15:02 T:140030437029952 INFO: Loading skin file: DialogMuteBug.xml, load type: LOAD_ON_GUI_INIT
39002:15:02 T:140030437029952 INFO: Loading skin file: DialogSeekBar.xml, load type: LOAD_ON_GUI_INIT
39102:15:02 T:140030437029952 INFO: Loading skin file: DialogBusy.xml, load type: LOAD_ON_GUI_INIT
39202:15:02 T:140030437029952 INFO: Loading skin file: DialogExtendedProgressBar.xml, load type: LOAD_ON_GUI_INIT
39302:15:02 T:140030437029952 INFO: Loading resource://resource.uisounds.confluence/sounds.xml
39402:15:03 T:140030437029952 INFO: skin loaded...
39502:15:03 T:140030437029952 DEBUG: Activating window ID: 12997
39602:15:03 T:140030437029952 DEBUG: ------ Window Init () ------
39702:15:03 T:140030437029952 INFO: load splash image: /usr/share/kodi/media/Splash.png
39802:15:03 T:140030437029952 DEBUG: JSONRPC: JSON schema type definition references an unknown type Setting.Details.Setting
39902:15:03 T:140030437029952 WARNING: JSONRPC: Could not parse type "Setting.Details.SettingList"
40002:15:03 T:140030437029952 INFO: JSONRPC: Adding type "Setting.Details.SettingList" to list of incomplete definitions (waiting for "Setting.Details.Setting")
40102:15:03 T:140030437029952 INFO: JSONRPC: Resolving incomplete types/methods referencing Setting.Details.Setting
40202:15:03 T:140030437029952 INFO: JSONRPC v6.32.5: Successfully initialized
40302:15:03 T:140030437029952 DEBUG: ADDON: Starting service addons.
40402:15:03 T:140029510682368 DEBUG: Thread LanguageInvoker start, auto delete: false
40502:15:03 T:140029510682368 INFO: initializing python engine.
40602:15:03 T:140029502289664 DEBUG: Thread LanguageInvoker start, auto delete: false
40702:15:03 T:140029502289664 INFO: initializing python engine.
40802:15:03 T:140029280118528 DEBUG: Thread LanguageInvoker start, auto delete: false
40902:15:03 T:140029280118528 DEBUG: Previous line repeats 2 times.
41002:15:03 T:140029280118528 INFO: initializing python engine.
41102:15:03 T:140030437029952 INFO: Previous line repeats 2 times.
41202:15:03 T:140030437029952 DEBUG: Activating window ID: 12999
41302:15:03 T:140030437029952 DEBUG: ------ Window Init (Startup.xml) ------
41402:15:03 T:140030437029952 INFO: Loading skin file: Startup.xml, load type: LOAD_EVERY_TIME
41502:15:03 T:140030437029952 NOTICE: ActiveAE DSP - starting
41602:15:03 T:140030437029952 INFO: removing tempfiles
41702:15:03 T:140030437029952 DEBUG: ADDON: Starting service addons.
41802:15:03 T:140029263333120 DEBUG: Thread LanguageInvoker start, auto delete: false
41902:15:03 T:140029263333120 INFO: initializing python engine.
42002:15:03 T:140029254940416 DEBUG: Thread LanguageInvoker start, auto delete: false
42102:15:03 T:140029254940416 INFO: initializing python engine.
42202:15:03 T:140030437029952 DEBUG: CRepositoryUpdater: previous update at 12/26/2016 2:09:17 AM, next at 12/27/2016 2:09:17 AM
42302:15:03 T:140030437029952 NOTICE: initialize done
42402:15:03 T:140029246547712 DEBUG: Thread Timer start, auto delete: false
42502:15:03 T:140030437029952 NOTICE: Running the application...
42602:15:03 T:140030437029952 DEBUG: Activating window ID: 10000
42702:15:03 T:140030437029952 DEBUG: ------ Window Deinit (Startup.xml) ------
42802:15:03 T:140030437029952 DEBUG: ------ Window Init (Home.xml) ------
42902:15:03 T:140030437029952 INFO: Loading skin file: Home.xml, load type: KEEP_IN_MEMORY
43002:15:04 T:140030437029952 DEBUG: POParser: loaded 197 strings from file /home/jamesz/.kodi/addons/script.skin.helper.service/resources/language/resource.language.en_gb/strings.po
43102:15:04 T:140029510682368 DEBUG: Previous line repeats 5 times.
43202:15:04 T:140029510682368 DEBUG: CPythonInvoker(0, /home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py): start processing
43302:15:04 T:140029288511232 DEBUG: CPythonInvoker(2, /home/jamesz/.kodi/addons/script.grab.fanart/service.py): start processing
43402:15:04 T:140029263333120 DEBUG: CPythonInvoker(5, /home/jamesz/.kodi/addons/plugin.video.1channel/service.py): start processing
43502:15:04 T:140029502289664 DEBUG: CPythonInvoker(1, /home/jamesz/.kodi/addons/service.skin.widgets/default.py): start processing
43602:15:04 T:140029280118528 DEBUG: CPythonInvoker(3, /home/jamesz/.kodi/addons/script.skin.helper.service/service.py): start processing
43702:15:04 T:140029254940416 DEBUG: CPythonInvoker(6, /home/jamesz/.kodi/addons/script.common.plugin.cache/default.py): start processing
43802:15:04 T:140029271725824 DEBUG: CPythonInvoker(4, /home/jamesz/.kodi/addons/script.tv.show.next.aired/service.py): start processing
43902:15:04 T:140030437029952 WARNING: Trying to add unsupported control type 1
44002:15:04 T:140030437029952 WARNING: Previous line repeats 1 times.
44102:15:04 T:140030437029952 DEBUG: POParser: loaded 197 strings from file /home/jamesz/.kodi/addons/script.skin.helper.service/resources/language/resource.language.en_gb/strings.po
44202:15:04 T:140030437029952 DEBUG: Previous line repeats 6 times.
44302:15:04 T:140030437029952 WARNING: Trying to add unsupported control type 1
44402:15:04 T:140030437029952 WARNING: Previous line repeats 2 times.
44502:15:04 T:140030437029952 DEBUG: POParser: loaded 197 strings from file /home/jamesz/.kodi/addons/script.skin.helper.service/resources/language/resource.language.en_gb/strings.po
44602:15:04 T:140029510682368 DEBUG: Previous line repeats 5 times.
44702:15:04 T:140029510682368 DEBUG: -->Python Interpreter Initialized<--
44802:15:04 T:140029510682368 DEBUG: CPythonInvoker(0, /home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py): the source file to load is "/home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py"
44902:15:05 T:140029263333120 DEBUG: -->Python Interpreter Initialized<--
45002:15:05 T:140029263333120 DEBUG: CPythonInvoker(5, /home/jamesz/.kodi/addons/plugin.video.1channel/service.py): the source file to load is "/home/jamesz/.kodi/addons/plugin.video.1channel/service.py"
45102:15:05 T:140029510682368 DEBUG: CPythonInvoker(0, /home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py): setting the Python path to /home/jamesz/.kodi/addons/service.xbmc.versioncheck:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
45202:15:05 T:140029510682368 DEBUG: CPythonInvoker(0, /home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py): entering source directory /home/jamesz/.kodi/addons/service.xbmc.versioncheck
45302:15:05 T:140029510682368 DEBUG: CPythonInvoker(0, /home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py): instantiating addon using automatically obtained id of "service.xbmc.versioncheck" dependent on version 2.1.0 of the xbmc.python api
45402:15:05 T:140029288511232 DEBUG: -->Python Interpreter Initialized<--
45502:15:05 T:140029288511232 DEBUG: CPythonInvoker(2, /home/jamesz/.kodi/addons/script.grab.fanart/service.py): the source file to load is "/home/jamesz/.kodi/addons/script.grab.fanart/service.py"
45602:15:05 T:140029271725824 DEBUG: -->Python Interpreter Initialized<--
45702:15:05 T:140029271725824 DEBUG: CPythonInvoker(4, /home/jamesz/.kodi/addons/script.tv.show.next.aired/service.py): the source file to load is "/home/jamesz/.kodi/addons/script.tv.show.next.aired/service.py"
45802:15:05 T:140029263333120 DEBUG: CPythonInvoker(5, /home/jamesz/.kodi/addons/plugin.video.1channel/service.py): setting the Python path to /home/jamesz/.kodi/addons/plugin.video.1channel:/home/jamesz/.kodi/addons/script.module.addon.common/lib:/home/jamesz/.kodi/addons/script.module.metahandler/lib:/home/jamesz/.kodi/addons/script.module.myconnpy/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/home/jamesz/.kodi/addons/script.module.urlresolver/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
45902:15:05 T:140029263333120 DEBUG: CPythonInvoker(5, /home/jamesz/.kodi/addons/plugin.video.1channel/service.py): entering source directory /home/jamesz/.kodi/addons/plugin.video.1channel
46002:15:05 T:140029254940416 DEBUG: -->Python Interpreter Initialized<--
46102:15:05 T:140029254940416 DEBUG: CPythonInvoker(6, /home/jamesz/.kodi/addons/script.common.plugin.cache/default.py): the source file to load is "/home/jamesz/.kodi/addons/script.common.plugin.cache/default.py"
46202:15:05 T:140029254940416 DEBUG: CPythonInvoker(6, /home/jamesz/.kodi/addons/script.common.plugin.cache/default.py): setting the Python path to /home/jamesz/.kodi/addons/script.common.plugin.cache:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
46302:15:05 T:140029254940416 DEBUG: CPythonInvoker(6, /home/jamesz/.kodi/addons/script.common.plugin.cache/default.py): entering source directory /home/jamesz/.kodi/addons/script.common.plugin.cache
46402:15:05 T:140029263333120 DEBUG: CPythonInvoker(5, /home/jamesz/.kodi/addons/plugin.video.1channel/service.py): instantiating addon using automatically obtained id of "plugin.video.1channel" dependent on version 2.1.0 of the xbmc.python api
46502:15:05 T:140029254940416 DEBUG: CPythonInvoker(6, /home/jamesz/.kodi/addons/script.common.plugin.cache/default.py): instantiating addon using automatically obtained id of "script.common.plugin.cache" dependent on version 2.24.0 of the xbmc.python api
46602:15:05 T:140029271725824 DEBUG: CPythonInvoker(4, /home/jamesz/.kodi/addons/script.tv.show.next.aired/service.py): setting the Python path to /home/jamesz/.kodi/addons/script.tv.show.next.aired:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
46702:15:05 T:140029271725824 DEBUG: CPythonInvoker(4, /home/jamesz/.kodi/addons/script.tv.show.next.aired/service.py): entering source directory /home/jamesz/.kodi/addons/script.tv.show.next.aired
46802:15:05 T:140029288511232 DEBUG: CPythonInvoker(2, /home/jamesz/.kodi/addons/script.grab.fanart/service.py): setting the Python path to /home/jamesz/.kodi/addons/script.grab.fanart:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
46902:15:05 T:140029288511232 DEBUG: CPythonInvoker(2, /home/jamesz/.kodi/addons/script.grab.fanart/service.py): entering source directory /home/jamesz/.kodi/addons/script.grab.fanart
47002:15:05 T:140029271725824 DEBUG: CPythonInvoker(4, /home/jamesz/.kodi/addons/script.tv.show.next.aired/service.py): instantiating addon using automatically obtained id of "script.tv.show.next.aired" dependent on version 2.1.0 of the xbmc.python api
47102:15:05 T:140029288511232 DEBUG: CPythonInvoker(2, /home/jamesz/.kodi/addons/script.grab.fanart/service.py): instantiating addon using automatically obtained id of "script.grab.fanart" dependent on version 2.19.0 of the xbmc.python api
47202:15:05 T:140029502289664 DEBUG: -->Python Interpreter Initialized<--
47302:15:05 T:140029502289664 DEBUG: CPythonInvoker(1, /home/jamesz/.kodi/addons/service.skin.widgets/default.py): the source file to load is "/home/jamesz/.kodi/addons/service.skin.widgets/default.py"
47402:15:06 T:140030437029952 WARNING: Trying to add unsupported control type 1
47502:15:07 T:140029271725824 WARNING: Previous line repeats 9 times.
47602:15:07 T:140029271725824 DEBUG: POParser: loaded 43 strings from file /home/jamesz/.kodi/addons/script.tv.show.next.aired/resources/language/English/strings.po
47702:15:07 T:140030437029952 WARNING: Trying to add unsupported control type 1
47802:15:07 T:140029502289664 WARNING: Previous line repeats 2 times.
47902:15:07 T:140029502289664 DEBUG: CPythonInvoker(1, /home/jamesz/.kodi/addons/service.skin.widgets/default.py): setting the Python path to /home/jamesz/.kodi/addons/service.skin.widgets:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
48002:15:07 T:140029502289664 DEBUG: CPythonInvoker(1, /home/jamesz/.kodi/addons/service.skin.widgets/default.py): entering source directory /home/jamesz/.kodi/addons/service.skin.widgets
48102:15:07 T:140029502289664 DEBUG: CPythonInvoker(1, /home/jamesz/.kodi/addons/service.skin.widgets/default.py): instantiating addon using automatically obtained id of "service.skin.widgets" dependent on version 2.14.0 of the xbmc.python api
48202:15:07 T:140029510682368 DEBUG: Version Check: Version 0.3.20 started
48302:15:07 T:140028747323136 DEBUG: Thread JobWorker start, auto delete: true
48402:15:07 T:140028747323136 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','1','?action=INPROGRESSANDRECOMMENDEDMOVIES&reload=')
48502:15:07 T:140028747323136 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=7) plugin...
48602:15:07 T:140028738930432 DEBUG: Thread LanguageInvoker start, auto delete: false
48702:15:07 T:140028738930432 INFO: initializing python engine.
48802:15:07 T:140028738930432 DEBUG: CPythonInvoker(7, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
48902:15:08 T:140028730537728 DEBUG: Thread JobWorker start, auto delete: true
49002:15:08 T:140028730537728 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','2','?action=nextepisodes&reload=')
49102:15:08 T:140028730537728 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=8) plugin...
49202:15:08 T:140028722145024 DEBUG: Thread LanguageInvoker start, auto delete: false
49302:15:08 T:140028722145024 INFO: initializing python engine.
49402:15:08 T:140028722145024 DEBUG: CPythonInvoker(8, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
49502:15:08 T:140028713752320 DEBUG: Thread LanguageInvoker start, auto delete: false
49602:15:08 T:140028713752320 INFO: initializing python engine.
49702:15:08 T:140028713752320 DEBUG: CPythonInvoker(9, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): start processing
49802:15:08 T:140030437029952 DEBUG: no profile autoexec.py (/home/jamesz/.kodi/userdata/autoexec.py) found, skipping
49902:15:08 T:140030437029952 DEBUG: NetworkMessage - Starting network services
50002:15:08 T:140030437029952 DEBUG: CZeroconfAvahi::clientCallback: client is up and running
50102:15:08 T:140030437029952 NOTICE: starting zeroconf publishing
50202:15:08 T:140028696966912 DEBUG: Thread JobWorker start, auto delete: true
50302:15:08 T:140030437029952 NOTICE: WebServer: Started the webserver
50402:15:08 T:140030437029952 NOTICE: starting upnp client
50502:15:08 T:140028696966912 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','3','?action=recentalbums&limit=25&reload=')
50602:15:08 T:140028696966912 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=10) plugin...
50702:15:08 T:140028332201728 DEBUG: Thread LanguageInvoker start, auto delete: false
50802:15:08 T:140028332201728 INFO: initializing python engine.
50902:15:08 T:140028332201728 DEBUG: CPythonInvoker(10, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
51002:15:08 T:140029271725824 DEBUG: script.tv.show.next.aired: ### params: {'service': 'true'}
51102:15:08 T:140029271725824 NOTICE: script.tv.show.next.aired: ### TV Show - Next Aired starting background proc (6.0.15)
51202:15:08 T:140030437029952 NOTICE: starting upnp server
51302:15:08 T:140030437029952 NOTICE: starting upnp controller
51402:15:08 T:140030437029952 NOTICE: starting upnp renderer
51502:15:08 T:140027979872000 DEBUG: Thread EventServer start, auto delete: false
51602:15:08 T:140027979872000 NOTICE: ES: Starting UDP Event server on 0.0.0.0:9777
51702:15:08 T:140027979872000 NOTICE: UDP: Listening on port 9777
51802:15:08 T:140030437029952 INFO: JSONRPC Server: Successfully initialized
51902:15:08 T:140027971479296 DEBUG: Thread TCPServer start, auto delete: false
52002:15:08 T:140030437029952 DEBUG: UPower: Received an unknown signal NameAcquired
52102:15:08 T:140027963086592 DEBUG: Thread JobWorker start, auto delete: true
52202:15:08 T:140030437029952 DEBUG: ------ Window Init () ------
52302:15:08 T:140027963086592 DEBUG: DoWork - took 259 ms to load special://skin/extras/backgrounds/global_blue.jpg
52402:15:08 T:140027543680768 DEBUG: Thread AlarmClock start, auto delete: false
52502:15:08 T:140030437029952 DEBUG: started alarm with name: widgetrotate510
52602:15:08 T:140030437029952 DEBUG: started alarm with name: widgetrotate520
52702:15:08 T:140029263333120 NOTICE: 1Channel: Service: Installed Version: 2.5.72
52802:15:08 T:140029280118528 DEBUG: -->Python Interpreter Initialized<--
52902:15:08 T:140029280118528 DEBUG: CPythonInvoker(3, /home/jamesz/.kodi/addons/script.skin.helper.service/service.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/service.py"
53002:15:09 T:140027963086592 DEBUG: DoWork - took 235 ms to load special://masterprofile/Thumbnails/d/d2047bf9.dds
53102:15:09 T:140027963086592 DEBUG: DoWork - took 184 ms to load special://masterprofile/Thumbnails/c/c1dd5d08.dds
53202:15:09 T:140027963086592 DEBUG: DoWork - took 117 ms to load special://masterprofile/Thumbnails/1/1fdbd04f.jpg
53302:15:09 T:140029280118528 DEBUG: CPythonInvoker(3, /home/jamesz/.kodi/addons/script.skin.helper.service/service.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
53402:15:09 T:140029280118528 DEBUG: CPythonInvoker(3, /home/jamesz/.kodi/addons/script.skin.helper.service/service.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
53502:15:09 T:140029280118528 DEBUG: CPythonInvoker(3, /home/jamesz/.kodi/addons/script.skin.helper.service/service.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
53602:15:10 T:140029271725824 DEBUG: RunQuery took 550 ms for 66 items query: SELECT * FROM tvshow_view
53702:15:10 T:140029263333120 NOTICE: 1Channel: Loading sqlite3 as DB engine
53802:15:10 T:140029263333120 DEBUG: 1Channel: Running: SELECT value FROM db_info WHERE setting="version" with []
53902:15:10 T:140029263333120 DEBUG: 1Channel: Building PrimeWire Database
54002:15:10 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS seasons (season UNIQUE, contents) with []
54102:15:10 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS favorites (type, name, url, year) with []
54202:15:10 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS subscriptions (url, title, img, year, imdbnum, days VARCHAR(7)) with []
54302:15:10 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS url_cache (url UNIQUE, response, timestamp) with []
54402:15:10 T:140029288511232 NOTICE: script.grab.fanart: Grab Fanart Service Started
54502:15:10 T:140029288511232 DEBUG: script.grab.fanart: media type is: random
54602:15:10 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS db_info (setting TEXT, value TEXT) with []
54702:15:11 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS new_bkmark (url TEXT PRIMARY KEY NOT NULL, resumepoint DOUBLE NOT NULL) with []
54802:15:11 T:140029263333120 DEBUG: 1Channel: Running: CREATE TABLE IF NOT EXISTS external_subs (type INTEGER NOT NULL, url TEXT NOT NULL, imdbnum TEXT, days VARCHAR(7), PRIMARY KEY (type, url)) with []
54902:15:11 T:140029263333120 DEBUG: 1Channel: Running: CREATE UNIQUE INDEX IF NOT EXISTS unique_fav ON favorites (url) with []
55002:15:11 T:140029288511232 DEBUG: RunQuery took 368 ms for 1116 items query: select * from movie_view
55102:15:11 T:140029263333120 DEBUG: 1Channel: Running: CREATE UNIQUE INDEX IF NOT EXISTS unique_sub ON subscriptions (url) with []
55202:15:11 T:140029263333120 DEBUG: 1Channel: Running: CREATE UNIQUE INDEX IF NOT EXISTS unique_url ON url_cache (url) with []
55302:15:11 T:140029263333120 DEBUG: 1Channel: Running: CREATE UNIQUE INDEX IF NOT EXISTS unique_db_info ON db_info (setting) with []
55402:15:11 T:140029263333120 DEBUG: 1Channel: Running: INSERT OR REPLACE INTO db_info (setting, value) VALUES(?,?) with ('version', '2.5.72')
55502:15:11 T:140027409463040 DEBUG: CPlayerCoreConfig::<ctor>: created player VSX-1122 for core 5
55602:15:11 T:140029263333120 NOTICE: 1Channel: Service: Resetting...
55702:15:11 T:140029263333120 NOTICE: 1Channel: Service: starting...
55802:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1/
55902:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/4/
56002:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/5/
56102:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/6/
56202:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/100/
56302:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/107/
56402:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/108/
56502:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/7/
56602:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/101/
56702:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/102/
56802:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/103/
56902:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/104/
57002:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/105/
57102:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/106/
57202:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/F/
57302:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/14/
57402:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/2/
57502:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/8/
57602:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/9/
57702:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/A/
57802:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/E/
57902:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/200/
58002:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/201/
58102:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/202/
58202:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/203/
58302:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/204/
58402:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/205/
58502:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/10/
58602:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/15/
58702:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/3/
58802:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/B/
58902:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/C/
59002:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/D/
59102:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/D2/
59202:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/300/
59302:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/306/
59402:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/301/
59502:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/302/
59602:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/303/
59702:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/304/
59802:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/305/
59902:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/11/
60002:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/16/
60102:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/18/
60202:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/19/
60302:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1A/
60402:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1B/
60502:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1C/
60602:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1D/
60702:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1E/
60802:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/400/
60902:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/401/
61002:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/402/
61102:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/403/
61202:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/404/
61302:15:11 T:140027359106816 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/405/
61402:15:12 T:140029254940416 DEBUG: StorageServer Module loaded RUN
61502:15:12 T:140029254940416 DEBUG: StorageClient-2.5.4 Starting server
61602:15:12 T:140029502289664 DEBUG: Skin Widgets: script version 0.0.33 started
61702:15:12 T:140029502289664 DEBUG: RunQuery took 30 ms for 97 items query: select * from movie_view WHERE ((movie_view.playCount IS NULL OR movie_view.playCount < 1))
61802:15:13 T:140029288511232 DEBUG: script.grab.fanart: found 1115 movies files
61902:15:13 T:140029288511232 DEBUG: RunQuery took 61 ms for 66 items query: SELECT * FROM tvshow_view
62002:15:13 T:140029288511232 DEBUG: script.grab.fanart: found 65 tv files
62102:15:13 T:140029288511232 DEBUG: GetArtistsByWhere query: SELECT artistview.* FROM artistview WHERE (artistview.idArtist IN (SELECT song_artist.idArtist FROM song_artist) OR artistview.idArtist IN (SELECT album_artist.idArtist FROM album_artist)) and artistview.strArtist != '' and artistview.strArtist <> 'Various artists'
62202:15:15 T:140028713752320 DEBUG: -->Python Interpreter Initialized<--
62302:15:15 T:140028713752320 DEBUG: CPythonInvoker(9, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): the source file to load is "/home/jamesz/.kodi/addons/script.skinshortcuts/default.py"
62402:15:15 T:140028332201728 DEBUG: -->Python Interpreter Initialized<--
62502:15:15 T:140028332201728 DEBUG: CPythonInvoker(10, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
62602:15:16 T:140028713752320 DEBUG: CPythonInvoker(9, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): setting the Python path to /home/jamesz/.kodi/addons/script.skinshortcuts:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/home/jamesz/.kodi/addons/script.module.unidecode/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
62702:15:16 T:140028713752320 DEBUG: CPythonInvoker(9, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): entering source directory /home/jamesz/.kodi/addons/script.skinshortcuts
62802:15:16 T:140029280118528 NOTICE: Skin Helper Service --> skin helper service version 1.0.100 started
62902:15:16 T:140028713752320 DEBUG: CPythonInvoker(9, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): instantiating addon using automatically obtained id of "script.skinshortcuts" dependent on version 2.20.0 of the xbmc.python api
63002:15:16 T:140029280118528 NOTICE: Skin Helper Service --> WebService - start helper webservice on port 52307
63102:15:16 T:140028738930432 DEBUG: -->Python Interpreter Initialized<--
63202:15:16 T:140028738930432 DEBUG: CPythonInvoker(7, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
63302:15:16 T:140029510682368 DEBUG: Version Check: Version installed {u'major': 16, u'tag': u'stable', u'minor': 1, u'revision': u'c327c53'}
63402:15:16 T:140029510682368 DEBUG: Version Check: Version available {u'major': u'16', u'extrainfo': u'final', u'tagversion': u'', u'tag': u'stable', u'addon_support': u'yes', u'minor': u'1', u'revision': u'20160424-c327c53'}
63502:15:16 T:140029510682368 DEBUG: Version Check: There is no newer stable available
63602:15:16 T:140029510682368 INFO: CPythonInvoker(0, /home/jamesz/.kodi/addons/service.xbmc.versioncheck/service.py): script successfully run
63702:15:16 T:140028332201728 DEBUG: CPythonInvoker(10, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
63802:15:16 T:140028332201728 DEBUG: CPythonInvoker(10, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
63902:15:16 T:140028332201728 DEBUG: CPythonInvoker(10, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
64002:15:16 T:140028738930432 DEBUG: CPythonInvoker(7, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
64102:15:16 T:140028738930432 DEBUG: CPythonInvoker(7, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
64202:15:16 T:140028738930432 DEBUG: CPythonInvoker(7, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
64302:15:16 T:140029510682368 INFO: Python script stopped
64402:15:16 T:140029510682368 DEBUG: Thread LanguageInvoker 140029510682368 terminating
64502:15:18 T:140029288511232 DEBUG: Time to retrieve artists from dataset = 4806
64602:15:19 T:140029288511232 DEBUG: script.grab.fanart: found 573 music files
64702:15:19 T:140027367499520 DEBUG: Testing Existence (multipath://special%3a%2f%2fprofile%2fplaylists%2fvideo/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
64802:15:19 T:140027367499520 DEBUG: Testing Existence (special://profile/playlists/video)
64902:15:19 T:140027367499520 DEBUG: CMultiPathDirectory::GetDirectory(multipath://special%3a%2f%2fprofile%2fplaylists%2fvideo/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
65002:15:19 T:140027367499520 DEBUG: Getting Directory (special://profile/playlists/video)
65102:15:19 T:140027367499520 DEBUG: Getting Directory (special://profile/playlists/mixed)
65202:15:19 T:140027367499520 DEBUG: CMultiPathDirectory::MergeItems, items = 0
65302:15:20 T:140027367499520 DEBUG: Testing Existence (multipath://special%3a%2f%2fprofile%2fplaylists%2fmusic/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
65402:15:20 T:140027367499520 DEBUG: Testing Existence (special://profile/playlists/music)
65502:15:20 T:140027367499520 DEBUG: CMultiPathDirectory::GetDirectory(multipath://special%3a%2f%2fprofile%2fplaylists%2fmusic/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
65602:15:20 T:140027367499520 DEBUG: Getting Directory (special://profile/playlists/music)
65702:15:20 T:140027367499520 DEBUG: Getting Directory (special://profile/playlists/mixed)
65802:15:20 T:140027367499520 DEBUG: CMultiPathDirectory::MergeItems, items = 0
65902:15:21 T:140027367499520 DEBUG: RunQuery took 75 ms for 1116 items query: select * from movie_view
66002:15:21 T:140027367499520 DEBUG: RunQuery took 11 ms for 67 items query: select * from movie_view WHERE (movie_view.idFile IN (SELECT DISTINCT idFile FROM bookmark WHERE type = 1))
66102:15:21 T:140027367499520 DEBUG: RunQuery took 78 ms for 25 items query: select * from movie_view ORDER BY dateAdded desc, idMovie desc LIMIT 25
66202:15:21 T:140027367499520 DEBUG: RunQuery took 14 ms for 97 items query: select * from movie_view WHERE ((CAST(movie_view.playCount as DECIMAL(5,1)) = 0 OR movie_view.playCount IS NULL))
66302:15:22 T:140027367499520 DEBUG: RunQuery took 70 ms for 66 items query: SELECT * FROM tvshow_view
66402:15:22 T:140028332201728 DEBUG: GetRecentlyAddedAlbums query: SELECT albumview.*, albumartistview.* FROM (SELECT idAlbum FROM album WHERE strAlbum != '' ORDER BY idAlbum DESC LIMIT 25) AS recentalbums JOIN albumview ON albumview.idAlbum = recentalbums.idAlbum LEFT JOIN albumartistview ON albumview.idAlbum = albumartistview.idAlbum ORDER BY albumview.idAlbum desc, albumartistview.iOrder
66502:15:22 T:140028722145024 DEBUG: -->Python Interpreter Initialized<--
66602:15:22 T:140028722145024 DEBUG: CPythonInvoker(8, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
66702:15:22 T:140028722145024 DEBUG: CPythonInvoker(8, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
66802:15:22 T:140028722145024 DEBUG: CPythonInvoker(8, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
66902:15:22 T:140028722145024 DEBUG: CPythonInvoker(8, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
67002:15:23 T:140028738930432 DEBUG: RunQuery took 22 ms for 67 items query: select * from movie_view WHERE (movie_view.idFile IN (SELECT DISTINCT idFile FROM bookmark WHERE type = 1))
67102:15:23 T:140027367499520 DEBUG: RunQuery took 164 ms for 22 items query: SELECT * FROM tvshow_view WHERE ( ((tvshow_view.watchedcount > 0 AND tvshow_view.watchedcount < tvshow_view.totalCount) OR (tvshow_view.watchedcount = 0 AND EXISTS (SELECT 1 FROM episode_view WHERE episode_view.idShow = tvshow_view.idShow AND episode_view.resumeTimeInSeconds > 0))))
67202:15:23 T:140027367499520 DEBUG: RunQuery took 332 ms for 25 items query: select * from episode_view ORDER BY dateAdded desc, idEpisode desc LIMIT 25
67302:15:24 T:140027367499520 DEBUG: GetArtistsByWhere query: SELECT artistview.* FROM artistview WHERE (artistview.idArtist IN (SELECT song_artist.idArtist FROM song_artist) OR artistview.idArtist IN (SELECT album_artist.idArtist FROM album_artist)) and artistview.strArtist != '' and artistview.strArtist <> 'Various artists'
67402:15:25 T:140027367499520 DEBUG: Time to retrieve artists from dataset = 352
67502:15:25 T:140029280118528 DEBUG: POParser: loaded 197 strings from file /home/jamesz/.kodi/addons/script.skin.helper.service/resources/language/resource.language.en_gb/strings.po
67602:15:25 T:140027241674496 DEBUG: Previous line repeats 5 times.
67702:15:25 T:140027241674496 DEBUG: CFavourites::Load - no system favourites found, skipping
67802:15:25 T:140027241674496 DEBUG: RunQuery took 14 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet ORDER BY sets.idSet
67902:15:26 T:140027241674496 DEBUG: RunQuery took 10 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet WHERE sets.idSet=1 ORDER BY sets.idSet
68002:15:26 T:140027241674496 DEBUG: RunQuery took 4 ms for 12 items query: select * from movie_view WHERE movie_view.idSet = 1
68102:15:26 T:140028738930432 DEBUG: RunQuery took 14 ms for 35 items query: select * from movie_view WHERE ((movie_view.playCount IS NULL OR movie_view.playCount = 0)) AND ((CAST(movie_view.c05 as DECIMAL(5,1)) > 7))
68202:15:28 T:140028722145024 DEBUG: RunQuery took 124 ms for 22 items query: SELECT * FROM tvshow_view WHERE ( ((tvshow_view.watchedcount > 0 AND tvshow_view.watchedcount < tvshow_view.totalCount) OR (tvshow_view.watchedcount = 0 AND EXISTS (SELECT 1 FROM episode_view WHERE episode_view.idShow = tvshow_view.idShow AND episode_view.resumeTimeInSeconds > 0))))
68302:15:29 T:140027224889088 DEBUG: RunQuery took 6 ms for 74 items query: select * from episode_view WHERE (episode_view.idShow = 53) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
68402:15:29 T:140027224889088 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
68502:15:29 T:140027233281792 DEBUG: RunQuery took 7 ms for 85 items query: select * from episode_view WHERE (episode_view.idShow = 46) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
68602:15:29 T:140027233281792 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
68702:15:29 T:140027216496384 DEBUG: RunQuery took 3 ms for 9 items query: select * from episode_view WHERE (episode_view.idShow = 74) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
68802:15:29 T:140027216496384 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
68902:15:29 T:140027208103680 DEBUG: RunQuery took 5 ms for 16 items query: select * from episode_view WHERE (episode_view.idShow = 19) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
69002:15:29 T:140027208103680 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
69102:15:29 T:140027224889088 DEBUG: RunQuery took 7 ms for 2 items query: select * from episode_view WHERE (episode_view.idShow = 37) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
69202:15:29 T:140027224889088 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
69302:15:29 T:140027233281792 DEBUG: RunQuery took 4 ms for 18 items query: select * from episode_view WHERE (episode_view.idShow = 60) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
69402:15:29 T:140027233281792 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
69502:15:30 T:140029502289664 DEBUG: RunQuery took 327 ms for 5060 items query: select * from episode_view WHERE ((episode_view.playCount IS NULL OR episode_view.playCount < 1))
69602:15:30 T:140027208103680 DEBUG: RunQuery took 6 ms for 79 items query: select * from episode_view WHERE (episode_view.idShow = 62) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
69702:15:30 T:140027208103680 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
69802:15:30 T:140027216496384 DEBUG: RunQuery took 18 ms for 161 items query: select * from episode_view WHERE (episode_view.idShow = 25) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
69902:15:30 T:140027216496384 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
70002:15:30 T:140027233281792 DEBUG: RunQuery took 30 ms for 284 items query: select * from episode_view WHERE (episode_view.idShow = 7) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
70102:15:30 T:140027233281792 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
70202:15:30 T:140028747323136 DEBUG: WaitOnScriptResult- plugin returned successfully
70302:15:30 T:140028738930432 INFO: CPythonInvoker(7, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
70402:15:30 T:140028738930432 INFO: Python script stopped
70502:15:30 T:140028738930432 DEBUG: Thread LanguageInvoker 140028738930432 terminating
70602:15:30 T:140028747323136 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','4','?action=recentmovies&reload=')
70702:15:30 T:140028747323136 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=11) plugin...
70802:15:30 T:140028738930432 DEBUG: Thread LanguageInvoker start, auto delete: false
70902:15:30 T:140028738930432 INFO: initializing python engine.
71002:15:30 T:140028738930432 DEBUG: CPythonInvoker(11, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
71102:15:31 T:140027963086592 DEBUG: DoWork - took 215 ms to load special://masterprofile/Thumbnails/3/3820f6d0.jpg
71202:15:31 T:140027963086592 DEBUG: GetImageHash - unable to stat url /media/XBMC 3/Batman Begins/logo.png
71302:15:31 T:140027208103680 DEBUG: RunQuery took 30 ms for 169 items query: select * from episode_view WHERE (episode_view.idShow = 65) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
71402:15:31 T:140027208103680 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
71502:15:31 T:140027216496384 DEBUG: RunQuery took 63 ms for 230 items query: select * from episode_view WHERE (episode_view.idShow = 21) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
71602:15:31 T:140027216496384 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
71702:15:31 T:140027233281792 DEBUG: RunQuery took 6 ms for 93 items query: select * from episode_view WHERE (episode_view.idShow = 17) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
71802:15:31 T:140027233281792 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
71902:15:31 T:140027208103680 DEBUG: RunQuery took 20 ms for 179 items query: select * from episode_view WHERE (episode_view.idShow = 40) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
72002:15:31 T:140027208103680 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
72102:15:31 T:140027216496384 DEBUG: RunQuery took 8 ms for 3 items query: select * from episode_view WHERE (episode_view.idShow = 71) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
72202:15:31 T:140027216496384 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
72302:15:31 T:140027963086592 DEBUG: DoWork - took 380 ms to load special://masterprofile/Thumbnails/a/ae1a95bf.dds
72402:15:31 T:140027233281792 DEBUG: RunQuery took 12 ms for 100 items query: select * from episode_view WHERE (episode_view.idShow = 36) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
72502:15:31 T:140027233281792 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
72602:15:32 T:140027963086592 DEBUG: DoWork - took 152 ms to load special://masterprofile/Thumbnails/6/670c8d05.dds
72702:15:32 T:140028738930432 DEBUG: -->Python Interpreter Initialized<--
72802:15:32 T:140028738930432 DEBUG: CPythonInvoker(11, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
72902:15:32 T:140028738930432 DEBUG: CPythonInvoker(11, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
73002:15:32 T:140028738930432 DEBUG: CPythonInvoker(11, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
73102:15:32 T:140028738930432 DEBUG: CPythonInvoker(11, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
73202:15:32 T:140027963086592 DEBUG: DoWork - took 242 ms to load special://masterprofile/Thumbnails/5/506a286d.dds
73302:15:32 T:140027224889088 DEBUG: RunQuery took 10 ms for 92 items query: select * from episode_view WHERE (episode_view.idShow = 47) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
73402:15:32 T:140027224889088 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
73502:15:32 T:140027233281792 DEBUG: RunQuery took 8 ms for 6 items query: select * from episode_view WHERE (episode_view.idShow = 68) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
73602:15:32 T:140027233281792 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
73702:15:32 T:140027216496384 DEBUG: RunQuery took 12 ms for 67 items query: select * from episode_view WHERE (episode_view.idShow = 22) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
73802:15:32 T:140027216496384 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
73902:15:32 T:140028713752320 INFO: CPythonInvoker(9, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): script successfully run
74002:15:32 T:140027963086592 DEBUG: DoWork - took 218 ms to load special://masterprofile/Thumbnails/d/d0033ed9.dds
74102:15:33 T:140027208103680 DEBUG: RunQuery took 13 ms for 94 items query: select * from episode_view WHERE (episode_view.idShow = 55) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
74202:15:33 T:140027208103680 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
74302:15:33 T:140027224889088 DEBUG: RunQuery took 17 ms for 209 items query: select * from episode_view WHERE (episode_view.idShow = 26) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
74402:15:33 T:140027224889088 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
74502:15:33 T:140027208103680 DEBUG: RunQuery took 13 ms for 94 items query: select * from episode_view WHERE (episode_view.idShow = 41) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
74602:15:33 T:140027208103680 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
74702:15:33 T:140027216496384 DEBUG: RunQuery took 59 ms for 273 items query: select * from episode_view WHERE (episode_view.idShow = 61) AND (((episode_view.playCount IS NULL OR episode_view.playCount < 1)) AND ((CAST(episode_view.c12 as DECIMAL(5,1)) > 0)))
74802:15:33 T:140027216496384 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
74902:15:40 T:140028730537728 DEBUG: WaitOnScriptResult- plugin returned successfully
75002:15:40 T:140028722145024 INFO: CPythonInvoker(8, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
75102:15:40 T:140028730537728 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','5','?action=recentepisodes&reload=')
75202:15:40 T:140028730537728 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=12) plugin...
75302:15:40 T:140027233281792 DEBUG: Thread LanguageInvoker start, auto delete: false
75402:15:40 T:140027233281792 INFO: initializing python engine.
75502:15:40 T:140027233281792 DEBUG: CPythonInvoker(12, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
75602:15:41 T:140030437029952 DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-x86_64-linux.so)
75702:15:43 T:140028713752320 INFO: Python script stopped
75802:15:43 T:140028713752320 DEBUG: Thread LanguageInvoker 140028713752320 terminating
75902:15:43 T:140028722145024 INFO: Python script stopped
76002:15:43 T:140028722145024 DEBUG: Thread LanguageInvoker 140028722145024 terminating
76102:15:44 T:140028738930432 DEBUG: RunQuery took 28 ms for 97 items query: select * from movie_view WHERE ((movie_view.playCount IS NULL OR movie_view.playCount = 0))
76202:15:45 T:140027233281792 DEBUG: -->Python Interpreter Initialized<--
76302:15:45 T:140027233281792 DEBUG: CPythonInvoker(12, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
76402:15:45 T:140027233281792 DEBUG: CPythonInvoker(12, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
76502:15:45 T:140027233281792 DEBUG: CPythonInvoker(12, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
76602:15:45 T:140027233281792 DEBUG: CPythonInvoker(12, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
76702:15:48 T:140028747323136 DEBUG: WaitOnScriptResult- plugin returned successfully
76802:15:48 T:140028738930432 INFO: CPythonInvoker(11, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
76902:15:48 T:140028747323136 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','6','?action=recentsongs&limit=25&reload=')
77002:15:48 T:140028747323136 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=13) plugin...
77102:15:48 T:140028722145024 DEBUG: Thread LanguageInvoker start, auto delete: false
77202:15:48 T:140028722145024 INFO: initializing python engine.
77302:15:48 T:140028722145024 DEBUG: CPythonInvoker(13, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
77402:15:49 T:140028738930432 INFO: Python script stopped
77502:15:49 T:140028738930432 DEBUG: Thread LanguageInvoker 140028738930432 terminating
77602:15:49 T:140028722145024 DEBUG: -->Python Interpreter Initialized<--
77702:15:49 T:140028722145024 DEBUG: CPythonInvoker(13, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
77802:15:49 T:140028722145024 DEBUG: CPythonInvoker(13, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
77902:15:49 T:140028722145024 DEBUG: CPythonInvoker(13, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
78002:15:49 T:140028722145024 DEBUG: CPythonInvoker(13, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
78102:15:49 T:140027233281792 DEBUG: RunQuery took 357 ms for 5060 items query: select * from episode_view WHERE ((episode_view.playCount IS NULL OR episode_view.playCount = 0))
78202:15:51 T:140029502289664 DEBUG: RunQuery took 26 ms for 0 items query: select * from musicvideo_view
78302:15:51 T:140029502289664 DEBUG: GetAlbumsByWhere query: SELECT albumview.*, albumartistview.* FROM albumview LEFT JOIN albumartistview on albumartistview.idalbum = albumview.idalbum WHERE albumview.strReleaseType = 'album'
78402:15:51 T:140029502289664 DEBUG: GetAlbumsByWhere - query took 301 ms
78502:15:53 T:140028730537728 DEBUG: WaitOnScriptResult- plugin returned successfully
78602:15:53 T:140027233281792 INFO: CPythonInvoker(12, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
78702:15:53 T:140028730537728 DEBUG: CRecentlyAddedJob::UpdateMusic() - Running RecentlyAdded home screen update
78802:15:53 T:140028730537728 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.itrack, songartistview.iOrder
78902:15:53 T:140028730537728 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 LEFT JOIN albumartistview ON albumview.idAlbum = albumartistview.idAlbum ORDER BY albumview.idAlbum desc, albumartistview.iOrder
79002:15:53 T:140028730537728 DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update
79102:15:53 T:140028730537728 DEBUG: RunQuery took 68 ms for 10 items query: select * from movie_view ORDER BY dateAdded desc, idMovie desc LIMIT 10
79202:15:53 T:140028730537728 DEBUG: RunQuery took 298 ms for 10 items query: select * from episode_view ORDER BY dateAdded desc, idEpisode desc LIMIT 10
79302:15:53 T:140028730537728 DEBUG: RunQuery took 1 ms for 0 items query: select * from musicvideo_view ORDER BY dateAdded desc, idMVideo desc LIMIT 10
79402:15:53 T:140028730537728 DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update
79502:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.webserver type: _http._tcp name:Kodi Living Room port:8080
79602:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::addService() named: Kodi Living Room type: _http._tcp port:8080
79702:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.jsonrpc-http type: _xbmc-jsonrpc-h._tcp name:Kodi Living Room port:8080
79802:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::addService() named: Kodi Living Room type: _xbmc-jsonrpc-h._tcp port:8080
79902:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.eventserver type: _xbmc-events._udp name:Kodi Living Room port:9777
80002:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::addService() named: Kodi Living Room type: _xbmc-events._udp port:9777
80102:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.jsonrpc-tpc type: _xbmc-jsonrpc._tcp name:Kodi Living Room port:9090
80202:15:54 T:140028730537728 DEBUG: CZeroconfAvahi::addService() named: Kodi Living Room type: _xbmc-jsonrpc._tcp port:9090
80302:15:54 T:140028730537728 INFO: WEATHER: Downloading weather
80402:15:54 T:140028738930432 DEBUG: Thread LanguageInvoker start, auto delete: false
80502:15:54 T:140028738930432 INFO: initializing python engine.
80602:15:54 T:140028738930432 DEBUG: CPythonInvoker(14, /home/jamesz/.kodi/addons/weather.yahoo/default.py): start processing
80702:15:55 T:140028705359616 DEBUG: CZeroconfAvahi::groupCallback: Service successfully established
80802:15:55 T:140027233281792 DEBUG: Previous line repeats 3 times.
80902:15:55 T:140027233281792 INFO: Python script stopped
81002:15:55 T:140027233281792 DEBUG: Thread LanguageInvoker 140027233281792 terminating
81102:15:57 T:140030437029952 DEBUG: LIRC: Update - NEW at 71950:000000037ff07bde 00 KEY_RIGHT mceusb (KEY_RIGHT)
81202:15:57 T:140030437029952 DEBUG: OnKey: 168 (0xa8) pressed, action is Right
81302:15:57 T:140030437029952 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/ImageLib-x86_64-linux.so)
81402:15:57 T:140030437029952 DEBUG: Loading: /usr/lib/kodi/system/ImageLib-x86_64-linux.so
81502:15:57 T:140030437029952 DEBUG: LIRC: Update - NEW at 72751:000000037ff07bde 00 KEY_RIGHT mceusb (KEY_RIGHT)
81602:15:57 T:140030437029952 DEBUG: OnKey: 168 (0xa8) pressed, action is Right
81702:15:58 T:140030437029952 DEBUG: LIRC: Update - NEW at 73497:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
81802:15:58 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
81902:15:58 T:140028738930432 DEBUG: -->Python Interpreter Initialized<--
82002:15:58 T:140028738930432 DEBUG: CPythonInvoker(14, /home/jamesz/.kodi/addons/weather.yahoo/default.py): the source file to load is "/home/jamesz/.kodi/addons/weather.yahoo/default.py"
82102:15:58 T:140028738930432 DEBUG: CPythonInvoker(14, /home/jamesz/.kodi/addons/weather.yahoo/default.py): setting the Python path to /home/jamesz/.kodi/addons/weather.yahoo:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
82202:15:58 T:140028738930432 DEBUG: CPythonInvoker(14, /home/jamesz/.kodi/addons/weather.yahoo/default.py): entering source directory /home/jamesz/.kodi/addons/weather.yahoo
82302:15:58 T:140028738930432 DEBUG: CPythonInvoker(14, /home/jamesz/.kodi/addons/weather.yahoo/default.py): instantiating addon using automatically obtained id of "weather.yahoo" dependent on version 2.19.0 of the xbmc.python api
82402:15:59 T:140028722145024 DEBUG: GetRecentlyAddedAlbumSongs() query: SELECT songview.*, songartistview.* FROM (SELECT idAlbum FROM album ORDER BY idAlbum DESC LIMIT 25) AS recentalbums JOIN songview ON songview.idAlbum = recentalbums.idAlbum JOIN songartistview ON songview.idSong = songartistview.idSong ORDER BY songview.idAlbum desc, songview.itrack, songartistview.iOrder
82502:15:59 T:140030437029952 DEBUG: LIRC: Update - NEW at 74450:000000037ff07bde 00 KEY_RIGHT mceusb (KEY_RIGHT)
82602:15:59 T:140030437029952 DEBUG: OnKey: 168 (0xa8) pressed, action is Right
82702:16:00 T:140030437029952 DEBUG: LIRC: Update - NEW at 75050:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
82802:16:00 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
82902:16:00 T:140030437029952 DEBUG: Activating window ID: 10025
83002:16:00 T:140030437029952 DEBUG: ------ Window Deinit (Home.xml) ------
83102:16:00 T:140030437029952 DEBUG: ------ Window Init (MyVideoNav.xml) ------
83202:16:00 T:140030437029952 INFO: Loading skin file: MyVideoNav.xml, load type: KEEP_IN_MEMORY
83302:16:12 T:140030437029952 DEBUG: CGUIMediaWindow::GetDirectory (smb://JAMESZ/Complete/)
83402:16:12 T:140030437029952 DEBUG: ParentPath = [smb://JAMESZ/Complete/]
83502:16:12 T:140027535288064 DEBUG: Thread BackgroundLoader start, auto delete: false
83602:16:12 T:140027526895360 DEBUG: Thread LanguageInvoker start, auto delete: false
83702:16:12 T:140027526895360 INFO: initializing python engine.
83802:16:12 T:140027526895360 DEBUG: CPythonInvoker(15, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): start processing
83902:16:13 T:140027535288064 DEBUG: Thread BackgroundLoader 140027535288064 terminating
84002:16:13 T:140028738930432 DEBUG: weather.yahoo: version 3.3.2 started: ['/home/jamesz/.kodi/addons/weather.yahoo/default.py', '1']
84102:16:14 T:140028738930432 DEBUG: weather.yahoo: weather location: 12761689
84202:16:15 T:140030437029952 DEBUG: LIRC: Update - NEW at 90253:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
84302:16:15 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
84402:16:15 T:140030437029952 DEBUG: LIRC: Update - NEW at 90754:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
84502:16:15 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
84602:16:16 T:140028696966912 DEBUG: WaitOnScriptResult- plugin returned successfully
84702:16:16 T:140028332201728 INFO: CPythonInvoker(10, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
84802:16:16 T:140030437029952 DEBUG: LIRC: Update - NEW at 91628:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
84902:16:16 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
85002:16:16 T:140030437029952 DEBUG: CGUIMediaWindow::GetDirectory (smb://JAMESZ/Complete/Movie/)
85102:16:16 T:140030437029952 DEBUG: ParentPath = [smb://JAMESZ/Complete/]
85202:16:16 T:140027384284928 DEBUG: Thread BackgroundLoader start, auto delete: false
85302:16:16 T:140027384284928 DEBUG: Thread BackgroundLoader 140027384284928 terminating
85402:16:17 T:140028332201728 INFO: Python script stopped
85502:16:17 T:140028332201728 DEBUG: Thread LanguageInvoker 140028332201728 terminating
85602:16:17 T:140030437029952 DEBUG: LIRC: Update - NEW at 92412:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
85702:16:17 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
85802:16:17 T:140027526895360 DEBUG: -->Python Interpreter Initialized<--
85902:16:17 T:140027526895360 DEBUG: CPythonInvoker(15, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): the source file to load is "/home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py"
86002:16:17 T:140027526895360 DEBUG: CPythonInvoker(15, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): setting the Python path to /home/jamesz/.kodi/addons/script.tv.show.next.aired:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
86102:16:17 T:140027526895360 DEBUG: CPythonInvoker(15, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): entering source directory /home/jamesz/.kodi/addons/script.tv.show.next.aired
86202:16:17 T:140027526895360 DEBUG: CPythonInvoker(15, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): instantiating addon using automatically obtained id of "script.tv.show.next.aired" dependent on version 2.1.0 of the xbmc.python api
86302:16:18 T:140030437029952 DEBUG: LIRC: Update - NEW at 93073:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
86402:16:18 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
86502:16:18 T:140030437029952 INFO: Loading skin file: DialogContextMenu.xml, load type: KEEP_IN_MEMORY
86602:16:18 T:140030437029952 DEBUG: ------ Window Init (DialogContextMenu.xml) ------
86702:16:19 T:140030437029952 DEBUG: LIRC: Update - NEW at 94121:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
86802:16:19 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
86902:16:19 T:140030437029952 DEBUG: ------ Window Deinit (DialogContextMenu.xml) ------
87002:16:19 T:140030437029952 DEBUG: OnPlayMedia smb://JAMESZ/Complete/Movie/Movie.mp4
87102:16:19 T:140030437029952 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
87202:16:19 T:140030437029952 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
87302:16:19 T:140030437029952 DEBUG: Loading settings for smb://JAMESZ/Complete/Movie/Movie.mp4
87402:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers(smb://JAMESZ/Complete/Movie/Movie.mp4)
87502:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
87602:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
87702:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: mms/udp
87802:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
87902:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
88002:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
88102:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
88202:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
88302:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
88402:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
88502:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
88602:16:19 T:140030437029952 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
88702:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
88802:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
88902:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
89002:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
89102:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
89202:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: VSX-1122 (4)
89302:16:19 T:140030437029952 DEBUG: CPlayerCoreFactory::GetPlayers: added 2 players
89402:16:19 T:140030437029952 DEBUG: Radio UECP (RDS) Processor - new CDVDRadioRDSData
89502:16:19 T:140030437029952 NOTICE: DVDPlayer: Opening: smb://JAMESZ/Complete/Movie/Movie.mp4
89602:16:19 T:140030437029952 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
89702:16:19 T:140030437029952 DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
89802:16:19 T:140030437029952 DEBUG: LinuxRendererGL: Cleaning up GL resources
89902:16:19 T:140030437029952 DEBUG: CLinuxRendererGL::PreInit - precision of luminance 16 is 16
90002:16:19 T:140027250067200 DEBUG: Thread DVDPlayer start, auto delete: false
90102:16:19 T:140027250067200 NOTICE: Creating InputStream
90202:16:19 T:140027250067200 DEBUG: CSMBFile::Open - opened smb://JAMESZ/Complete/Movie/Movie.mp4, fd=10000
90302:16:19 T:140027250067200 DEBUG: ScanForExternalSubtitles: Searching for subtitles...
90402:16:19 T:140027250067200 DEBUG: ScanForExternalSubtitles: END (total time: 3 ms)
90502:16:19 T:140027250067200 NOTICE: Creating Demuxer
90602:16:19 T:140027250067200 DEBUG: Open - probing detected format [mov,mp4,m4a,3gp,3g2,mj2]
90702:16:19 T:140029502289664 DEBUG: GetArtistsByWhere query: SELECT artistview.* FROM artistview WHERE (artistview.idArtist IN (SELECT song_artist.idArtist FROM song_artist) OR artistview.idArtist IN (SELECT album_artist.idArtist FROM album_artist)) and artistview.strArtist != '' and artistview.strArtist <> 'Various artists'
90802:16:19 T:140029502289664 DEBUG: Time to retrieve artists from dataset = 171
90902:16:20 T:140030437029952 DEBUG: ------ Window Init (DialogBusy.xml) ------
91002:16:20 T:140027526895360 DEBUG: POParser: loaded 43 strings from file /home/jamesz/.kodi/addons/script.tv.show.next.aired/resources/language/English/strings.po
91102:16:20 T:140027526895360 DEBUG: script.tv.show.next.aired: ### params: {'backend': 'True'}
91202:16:20 T:140027526895360 NOTICE: script.tv.show.next.aired: ### TV Show - Next Aired starting GUI proc (6.0.15)
91302:16:20 T:140028747323136 DEBUG: WaitOnScriptResult- plugin returned successfully
91402:16:20 T:140027526895360 DEBUG: script.tv.show.next.aired: ### run_backend started
91502:16:20 T:140028722145024 INFO: CPythonInvoker(13, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
91602:16:21 T:140028722145024 INFO: Python script stopped
91702:16:21 T:140028722145024 DEBUG: Thread LanguageInvoker 140028722145024 terminating
91802:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: [mov,mp4,m4a,3gp,3g2,mj2] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol
91902:16:21 T:140027250067200 DEBUG: Open - avformat_find_stream_info starting
92002:16:21 T:140027250067200 DEBUG: Open - av_find_stream_info finished
92102:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Input #0, mov,mp4,m4a,3gp,3g2,mj2, smb://JAMESZ/Complete/Movie/Movie.mp':
92202:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Metadata:
92302:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: major_brand : isom
92402:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: minor_version : 512
92502:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: compatible_brands: isomiso2avc1mp41
92602:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: creation_time : 2016-09-05 19:10:22
92702:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: title : Going.Clear.Scientology.and.the.Prison.of.Belief.2015.1080p.BluRay.H264.AAC-RARBG
92802:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: encoder : Lavf56.40.101
92902:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: comment : Going.Clear.Scientology.and.the.Prison.of.Belief.2015.1080p.BluRay.H264.AAC-RARBG
93002:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Duration: 01:59:54.29, start: 0.000000, bitrate: 2729 kb/s
93102:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 1920x1080 [SAR 1:1 DAR 16:9], 2500 kb/s, 23.98 fps, 23.98 tbr, 11988 tbn, 47.95 tbc (default)
93202:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Metadata:
93302:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: creation_time : 2016-09-05 19:10:22
93402:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: handler_name : VideoHandler
93502:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Stream #0:1(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, 5.1, fltp, 223 kb/s (default)
93602:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: Metadata:
93702:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: creation_time : 2016-09-05 19:10:22
93802:16:21 T:140027250067200 INFO: ffmpeg[7F5AA27FC700]: handler_name : SoundHandler
93902:16:21 T:140027250067200 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
94002:16:21 T:140027250067200 DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
94102:16:21 T:140027250067200 NOTICE: Opening stream: 0 source: 256
94202:16:21 T:140027250067200 NOTICE: Creating video codec with codec id: 28
94302:16:21 T:140027250067200 DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:no MediaCodec:no OpenMax:no libstagefright:no VDPAU:yes VAAPI:yes iMXVPU:no MMAL:no
94402:16:21 T:140027250067200 DEBUG: FactoryCodec - Video: - Opening
94502:16:21 T:140027250067200 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
94602:16:21 T:140027250067200 DEBUG: FactoryCodec - Video: ff-h264 - Opened
94702:16:21 T:140027250067200 NOTICE: Creating video thread
94802:16:21 T:140027250067200 NOTICE: Opening stream: 1 source: 256
94902:16:21 T:140028722145024 DEBUG: Thread DVDPlayerVideo start, auto delete: false
95002:16:21 T:140027250067200 NOTICE: Finding audio codec for: 86018
95102:16:21 T:140027250067200 DEBUG: FactoryCodec - Audio: passthrough - Opening
95202:16:21 T:140027250067200 DEBUG: FactoryCodec - Audio: passthrough - Failed
95302:16:21 T:140027250067200 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
95402:16:21 T:140027250067200 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
95502:16:21 T:140027250067200 NOTICE: Creating audio thread
95602:16:21 T:140028722145024 NOTICE: running thread: video_thread
95702:16:21 T:140028722145024 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
95802:16:21 T:140027250067200 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: smb://JAMESZ/Complete/Movie/Movie.mp4
95902:16:21 T:140027409463040 DEBUG: Thread DVDPlayerAudio start, auto delete: false
96002:16:21 T:140027409463040 NOTICE: running thread: CDVDPlayerAudio::Process()
96102:16:21 T:140027409463040 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
96202:16:21 T:140027250067200 DEBUG: OnPlayBackStarted: play state was 1, starting 1
96302:16:21 T:140027250067200 DEBUG: CDVDPlayer::SetCaching - caching state 3
96402:16:21 T:140028722145024 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(0.000000, 1)
96502:16:21 T:140028722145024 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
96602:16:21 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
96702:16:21 T:140027250067200 DEBUG: CDVDPlayer::CheckContinuity - wrapback :2, prev:83416.750083, curr:41708.375042, diff:-41708.375042
96802:16:21 T:140028722145024 NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating VDPAU(1920x1080)
96902:16:21 T:140027409463040 NOTICE: Creating audio stream (codec id: 86018, channels: 6, sample rate: 48000, no pass-through)
97002:16:21 T:140028722145024 NOTICE: VDPAU::Open: required extension GL_NV_vdpau_interop not found
97102:16:21 T:140028722145024 NOTICE: (VDPAU) Close
97202:16:21 T:140027409463040 DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
97302:16:21 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket duplicate 1 packets of duration 21
97402:16:21 T:140030437029952 DEBUG: PlayFile: OpenFile succeed, play state 2
97502:16:21 T:140030437029952 DEBUG: OnPlayBackStarted: play state was 2, starting 0
97602:16:21 T:140028722145024 NOTICE: VAAPI::Close
97702:16:21 T:140029812700928 INFO: CActiveAESink::OpenSink - initialize sink
97802:16:21 T:140030437029952 DEBUG: CGUIInfoManager::SetCurrentMovie(smb://JAMESZ/Complete/Movie/Movie.mp4)
97902:16:21 T:140029263333120 NOTICE: 1Channel: Service: Playback started
98002:16:21 T:140028722145024 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
98102:16:21 T:140028722145024 DEBUG: CDVDVideoCodecFFmpeg - open frame threaded with 4 threads
98202:16:21 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
98302:16:21 T:140030437029952 DEBUG: Previous line repeats 3 times.
98402:16:21 T:140030437029952 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
98502:16:21 T:140030437029952 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
98602:16:21 T:140030437029952 DEBUG: UPnP: Building didl for object 'smb://JAMESZ/Complete/Movie/Movie.mp4'
98702:16:21 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 0
98802:16:21 T:140028722145024 DEBUG: Previous line repeats 1 times.
98902:16:21 T:140028722145024 NOTICE: fps: 23.976024, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080
99002:16:21 T:140028722145024 DEBUG: OutputPicture - change configuration. 1920x1080. framerate: 23.98. format: YV12
99102:16:21 T:140028722145024 NOTICE: Display resolution DESKTOP : 1280x720@ 60.00 - Full Screen (16)
99202:16:21 T:140028722145024 DEBUG: CXBMCRenderManager::Configure - 3
99302:16:21 T:140030437029952 DEBUG: Activating window ID: 12005
99402:16:21 T:140030437029952 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
99502:16:22 T:140030437029952 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
99602:16:22 T:140030437029952 INFO: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY
99702:16:22 T:140030437029952 NOTICE: Using GL_TEXTURE_2D
99802:16:22 T:140030437029952 DEBUG: GL: Requested render method: 0
99902:16:22 T:140030437029952 DEBUG: GL: BaseYUV2RGBGLSLShader: defines:
1000 #define XBMC_texture_rectangle 0
1001 #define XBMC_texture_rectangle_hack 0
1002 #define XBMC_STRETCH 0
1003 #define XBMC_YV12
100402:16:22 T:140030437029952 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
100502:16:22 T:140030437029952 ERROR: GL: Error compiling vertex shader
100602:16:22 T:140030437029952 ERROR: =
100702:16:22 T:140030437029952 ERROR: GL: Error compiling vertex shader
100802:16:22 T:140030437029952 ERROR: GL: Error enabling YUV2RGB GLSL shader
100902:16:22 T:140030437029952 NOTICE: GL: ARB shaders support detected
101002:16:22 T:140030437029952 DEBUG: GL: YUV2RGBProgressiveShaderARB: loading yuv2rgb_basic_2d.arb
101102:16:22 T:140030437029952 NOTICE: GL: Selecting Single Pass ARB YUV2RGB shader
101202:16:22 T:140030437029952 NOTICE: GL: No vertex shader, fixed pipeline in use
101302:16:22 T:140029812700928 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=NVidia,DEV=0
101402:16:22 T:140029812700928 INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=NVidia,DEV=0"
101502:16:22 T:140029812700928 INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=NVidia,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x02"
101602:16:22 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
101702:16:22 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
101802:16:22 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 680, bufferSize 2720
101902:16:22 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 544, bufferSize 2720
102002:16:22 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 57 ms
102102:16:22 T:140027250067200 DEBUG: CDVDPlayer::SetCaching - caching state 0
102202:16:22 T:140030437029952 ERROR: GL: Error compiling vertex shader
102302:16:22 T:140030437029952 ERROR: ��������`��X[
102402:16:22 T:140030437029952 ERROR: GL: Error compiling vertex shader
102502:16:22 T:140030437029952 ERROR: GL: Error compiling and linking video filter shader
102602:16:22 T:140030437029952 ERROR: GL: Falling back to bilinear due to failure to init scaler
102702:16:22 T:140030437029952 NOTICE: GL: NPOT texture support detected
102802:16:22 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 6 Output Channel Count: 6
102902:16:22 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR,FC,LFE,BL,BR
103002:16:22 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR,BL,BR,FC,LFE (ALSA: FL FR RL RR FC LFE)
103102:16:22 T:140029812700928 DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
103202:16:22 T:140029812700928 DEBUG: Output Device : HDA NVidia
103302:16:22 T:140029812700928 DEBUG: Sample Rate : 48000
103402:16:22 T:140029812700928 DEBUG: Sample Format : AE_FMT_S32NE
103502:16:22 T:140029812700928 DEBUG: Channel Count : 6
103602:16:22 T:140029812700928 DEBUG: Channel Layout: FL,FR,BL,BR,FC,LFE
103702:16:22 T:140029812700928 DEBUG: Frames : 544
103802:16:22 T:140029812700928 DEBUG: Frame Samples : 3264
103902:16:22 T:140029812700928 DEBUG: Frame Size : 24
104002:16:22 T:140029821093632 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
104102:16:22 T:140027409463040 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_DELAY(21333.333333)
104202:16:22 T:140029821093632 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
104302:16:22 T:140027250067200 DEBUG: CDVDPlayer::HandleMessages - player started 1
104402:16:22 T:140027409463040 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(21333.333333, 1)
104502:16:22 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
104602:16:22 T:140027250067200 DEBUG: CDVDPlayer::HandleMessages - player started 2
104702:16:22 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
104802:16:22 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
104902:16:22 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -1511.751562 below threshold of 50000.000000
105002:16:22 T:140030437029952 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
105102:16:22 T:140030437029952 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
105202:16:22 T:140030437029952 INFO: Loading skin file: DialogSeekBar.xml, load type: LOAD_ON_GUI_INIT
105302:16:23 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
105402:16:23 T:140027526895360 DEBUG: Previous line repeats 3 times.
105502:16:23 T:140027526895360 INFO: CPythonInvoker(15, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): script successfully run
105602:16:23 T:140027526895360 INFO: Python script stopped
105702:16:23 T:140027526895360 DEBUG: Thread LanguageInvoker 140027526895360 terminating
105802:16:23 T:140029502289664 DEBUG: GetSongsFullByWhere query = SELECT songview.*, song_artist.idArtist AS idArtist, artist.strArtist AS strArtist, artist.strMusicBrainzArtistID AS strMusicBrainzArtistID FROM songview LEFT JOIN song_artist on song_artist.idsong = songview.idsong LEFT JOIN artist ON song_artist.idArtist = artist.idArtist WHERE ((CAST(songview.iTimesPlayed as DECIMAL(5,1)) < 1))
105902:16:24 T:140029502289664 DEBUG: GetSongsFullByWhere() - took 725 ms
106002:16:24 T:140028738930432 DEBUG: weather.yahoo: forecast data: {"query":{"count":0,"created":"2016-12-26T07:16:24Z","lang":"en-US","results":null}}
106102:16:24 T:140028738930432 DEBUG: weather.yahoo: available locations: 1
106202:16:24 T:140028738930432 DEBUG: weather.yahoo: finished
106302:16:24 T:140028738930432 INFO: CPythonInvoker(14, /home/jamesz/.kodi/addons/weather.yahoo/default.py): script successfully run
106402:16:24 T:140028738930432 INFO: Python script stopped
106502:16:24 T:140028738930432 DEBUG: Thread LanguageInvoker 140028738930432 terminating
106602:16:24 T:140028730537728 DEBUG: POParser: loaded 130 weather tokens
106702:16:25 T:140029502289664 DEBUG: Skin Widgets: Total time needed to request random queries: 0:01:12.613329
106802:16:25 T:140029502289664 DEBUG: RunQuery took 17 ms for 67 items query: select * from movie_view WHERE (movie_view.idFile IN (SELECT DISTINCT idFile FROM bookmark WHERE type = 1))
106902:16:26 T:140029502289664 DEBUG: RunQuery took 160 ms for 22 items query: SELECT * FROM tvshow_view WHERE ( ((tvshow_view.watchedcount > 0 AND tvshow_view.watchedcount < tvshow_view.totalCount) OR (tvshow_view.watchedcount = 0 AND EXISTS (SELECT 1 FROM episode_view WHERE episode_view.idShow = tvshow_view.idShow AND episode_view.resumeTimeInSeconds > 0))))
107002:16:26 T:140029502289664 DEBUG: RunQuery took 9 ms for 74 items query: select * from episode_view WHERE (episode_view.idShow = 53) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
107102:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
107202:16:26 T:140029502289664 DEBUG: RunQuery took 3 ms for 2 items query: select * from episode_view WHERE (episode_view.idShow = 37) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
107302:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
107402:16:26 T:140029502289664 DEBUG: RunQuery took 9 ms for 85 items query: select * from episode_view WHERE (episode_view.idShow = 46) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
107502:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
107602:16:26 T:140029502289664 DEBUG: RunQuery took 5 ms for 18 items query: select * from episode_view WHERE (episode_view.idShow = 60) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
107702:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
107802:16:26 T:140029502289664 DEBUG: RunQuery took 3 ms for 9 items query: select * from episode_view WHERE (episode_view.idShow = 74) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
107902:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
108002:16:26 T:140029502289664 DEBUG: RunQuery took 17 ms for 161 items query: select * from episode_view WHERE (episode_view.idShow = 25) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
108102:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
108202:16:26 T:140029502289664 DEBUG: RunQuery took 4 ms for 16 items query: select * from episode_view WHERE (episode_view.idShow = 19) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
108302:16:26 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
108402:16:27 T:140029502289664 DEBUG: RunQuery took 7 ms for 79 items query: select * from episode_view WHERE (episode_view.idShow = 62) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
108502:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
108602:16:27 T:140029502289664 DEBUG: RunQuery took 28 ms for 284 items query: select * from episode_view WHERE (episode_view.idShow = 7) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
108702:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
108802:16:27 T:140029502289664 DEBUG: RunQuery took 10 ms for 93 items query: select * from episode_view WHERE (episode_view.idShow = 17) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
108902:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
109002:16:27 T:140029502289664 DEBUG: RunQuery took 26 ms for 230 items query: select * from episode_view WHERE (episode_view.idShow = 21) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
109102:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
109202:16:27 T:140030437029952 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
109302:16:27 T:140029502289664 DEBUG: RunQuery took 3 ms for 3 items query: select * from episode_view WHERE (episode_view.idShow = 71) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
109402:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
109502:16:27 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:5074826.949775, should be:5059271.073086, error:-15555.876689
109602:16:27 T:140029502289664 DEBUG: RunQuery took 19 ms for 169 items query: select * from episode_view WHERE (episode_view.idShow = 65) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
109702:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
109802:16:27 T:140029502289664 DEBUG: RunQuery took 12 ms for 179 items query: select * from episode_view WHERE (episode_view.idShow = 40) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
109902:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
110002:16:27 T:140029502289664 DEBUG: RunQuery took 7 ms for 100 items query: select * from episode_view WHERE (episode_view.idShow = 36) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
110102:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
110202:16:27 T:140029502289664 DEBUG: RunQuery took 3 ms for 6 items query: select * from episode_view WHERE (episode_view.idShow = 68) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
110302:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
110402:16:27 T:140029502289664 DEBUG: RunQuery took 10 ms for 92 items query: select * from episode_view WHERE (episode_view.idShow = 47) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
110502:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
110602:16:27 T:140029502289664 DEBUG: RunQuery took 14 ms for 209 items query: select * from episode_view WHERE (episode_view.idShow = 26) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
110702:16:27 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
110802:16:28 T:140029502289664 DEBUG: RunQuery took 7 ms for 67 items query: select * from episode_view WHERE (episode_view.idShow = 22) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
110902:16:28 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
111002:16:28 T:140029502289664 DEBUG: RunQuery took 25 ms for 273 items query: select * from episode_view WHERE (episode_view.idShow = 61) AND (((episode_view.playCount IS NULL OR episode_view.playCount = 0)))
111102:16:28 T:140029502289664 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25
111202:16:28 T:140029502289664 DEBUG: GetAlbumsByWhere query: SELECT albumview.*, albumartistview.* FROM albumview LEFT JOIN albumartistview on albumartistview.idalbum = albumview.idalbum WHERE albumview.strReleaseType = 'album'
111302:16:28 T:140028722145024 DEBUG: CPullupCorrection: detected pattern of length 1: 41708.38, frameduration: 41708.333333
111402:16:28 T:140029502289664 DEBUG: GetAlbumsByWhere - query took 309 ms
111502:16:28 T:140029502289664 DEBUG: RunQuery took 1 ms for 0 items query: select * from musicvideo_view
111602:16:28 T:140029502289664 DEBUG: Skin Widgets: Total time needed to request recommended queries: 0:00:03.439596
111702:16:28 T:140029502289664 DEBUG: RunQuery took 19 ms for 97 items query: select * from movie_view WHERE ((movie_view.playCount IS NULL OR movie_view.playCount = 0))
111802:16:29 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:7059428.706086, should be:7018076.832113, error:-41351.873973
111902:16:29 T:140029502289664 DEBUG: RunQuery took 362 ms for 5060 items query: select * from episode_view WHERE ((episode_view.playCount IS NULL OR episode_view.playCount < 1))
112002:16:31 T:140029502289664 DEBUG: RunQuery took 1 ms for 0 items query: select * from musicvideo_view
112102:16:31 T:140029502289664 DEBUG: GetAlbumsByWhere query: SELECT albumview.*, albumartistview.* FROM albumview LEFT JOIN albumartistview on albumartistview.idalbum = albumview.idalbum WHERE albumview.strReleaseType = 'album'
112202:16:31 T:140029502289664 DEBUG: GetAlbumsByWhere - query took 350 ms
112302:16:32 T:140029502289664 DEBUG: Skin Widgets: Total time needed to request recent items queries: 0:00:03.134192
112402:16:32 T:140029502289664 DEBUG: Skin Widgets: Total time needed for all queries: 0:01:19.187934
112502:16:32 T:140027367499520 DEBUG: GetSongsFullByWhere query = SELECT songview.*, song_artist.idArtist AS idArtist, artist.strArtist AS strArtist, artist.strMusicBrainzArtistID AS strMusicBrainzArtistID FROM songview LEFT JOIN song_artist on song_artist.idsong = songview.idsong LEFT JOIN artist ON song_artist.idArtist = artist.idArtist
112602:16:32 T:140027367499520 DEBUG: GetSongsFullByWhere() - took 781 ms
112702:16:33 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
112802:16:45 T:140029812700928 DEBUG: Previous line repeats 5 times.
112902:16:45 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
113002:16:46 T:140027367499520 DEBUG: GetRecentlyAddedAlbums query: SELECT albumview.*, albumartistview.* FROM (SELECT idAlbum FROM album WHERE strAlbum != '' ORDER BY idAlbum DESC LIMIT 25) AS recentalbums JOIN albumview ON albumview.idAlbum = recentalbums.idAlbum LEFT JOIN albumartistview ON albumview.idAlbum = albumartistview.idAlbum ORDER BY albumview.idAlbum desc, albumartistview.iOrder
113102:16:46 T:140027367499520 ERROR: GetDirectory - Error getting /home/jamesz/Pictures/
113202:16:47 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -105855.117863 above threshold of 100000.000000
113302:16:47 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
113402:16:47 T:140027409463040 NOTICE: Previous line repeats 4 times.
113502:16:47 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -27110.960381 below threshold of 50000.000000
113602:16:47 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:25318874.322113, should be:25291765.457732, error:-27108.864381
113702:16:48 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:26295007.071732, should be:26322170.187888, error:27163.116156
113802:16:51 T:140027963086592 DEBUG: Thread JobWorker 140027963086592 terminating (autodelete)
113902:16:51 T:140028696966912 DEBUG: Thread JobWorker 140028696966912 terminating (autodelete)
114002:16:51 T:140028747323136 DEBUG: Thread JobWorker 140028747323136 terminating (autodelete)
114102:16:54 T:140028730537728 DEBUG: Thread JobWorker 140028730537728 terminating (autodelete)
114202:17:26 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
114302:17:27 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:64557921.446888, should be:64541957.878024, error:-15963.568864
114402:17:29 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:66566046.761024, should be:66472761.623705, error:-93285.137319
114502:17:30 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
114602:17:31 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:68500649.383705, should be:68478838.382138, error:-21811.001567
114702:17:33 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:70506961.298138, should be:70420870.208147, error:-86091.089991
114802:18:39 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:136800754.173147, should be:136790682.367718, error:-10071.805429
114902:18:47 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
115002:18:49 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -152448.291807 above threshold of 100000.000000
115102:18:49 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
115202:18:49 T:140027409463040 NOTICE: Previous line repeats 5 times.
115302:18:49 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -36260.156546 below threshold of 50000.000000
115402:18:49 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:147042962.379718, should be:147006705.296172, error:-36257.083546
115502:18:50 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:148018494.922172, should be:148029465.340222, error:10970.418050
115602:19:44 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
115702:19:45 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:202327296.351222, should be:202309958.341902, error:-17338.009320
115802:19:47 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:204327550.869902, should be:204229188.302391, error:-98362.567511
115902:20:53 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:270601579.556391, should be:270591510.152219, error:-10069.404172
116002:21:59 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:336964110.162219, should be:336953996.540507, error:-10113.621712
116102:23:06 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:403366372.549507, should be:403356189.861332, error:-10182.688175
116202:24:12 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:469711443.953332, should be:469701271.797215, error:-10172.156117
116302:24:18 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
116402:24:20 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -104125.331410 above threshold of 100000.000000
116502:24:20 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
116602:24:20 T:140027409463040 NOTICE: Previous line repeats 3 times.
116702:24:20 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -33394.380193 below threshold of 50000.000000
116802:24:20 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:477821351.504215, should be:477787960.127022, error:-33391.377193
116902:24:21 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:478795922.173022, should be:478809787.050430, error:13864.877407
117002:24:31 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
117102:24:33 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -112693.247425 above threshold of 100000.000000
117202:24:33 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
117302:24:33 T:140027409463040 NOTICE: Previous line repeats 4 times.
117402:24:33 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -36046.021639 below threshold of 50000.000000
117502:24:33 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:491077591.939430, should be:491041548.571791, error:-36043.367639
117602:24:34 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:492044085.556791, should be:492073636.241578, error:29550.684788
117702:25:28 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
117802:25:29 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:546397293.436578, should be:546365765.307987, error:-31528.128592
117902:25:31 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:548371915.041987, should be:548291418.314831, error:-80496.727156
118002:25:35 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
118102:25:37 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -107262.426402 above threshold of 100000.000000
118202:25:37 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
118302:25:37 T:140027409463040 NOTICE: Previous line repeats 4 times.
118402:25:37 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -28825.070123 below threshold of 50000.000000
118502:25:37 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:554426637.441831, should be:554397814.676708, error:-28822.765123
118602:25:38 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:555398507.921708, should be:555421075.283009, error:22567.361301
118702:25:51 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
118802:25:52 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:569450152.241009, should be:569414754.315098, error:-35397.925911
118902:25:54 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:571425435.840098, should be:571355371.029819, error:-70064.810279
119002:26:44 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
119102:26:46 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -106755.463761 above threshold of 100000.000000
119202:26:46 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
119302:26:46 T:140027409463040 NOTICE: Previous line repeats 4 times.
119402:26:46 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -35368.743994 below threshold of 50000.000000
119502:26:46 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:623760420.679819, should be:623725071.979825, error:-35348.699994
119602:26:47 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:624745104.970825, should be:624771752.960033, error:26647.989208
119702:27:46 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
119802:27:48 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:685063070.648033, should be:684972572.967445, error:-90497.680588
119902:27:50 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:686974002.201445, should be:686951665.162061, error:-22337.039383
120002:28:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:753398560.916061, should be:753388259.614217, error:-10301.301845
120102:29:45 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
120202:29:46 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:803724522.737217, should be:803633169.356082, error:-91353.381134
120302:29:49 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:805650920.145082, should be:805631199.510389, error:-19720.634693
120402:30:18 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
120502:30:19 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:835813818.598389, should be:835793132.852386, error:-20685.746004
120602:30:21 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:837810573.545386, should be:837722762.744446, error:-87810.800940
120702:30:24 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
120802:30:25 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:841726669.110446, should be:841657427.693474, error:-69241.416972
120902:30:25 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
121002:30:27 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -132229.334372 above threshold of 100000.000000
121102:30:27 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
121202:30:27 T:140027409463040 NOTICE: Previous line repeats 6 times.
121302:30:27 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -24419.153250 below threshold of 50000.000000
121402:30:27 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:843770776.232474, should be:843746360.292224, error:-24415.940250
121502:30:28 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:844754187.264224, should be:844777312.855823, error:23125.591599
121602:30:40 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
121702:30:42 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
121802:30:44 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:860825414.435823, should be:860745927.459926, error:-79486.975896
121902:30:46 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:862758389.797926, should be:862727881.981485, error:-30507.816442
122002:31:52 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:929060678.056485, should be:929050545.753607, error:-10132.302878
122102:32:59 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:995428698.075607, should be:995418644.902547, error:-10053.173060
122202:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2falbums%2f/
122302:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fartists%2f/
122402:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fgenres%2f/
122502:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2frecentlyaddedalbums%2f/
122602:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fsingles%2f/
122702:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fsongs%2f/
122802:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fyears%2f/
122902:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/library%3a%2f%2fvideo%2fmovies%2ftitles.xml%2f/
123002:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/library%3a%2f%2fvideo%2ftvshows%2ftitles.xml%2f/
123102:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/videodb%3a%2f%2frecentlyaddedepisodes%2f/
123202:33:32 T:140028738930432 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/videodb%3a%2f%2frecentlyaddedmovies%2f/
123302:33:36 T:140027258459904 DEBUG: CPlayerCoreConfig::<ctor>: created player XBMC (raspbmc) for core 5
123402:33:55 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
123502:33:57 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1053691202.944547, should be:1053593919.876083, error:-97283.068463
123602:33:59 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1055614062.938083, should be:1055598809.946287, error:-15252.991797
123702:34:00 T:140027971479296 DEBUG: JSONRPC Server: New connection detected
123802:34:00 T:140027971479296 INFO: JSONRPC Server: New connection added
123902:34:00 T:140027526895360 DEBUG: webserver: request received for /jsonrpc
124002:34:00 T:140027526895360 DEBUG: Previous line repeats 3 times.
124102:34:00 T:140027526895360 DEBUG: GetMovieId (), query = select idMovie from movie join files on files.idFile=movie.idFile where files.idPath=-1
124202:34:00 T:140027526895360 DEBUG: Previous line repeats 1 times.
124302:34:00 T:140027526895360 DEBUG: webserver: request received for /jsonrpc
124402:34:00 T:140027535288064 DEBUG: Previous line repeats 2 times.
124502:34:00 T:140027535288064 DEBUG: Thread JobWorker start, auto delete: true
124602:34:00 T:140027535288064 INFO: easy_aquire - Created session to http://www.msftncsi.com
124702:34:01 T:140027526895360 DEBUG: webserver: request received for /image/image%3A%2F%2Fvideo%40smb%253A%252F%252FJAMESZ%252FComplete%252FMovie%252FMovie.mp4%2F
124802:34:01 T:140028747323136 DEBUG: Previous line repeats 2 times.
124902:34:01 T:140028747323136 DEBUG: webserver: request received for /jsonrpc
125002:34:02 T:140028747323136 DEBUG: Previous line repeats 2 times.
125102:34:02 T:140028747323136 DEBUG: GetMovieId (), query = select idMovie from movie join files on files.idFile=movie.idFile where files.idPath=-1
125202:34:03 T:140028747323136 DEBUG: webserver: request received for /jsonrpc
125302:34:04 T:140028747323136 DEBUG: Previous line repeats 1 times.
125402:34:04 T:140028747323136 DEBUG: GetMovieId (), query = select idMovie from movie join files on files.idFile=movie.idFile where files.idPath=-1
125502:34:05 T:140028747323136 DEBUG: webserver: request received for /jsonrpc
125602:34:05 T:140028747323136 DEBUG: Previous line repeats 1 times.
125702:34:05 T:140028747323136 DEBUG: GetMovieId (), query = select idMovie from movie join files on files.idFile=movie.idFile where files.idPath=-1
125802:34:06 T:140027971479296 INFO: JSONRPC Server: Disconnection detected
125902:34:07 T:140027258459904 DEBUG: webserver: request received for /jsonrpc
126002:34:31 T:140027535288064 DEBUG: Thread JobWorker 140027535288064 terminating (autodelete)
126102:34:31 T:140030437029952 INFO: CheckIdle - Closing session to http://www.msftncsi.com (easy=0x7f5aed8f4510, multi=(nil))
126202:35:03 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1120014704.767287, should be:1120004663.814526, error:-10040.952760
126302:36:12 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1188270363.731526, should be:1188259996.400388, error:-10367.331139
126402:37:14 T:140028747323136 DEBUG: webserver: request received for /jsonrpc
126502:37:18 T:140027409463040 DEBUG: Previous line repeats 2 times.
126602:37:18 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1254535719.167388, should be:1254525662.911140, error:-10056.256248
126702:37:23 T:140027258459904 DEBUG: webserver: request received for /jsonrpc
126802:37:36 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
126902:37:38 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -114274.656701 above threshold of 100000.000000
127002:37:38 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
127102:37:38 T:140027409463040 NOTICE: Previous line repeats 4 times.
127202:37:38 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -35327.110133 below threshold of 50000.000000
127302:37:38 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1274751972.525141, should be:1274716648.488007, error:-35324.037133
127402:37:39 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1275748111.143007, should be:1275775095.200016, error:26984.057009
127502:38:46 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1342198409.120016, should be:1342188363.515670, error:-10045.604346
127602:39:26 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
127702:39:27 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1383337913.818670, should be:1383318702.447220, error:-19211.371450
127802:39:29 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -1025822.758163 above threshold of 100000.000000
127902:39:29 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
128002:39:29 T:140027409463040 NOTICE: Previous line repeats 46 times.
128102:39:29 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -33690.143708 below threshold of 50000.000000
128202:39:29 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1385442503.641219, should be:1385408816.081512, error:-33687.559707
128302:39:42 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
128402:40:20 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
128502:40:22 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -102849.706137 above threshold of 100000.000000
128602:40:22 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
128702:40:22 T:140027409463040 NOTICE: Previous line repeats 3 times.
128802:40:22 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -33857.086980 below threshold of 50000.000000
128902:40:22 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1438792568.126512, should be:1438758714.461532, error:-33853.664980
129002:40:23 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1439767144.442532, should be:1439780523.028761, error:13378.586229
129102:41:16 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
129202:41:18 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -100951.990495 above threshold of 100000.000000
129302:41:18 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
129402:41:18 T:140027409463040 NOTICE: Previous line repeats 4 times.
129502:41:18 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -29966.061265 below threshold of 50000.000000
129602:41:18 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1494185060.673761, should be:1494155097.405495, error:-29963.268266
129702:41:19 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1495158198.707495, should be:1495183192.825527, error:24994.118032
129802:42:25 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1561567265.660527, should be:1561557068.510349, error:-10197.150178
129902:42:59 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1595732271.786349, should be:1595697787.322778, error:-34484.463571
130002:43:01 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1597704037.419778, should be:1597676385.077357, error:-27652.342421
130102:44:08 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1664059030.497357, should be:1664048746.402344, error:-10284.095013
130202:45:16 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1732451543.265344, should be:1732441234.759930, error:-10308.505414
130302:46:05 T:140027535288064 DEBUG: CFavourites::Load - no system favourites found, skipping
130402:46:05 T:140027535288064 DEBUG: RunQuery took 41 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet ORDER BY sets.idSet
130502:46:05 T:140027535288064 DEBUG: RunQuery took 10 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet WHERE sets.idSet=1 ORDER BY sets.idSet
130602:46:05 T:140027535288064 DEBUG: RunQuery took 5 ms for 12 items query: select * from movie_view WHERE movie_view.idSet = 1
130702:46:22 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1798778364.553930, should be:1798768212.986212, error:-10151.567718
130802:47:29 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1865198369.046212, should be:1865188191.348390, error:-10177.697822
130902:47:45 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
131002:47:47 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -552927.697007 above threshold of 100000.000000
131102:47:47 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
131202:47:47 T:140027409463040 NOTICE: Previous line repeats 47 times.
131302:47:47 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -26902.369551 below threshold of 50000.000000
131402:47:47 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1883383289.945390, should be:1883356390.089839, error:-26899.855551
131502:47:48 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1884357533.531839, should be:1884374422.519835, error:16888.987997
131602:47:58 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
131702:48:05 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
131802:48:06 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1902463841.846835, should be:1902382002.676336, error:-81839.170499
131902:48:08 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1904392451.701336, should be:1904359737.482993, error:-32714.218343
132002:49:14 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1970715309.773993, should be:1970705297.129599, error:-10012.644395
132102:49:31 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
132202:49:32 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1988758323.219599, should be:1988666083.957212, error:-92239.262387
132302:49:34 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:1990694881.887212, should be:1990680633.161512, error:-14248.725700
132402:50:41 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2057081498.912512, should be:2057071397.006792, error:-10101.905720
132502:51:47 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2123404212.286792, should be:2123393993.803554, error:-10218.483238
132602:52:12 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
132702:52:13 T:140029812700928 DEBUG: Previous line repeats 1 times.
132802:52:13 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
132902:52:13 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2149536607.460554, should be:2149501273.639135, error:-35333.821418
133002:52:15 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2151509203.627135, should be:2151432859.427202, error:-76344.199933
133102:52:46 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
133202:52:48 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2183603059.553203, should be:2183543047.534563, error:-60012.018640
133302:52:50 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2185571908.323563, should be:2185523432.959086, error:-48475.364477
133402:53:01 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
133502:53:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2197576519.386086, should be:2197527510.181749, error:-49009.204337
133602:53:04 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2199528245.471748, should be:2199467835.445082, error:-60410.026666
133702:53:07 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
133802:53:08 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2203499135.093081, should be:2203462913.547539, error:-36221.545543
133902:53:10 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2205469080.533539, should be:2205401048.551020, error:-68031.982519
134002:54:01 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
134102:54:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2257731467.984020, should be:2257679238.926412, error:-52229.057608
134202:54:04 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2259684795.919412, should be:2259625250.707828, error:-59545.211584
134302:54:10 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
134402:54:12 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2267691169.626828, should be:2267595787.216070, error:-95382.410758
134502:54:18 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2273637399.697070, should be:2273627335.163720, error:-10064.533350
134602:54:20 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2275644866.161720, should be:2275591636.112509, error:-53230.049211
134702:55:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2317792724.244509, should be:2317782470.701400, error:-10253.543109
134802:55:18 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
134902:55:20 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -110206.975194 above threshold of 100000.000000
135002:55:20 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
135102:55:21 T:140027409463040 NOTICE: Previous line repeats 4 times.
135202:55:21 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -29006.420480 below threshold of 50000.000000
135302:55:21 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2336023220.346400, should be:2335994216.858920, error:-29003.487481
135402:55:22 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2337004924.363919, should be:2337030039.079972, error:25114.716053
135502:56:29 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
135602:56:30 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2405433899.902973, should be:2405366310.437212, error:-67589.465760
135702:56:32 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2407398373.658212, should be:2407347991.498981, error:-50382.159231
135802:56:42 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
135902:56:54 T:140029812700928 DEBUG: Previous line repeats 8 times.
136002:56:54 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
136102:56:56 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -115018.364512 above threshold of 100000.000000
136202:56:56 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
136302:56:56 T:140027409463040 NOTICE: Previous line repeats 4 times.
136402:56:56 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -35407.174406 below threshold of 50000.000000
136502:56:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2431614152.753981, should be:2431578748.233574, error:-35404.520406
136602:56:57 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2432587564.298574, should be:2432614591.707839, error:27027.409265
136702:57:07 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
136802:58:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2497083771.225839, should be:2497073689.580747, error:-10081.645092
136902:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2falbums%2f/
137002:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fartists%2f/
137102:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fgenres%2f/
137202:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2frecentlyaddedalbums%2f/
137302:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fsingles%2f/
137402:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fsongs%2f/
137502:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/musicdb%3a%2f%2fyears%2f/
137602:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/library%3a%2f%2fvideo%2fmovies%2ftitles.xml%2f/
137702:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/library%3a%2f%2fvideo%2ftvshows%2ftitles.xml%2f/
137802:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/videodb%3a%2f%2frecentlyaddedepisodes%2f/
137902:58:39 T:140027092444928 DEBUG: UPNP: notfified container update upnp://91925f6e-e8a7-7810-d399-9a3e857bec87/videodb%3a%2f%2frecentlyaddedmovies%2f/
138002:59:00 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
138102:59:00 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2555380811.509747, should be:2555349579.807941, error:-31231.701805
138202:59:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2557355945.141942, should be:2557274481.024380, error:-81464.117562
138303:00:00 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2615661733.027380, should be:2615636532.451560, error:-25200.575820
138403:00:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2617642586.574559, should be:2617601908.225336, error:-40678.349223
138503:00:51 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
138603:00:53 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2667830816.934336, should be:2667739420.547952, error:-91396.386384
138703:00:55 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2669750580.765952, should be:2669730855.285601, error:-19725.480350
138803:01:50 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
138903:01:51 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2726107912.067601, should be:2726044504.766751, error:-63407.300850
139003:01:53 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2728048424.958751, should be:2727994673.982531, error:-53750.976221
139103:02:53 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2788416633.816530, should be:2788354960.213919, error:-61673.602611
139203:03:32 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2826577260.463919, should be:2826567133.142327, error:-10127.321592
139303:04:38 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2892944786.936328, should be:2892934548.240232, error:-10238.696097
139403:04:42 T:140027117623040 DEBUG: webserver: request received for /jsonrpc
139503:04:42 T:140027117623040 DEBUG: Previous line repeats 1 times.
139603:04:42 T:140027117623040 DEBUG: GetMovieId (), query = select idMovie from movie join files on files.idFile=movie.idFile where files.idPath=-1
139703:05:44 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2959284382.091232, should be:2959274347.601646, error:-10034.489586
139803:05:47 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
139903:05:48 T:140027409463040 ERROR: CDVDAudio::AddPacketsRenderer - timeout adding data to renderer
140003:05:49 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -298293.287334 above threshold of 100000.000000
140103:05:49 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
140203:05:49 T:140027409463040 NOTICE: Previous line repeats 93 times.
140303:05:49 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -22620.134416 below threshold of 50000.000000
140403:05:49 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2963738505.554645, should be:2963715887.725230, error:-22617.829415
140503:05:50 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:2964719693.936231, should be:2964736925.462511, error:17231.526280
140603:06:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3031097129.065511, should be:3031087078.495132, error:-10050.570379
140703:08:03 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3097505536.144132, should be:3097495400.353909, error:-10135.790224
140803:08:23 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
140903:08:25 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3119612845.099908, should be:3119528151.294556, error:-84693.805353
141003:08:27 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3121560771.848556, should be:3121538345.939404, error:-22425.909153
141103:08:28 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
141203:08:29 T:140027409463040 ERROR: Previous line repeats 1 times.
141303:08:29 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3123641873.890404, should be:3123620256.804178, error:-21617.086226
141403:08:31 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -189133.243419 above threshold of 100000.000000
141503:08:31 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
141603:08:31 T:140027409463040 NOTICE: Previous line repeats 7 times.
141703:08:31 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -32835.591193 below threshold of 50000.000000
141803:08:31 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3125736090.925178, should be:3125703257.707984, error:-32833.217193
141903:08:32 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3126715926.565984, should be:3126729903.873073, error:13977.307089
142003:09:06 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
142103:09:08 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -116658.680022 above threshold of 100000.000000
142203:09:08 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
142303:09:08 T:140027409463040 NOTICE: Previous line repeats 4 times.
142403:09:08 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -32543.035077 below threshold of 50000.000000
142503:09:08 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3163145207.185073, should be:3163112666.454996, error:-32540.730077
142603:09:09 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3164117302.239996, should be:3164139191.289494, error:21889.049498
142703:10:16 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3230449380.164494, should be:3230439273.122352, error:-10107.042142
142803:10:16 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
142903:10:18 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3232456917.263352, should be:3232366471.928058, error:-90445.335294
143003:10:20 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3234377228.044058, should be:3234355919.856093, error:-21308.187965
143103:11:24 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3298761509.249093, should be:3298751399.759943, error:-10109.489150
143203:11:54 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
143303:11:54 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3328967401.437943, should be:3328941394.261961, error:-26007.175982
143403:11:56 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
143503:11:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3330956906.846961, should be:3330870844.204030, error:-86062.642931
143603:11:57 T:140028722145024 DEBUG: CDVDPlayerVideo::CalcDropRequirement - hurry: 1
143703:11:58 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3332884596.511030, should be:3332836652.077299, error:-47944.433731
143803:12:05 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3338870598.430299, should be:3338860449.969159, error:-10148.461141
143903:13:11 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3405216435.369157, should be:3405206290.478439, error:-10144.890718
144003:13:37 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
144103:13:37 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3431346455.432440, should be:3431325072.212524, error:-21383.219916
144203:13:39 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3433354728.912524, should be:3433268643.434927, error:-86085.477597
144303:14:06 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
144403:14:07 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3461498923.320927, should be:3461404089.345207, error:-94833.975719
144503:14:09 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3463414682.173207, should be:3463397444.564794, error:-17237.608413
144603:15:04 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
144703:15:06 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3519630326.619794, should be:3519533745.328892, error:-96581.290902
144803:15:08 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3521534441.717892, should be:3521514982.556224, error:-19459.161668
144903:15:19 T:140028747323136 DEBUG: script.grab.fanart: media type is: random
145003:15:19 T:140028747323136 DEBUG: RunQuery took 101 ms for 1116 items query: select * from movie_view
145103:15:22 T:140028747323136 DEBUG: script.grab.fanart: found 1115 movies files
145203:15:22 T:140028747323136 DEBUG: RunQuery took 104 ms for 66 items query: SELECT * FROM tvshow_view
145303:15:22 T:140028747323136 DEBUG: script.grab.fanart: found 65 tv files
145403:15:22 T:140028747323136 DEBUG: GetArtistsByWhere query: SELECT artistview.* FROM artistview WHERE (artistview.idArtist IN (SELECT song_artist.idArtist FROM song_artist) OR artistview.idArtist IN (SELECT album_artist.idArtist FROM album_artist)) and artistview.strArtist != '' and artistview.strArtist <> 'Various artists'
145503:15:23 T:140028747323136 DEBUG: Time to retrieve artists from dataset = 923
145603:15:24 T:140028747323136 DEBUG: script.grab.fanart: found 573 music files
145703:15:58 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
145803:16:00 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3573758826.613224, should be:3573684353.885889, error:-74472.727335
145903:16:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3575690090.369889, should be:3575652802.899449, error:-37287.470439
146003:16:18 T:140028747323136 DEBUG: CFavourites::Load - no system favourites found, skipping
146103:16:18 T:140028747323136 DEBUG: RunQuery took 32 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet ORDER BY sets.idSet
146203:16:18 T:140028747323136 DEBUG: RunQuery took 13 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet WHERE sets.idSet=1 ORDER BY sets.idSet
146303:16:18 T:140028747323136 DEBUG: RunQuery took 5 ms for 12 items query: select * from movie_view WHERE movie_view.idSet = 1
146403:17:08 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3641991461.798450, should be:3641981349.938093, error:-10111.860357
146503:18:14 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3708337001.497092, should be:3708326874.520576, error:-10126.976517
146603:19:21 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3774642343.953576, should be:3774632200.462466, error:-10143.491110
146703:19:48 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
146803:19:49 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3802728333.010466, should be:3802705423.099394, error:-22909.911072
146903:19:51 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3804711250.447394, should be:3804626325.541793, error:-84924.905602
147003:20:47 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
147103:20:47 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3860968668.559793, should be:3860938325.703112, error:-30342.856681
147203:20:49 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3862944968.587111, should be:3862862880.059302, error:-82088.527809
147303:21:53 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
147403:21:54 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3927261607.616302, should be:3927228879.760999, error:-32727.855303
147503:21:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3929229405.247999, should be:3929144743.207249, error:-84662.040751
147603:22:01 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
147703:22:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3935199516.856248, should be:3935160486.421866, error:-39030.434382
147803:22:04 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3937170863.159866, should be:3937105396.572317, error:-65466.587550
147903:22:42 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
148003:22:44 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -102785.178545 above threshold of 100000.000000
148103:22:44 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
148203:22:44 T:140027409463040 NOTICE: Previous line repeats 4 times.
148303:22:44 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -28291.985246 below threshold of 50000.000000
148403:22:44 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3977477529.743317, should be:3977449240.273070, error:-28289.470247
148503:22:45 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:3978462336.769070, should be:3978487668.301294, error:25331.532224
148603:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1/
148703:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/4/
148803:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/5/
148903:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/6/
149003:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/100/
149103:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/107/
149203:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/108/
149303:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/7/
149403:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/101/
149503:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/102/
149603:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/103/
149703:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/104/
149803:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/105/
149903:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/106/
150003:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/F/
150103:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/14/
150203:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/2/
150303:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/8/
150403:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/9/
150503:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/A/
150603:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/E/
150703:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/200/
150803:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/201/
150903:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/202/
151003:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/203/
151103:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/204/
151203:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/205/
151303:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/10/
151403:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/15/
151503:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/3/
151603:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/B/
151703:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/C/
151803:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/D/
151903:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/D2/
152003:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/300/
152103:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/306/
152203:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/301/
152303:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/302/
152403:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/303/
152503:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/304/
152603:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/305/
152703:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/11/
152803:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/16/
152903:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/18/
153003:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/19/
153103:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1A/
153203:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1B/
153303:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1C/
153403:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1D/
153503:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/1E/
153603:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/400/
153703:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/401/
153803:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/402/
153903:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/403/
154003:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/404/
154103:23:05 T:140028738930432 DEBUG: UPNP: notfified container update upnp://4112c9e5-f41f-4232-ad3e-1fe65097eb9d/405/
154203:23:20 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
154303:23:21 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4014635340.988294, should be:4014582076.040264, error:-53264.948030
154403:23:23 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4016586305.629264, should be:4016530225.824798, error:-56079.804466
154503:24:30 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4082892054.285798, should be:4082881932.296077, error:-10121.989721
154603:25:36 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4149244136.014077, should be:4149233865.628743, error:-10270.385334
154703:25:55 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
154803:25:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4169389367.021743, should be:4169339204.926432, error:-50162.095311
154903:25:58 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4171367900.400432, should be:4171311253.194980, error:-56647.205452
155003:27:06 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4239622896.235979, should be:4239612425.950470, error:-10470.285509
155103:28:02 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
155203:28:03 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4295864268.932469, should be:4295816183.841050, error:-48085.091419
155303:28:05 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4297820449.118052, should be:4297756391.817983, error:-64057.300069
155403:29:03 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
155503:29:03 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4356128701.421984, should be:4356118031.816360, error:-10669.605623
155603:29:05 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -105494.171371 above threshold of 100000.000000
155703:29:05 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
155803:29:05 T:140027409463040 NOTICE: Previous line repeats 4 times.
155903:29:05 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -26233.636842 below threshold of 50000.000000
156003:29:05 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4358259836.623360, should be:4358233605.919518, error:-26230.703841
156103:29:06 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4359242330.003519, should be:4359269322.181765, error:26992.178246
156203:30:06 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
156303:30:07 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4419570889.145764, should be:4419531366.200392, error:-39522.945373
156403:30:09 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4421542698.366392, should be:4421465104.177442, error:-77594.188951
156503:30:33 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
156603:30:35 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4447594129.867442, should be:4447521707.282486, error:-72422.584956
156703:30:37 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4449524700.889485, should be:4449489654.772370, error:-35046.117115
156803:30:37 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
156903:30:39 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -106341.718880 above threshold of 100000.000000
157003:30:39 T:140027409463040 NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 21
157103:30:39 T:140027409463040 NOTICE: Previous line repeats 4 times.
157203:30:39 T:140027409463040 DEBUG: CDVDPlayerAudio::HandleSyncError - average error -29137.574694 below threshold of 50000.000000
157303:30:39 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4451597567.496372, should be:4451568434.112677, error:-29133.383696
157403:30:40 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4452581331.421675, should be:4452609481.879442, error:28150.457767
157503:30:55 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
157603:30:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4468746817.695443, should be:4468713937.775864, error:-32879.919580
157703:30:58 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4470728117.299865, should be:4470654781.383201, error:-73335.916664
157803:32:02 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
157903:32:02 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4535022500.604199, should be:4535006699.011461, error:-15801.592738
158003:32:04 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4537006651.940462, should be:4536908908.153831, error:-97743.786631
158103:33:11 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4603298082.125831, should be:4603287878.623273, error:-10203.502558
158203:33:18 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
158303:33:19 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4611331006.870273, should be:4611308390.206518, error:-22616.663754
158403:33:21 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4613336705.394517, should be:4613250435.667503, error:-86269.727014
158503:34:27 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4679599846.910504, should be:4679589716.776625, error:-10130.133880
158603:35:34 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4745995765.446626, should be:4745985636.068566, error:-10129.378059
158703:35:55 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
158803:35:56 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4768125563.207566, should be:4768100013.427918, error:-25549.779648
158903:35:58 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4770106330.782918, should be:4770024750.112017, error:-81580.670901
159003:36:11 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
159103:36:12 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4784126666.205016, should be:4784074640.956074, error:-52025.248942
159203:36:14 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4786074050.868074, should be:4786020602.098336, error:-53448.769738
159303:37:18 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4850526008.284336, should be:4850515991.910738, error:-10016.373598
159403:38:03 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
159503:38:05 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4896775366.496737, should be:4896687654.663349, error:-87711.833387
159603:38:07 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4898699176.520349, should be:4898672217.781492, error:-26958.738856
159703:38:41 T:140029812700928 ERROR: CAESinkALSA - snd_pcm_writei(-32) Broken pipe - trying to recover
159803:38:43 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4934804146.920494, should be:4934709070.387735, error:-95076.532759
159903:38:45 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:4936710987.392734, should be:4936696903.445501, error:-14083.947232
160003:39:51 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:5003048639.843502, should be:5003038623.187897, error:-10016.655605
160103:40:58 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:5069517011.487896, should be:5069506622.903183, error:-10388.584713
160203:42:04 T:140027409463040 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError2 - was:5135843625.168181, should be:5135833425.448234, error:-10199.719948
160303:43:02 T:140030437029952 DEBUG: LIRC: Update - NEW at 5297404:000000037ff07be6 00 KEY_STOP mceusb (KEY_STOP)
160403:43:02 T:140030437029952 DEBUG: OnKey: guide (0xe0) pressed, action is Stop
160503:43:02 T:140030437029952 NOTICE: CDVDPlayer::CloseFile()
160603:43:02 T:140030437029952 NOTICE: DVDPlayer: waiting for threads to exit
160703:43:02 T:140027250067200 NOTICE: CDVDPlayer::OnExit()
160803:43:02 T:140027250067200 NOTICE: Closing stream player 1
160903:43:02 T:140027250067200 NOTICE: Waiting for audio thread to exit
161003:43:02 T:140027409463040 NOTICE: thread end: CDVDPlayerAudio::OnExit()
161103:43:02 T:140027250067200 NOTICE: Closing audio device
161203:43:02 T:140027409463040 DEBUG: Thread DVDPlayerAudio 140027409463040 terminating
161303:43:02 T:140029821093632 DEBUG: CActiveAE::DiscardStream - audio stream deleted
161403:43:02 T:140029821093632 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
161503:43:02 T:140027250067200 DEBUG: Previous line repeats 1 times.
161603:43:02 T:140027250067200 NOTICE: Deleting audio codec
161703:43:02 T:140029812700928 INFO: CActiveAESink::OpenSink - initialize sink
161803:43:02 T:140027250067200 NOTICE: Closing stream player 2
161903:43:02 T:140027250067200 NOTICE: waiting for video thread to exit
162003:43:02 T:140028722145024 NOTICE: thread end: video_thread
162103:43:02 T:140028722145024 DEBUG: Thread DVDPlayerVideo 140028722145024 terminating
162203:43:02 T:140027250067200 NOTICE: deleting video codec
162303:43:02 T:140027250067200 DEBUG: CSMBFile::Close closing fd 10000
162403:43:02 T:140027250067200 DEBUG: OnPlayBackStopped: play state was 2, starting 0
162503:43:02 T:140027250067200 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
162603:43:02 T:140027250067200 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
162703:43:02 T:140027250067200 DEBUG: Thread DVDPlayer 140027250067200 terminating
162803:43:02 T:140030437029952 NOTICE: DVDPlayer: finished waiting
162903:43:02 T:140030437029952 DEBUG: LinuxRendererGL: Cleaning up GL resources
163003:43:02 T:140030437029952 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
163103:43:02 T:140030437029952 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
163203:43:02 T:140029263333120 NOTICE: 1Channel: Service: Playback Stopped
163303:43:02 T:140029263333120 NOTICE: 1Channel: Service: Resetting...
163403:43:02 T:140030437029952 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
163503:43:02 T:140030437029952 DEBUG: ------ Window Init (MyVideoNav.xml) ------
163603:43:02 T:140030437029952 DEBUG: CGUIMediaWindow::GetDirectory (smb://JAMESZ/Complete/Movie/)
163703:43:02 T:140030437029952 DEBUG: ParentPath = [smb://JAMESZ/Complete/Movie/]
163803:43:02 T:140029812700928 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=NVidia,DEV=0
163903:43:02 T:140029812700928 INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=NVidia,DEV=0"
164003:43:02 T:140029812700928 INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=NVidia,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
164103:43:02 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
164203:43:02 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
164303:43:02 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
164403:43:02 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
164503:43:02 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
164603:43:02 T:140027258459904 DEBUG: Thread BackgroundLoader start, auto delete: false
164703:43:02 T:140027258459904 DEBUG: Thread BackgroundLoader 140027258459904 terminating
164803:43:02 T:140027258459904 DEBUG: Thread BackgroundLoader start, auto delete: false
164903:43:02 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
165003:43:02 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
165103:43:02 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
165203:43:02 T:140029812700928 DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
165303:43:02 T:140029812700928 DEBUG: Output Device : HDA NVidia
165403:43:02 T:140029812700928 DEBUG: Sample Rate : 44100
165503:43:02 T:140029812700928 DEBUG: Sample Format : AE_FMT_S32NE
165603:43:02 T:140029812700928 DEBUG: Channel Count : 2
165703:43:02 T:140029812700928 DEBUG: Channel Layout: FL,FR
165803:43:02 T:140029812700928 DEBUG: Frames : 2048
165903:43:02 T:140029812700928 DEBUG: Frame Samples : 4096
166003:43:02 T:140029812700928 DEBUG: Frame Size : 8
166103:43:02 T:140029821093632 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
166203:43:02 T:140027258459904 DEBUG: Thread BackgroundLoader 140027258459904 terminating
166303:43:03 T:140027258459904 DEBUG: Thread LanguageInvoker start, auto delete: false
166403:43:03 T:140027258459904 INFO: initializing python engine.
166503:43:03 T:140027258459904 DEBUG: CPythonInvoker(16, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): start processing
166603:43:03 T:140030437029952 NOTICE: CDVDPlayer::CloseFile()
166703:43:03 T:140030437029952 NOTICE: DVDPlayer: waiting for threads to exit
166803:43:03 T:140030437029952 NOTICE: DVDPlayer: finished waiting
166903:43:03 T:140030437029952 DEBUG: LinuxRendererGL: Cleaning up GL resources
167003:43:03 T:140030437029952 NOTICE: CDVDPlayer::CloseFile()
167103:43:03 T:140030437029952 NOTICE: DVDPlayer: waiting for threads to exit
167203:43:03 T:140030437029952 NOTICE: DVDPlayer: finished waiting
167303:43:03 T:140030437029952 DEBUG: LinuxRendererGL: Cleaning up GL resources
167403:43:03 T:140030437029952 DEBUG: Radio UECP (RDS) Processor - delete ~CDVDRadioRDSData
167503:43:03 T:140028747323136 DEBUG: Thread JobWorker start, auto delete: true
167603:43:03 T:140028747323136 DEBUG: DoWork - Saving file state for video item smb://JAMESZ/Complete/Movie/Movie.mp4
167703:43:03 T:140030437029952 DEBUG: OnKey: guide (0xe0) pressed, action is Stop
167803:43:03 T:140027258459904 DEBUG: -->Python Interpreter Initialized<--
167903:43:03 T:140027258459904 DEBUG: CPythonInvoker(16, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): the source file to load is "/home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py"
168003:43:03 T:140027258459904 DEBUG: CPythonInvoker(16, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): setting the Python path to /home/jamesz/.kodi/addons/script.tv.show.next.aired:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
168103:43:03 T:140027258459904 DEBUG: CPythonInvoker(16, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): entering source directory /home/jamesz/.kodi/addons/script.tv.show.next.aired
168203:43:03 T:140027258459904 DEBUG: CPythonInvoker(16, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): instantiating addon using automatically obtained id of "script.tv.show.next.aired" dependent on version 2.1.0 of the xbmc.python api
168303:43:03 T:140028747323136 DEBUG: GetImageHash - unable to stat url /media/XBMC 2/Pictures/08-14-15 Billy Joel Concert/08-14-15 Billy Joel Concert (4).jpg
168403:43:03 T:140027126015744 DEBUG: Thread JobWorker start, auto delete: true
168503:43:03 T:140028747323136 DEBUG: DoWork - trying to extract thumb from video file smb://JAMESZ/Complete/Movie/Movie.mp4
168603:43:03 T:140027126015744 DEBUG: GetImageHash - unable to stat url /media/XBMC 3/Batman Begins/Batman Begins-fanart.jpg
168703:43:03 T:140028747323136 DEBUG: CSMBFile::Open - opened smb://JAMESZ/Complete/Movie/Movie.mp4, fd=10000
168803:43:04 T:140028747323136 DEBUG: Open - probing detected format [mov,mp4,m4a,3gp,3g2,mj2]
168903:43:04 T:140027258459904 DEBUG: POParser: loaded 43 strings from file /home/jamesz/.kodi/addons/script.tv.show.next.aired/resources/language/English/strings.po
169003:43:04 T:140027258459904 DEBUG: script.tv.show.next.aired: ### params: {'backend': 'True'}
169103:43:04 T:140027258459904 NOTICE: script.tv.show.next.aired: ### TV Show - Next Aired starting GUI proc (6.0.15)
169203:43:04 T:140027258459904 DEBUG: script.tv.show.next.aired: ### run_backend started
169303:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: [mov,mp4,m4a,3gp,3g2,mj2] Protocol name not provided, cannot determine if input is local or a network protocol, buffers and access patterns cannot be configured optimally without knowing the protocol
169403:43:05 T:140028747323136 DEBUG: Open - avformat_find_stream_info starting
169503:43:05 T:140028747323136 DEBUG: Open - av_find_stream_info finished
169603:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Input #0, mov,mp4,m4a,3gp,3g2,mj2, smb://JAMESZ/Complete/Movie/Movie.mp':
169703:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Metadata:
169803:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: major_brand : isom
169903:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: minor_version : 512
170003:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: compatible_brands: isomiso2avc1mp41
170103:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: creation_time : 2016-09-05 19:10:22
170203:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: title : Going.Clear.Scientology.and.the.Prison.of.Belief.2015.1080p.BluRay.H264.AAC-RARBG
170303:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: encoder : Lavf56.40.101
170403:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: comment : Going.Clear.Scientology.and.the.Prison.of.Belief.2015.1080p.BluRay.H264.AAC-RARBG
170503:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Duration: 01:59:54.29, start: 0.000000, bitrate: 2729 kb/s
170603:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 1920x1080 [SAR 1:1 DAR 16:9], 2500 kb/s, 23.98 fps, 23.98 tbr, 11988 tbn, 47.95 tbc (default)
170703:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Metadata:
170803:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: creation_time : 2016-09-05 19:10:22
170903:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: handler_name : VideoHandler
171003:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Stream #0:1(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, 5.1, fltp, 223 kb/s (default)
171103:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: Metadata:
171203:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: creation_time : 2016-09-05 19:10:22
171303:43:05 T:140028747323136 INFO: ffmpeg[7F5AFBBE1700]: handler_name : SoundHandler
171403:43:05 T:140028747323136 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
171503:43:05 T:140028747323136 DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
171603:43:05 T:140028747323136 DEBUG: ScanForExternalSubtitles: Searching for subtitles...
171703:43:05 T:140028747323136 DEBUG: ScanForExternalSubtitles: END (total time: 3 ms)
171803:43:05 T:140028747323136 DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:no MediaCodec:no OpenMax:no libstagefright:no VDPAU:yes VAAPI:yes iMXVPU:no MMAL:no
171903:43:05 T:140028747323136 DEBUG: FactoryCodec - Video: - Opening
172003:43:05 T:140028747323136 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
172103:43:05 T:140028747323136 DEBUG: FactoryCodec - Video: ff-h264 - Opened
172203:43:05 T:140028747323136 DEBUG: ExtractThumb - seeking to pos 2398098ms (total: 7194294ms) in smb://JAMESZ/Complete/Movie/Movie.mp4
172303:43:05 T:140028747323136 DEBUG: SeekTime - unknown position after seek
172403:43:05 T:140028747323136 DEBUG: cached image 'special://masterprofile/Thumbnails/8/82fe40ef.jpg' size 360x202
172503:43:05 T:140028747323136 DEBUG: CSMBFile::Close closing fd 10000
172603:43:05 T:140028747323136 DEBUG: ExtractThumb - measured 1859 ms to extract thumb from file <smb://JAMESZ/Complete/Movie/Movie.mp4> in 8 packets.
172703:43:06 T:140028747323136 DEBUG: Creating DDS version of: special://masterprofile/Thumbnails/8/82fe40ef.jpg
172803:43:06 T:140028747323136 DEBUG: Compress - using DXT1 (min error is: 7.41:0.00)
172903:43:33 T:140030437029952 DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-x86_64-linux.so)
173003:43:36 T:140027126015744 DEBUG: Thread JobWorker 140027126015744 terminating (autodelete)
173103:43:36 T:140028747323136 DEBUG: Thread JobWorker 140028747323136 terminating (autodelete)
173203:44:38 T:140030437029952 NOTICE: Samba is idle. Closing the remaining connections
173303:46:03 T:140030437029952 DEBUG: CAnnouncementManager - Announcement: OnScreensaverActivated from xbmc
173403:46:03 T:140030437029952 DEBUG: GOT ANNOUNCEMENT, type: 4, from xbmc, message OnScreensaverActivated
173503:46:03 T:140030437029952 DEBUG: ------ Window Init () ------
173603:47:58 T:140027250067200 DEBUG: CFavourites::Load - no system favourites found, skipping
173703:47:58 T:140027250067200 DEBUG: RunQuery took 13 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet ORDER BY sets.idSet
173803:47:58 T:140027250067200 DEBUG: RunQuery took 7 ms for 12 items query: select * from movie_view JOIN sets ON movie_view.idSet = sets.idSet WHERE sets.idSet=1 ORDER BY sets.idSet
173903:47:58 T:140027250067200 DEBUG: RunQuery took 3 ms for 12 items query: select * from movie_view WHERE movie_view.idSet = 1
174003:48:28 T:140030437029952 DEBUG: LIRC: Update - NEW at 5623533:000000037ff07bdc 00 KEY_BACK mceusb (KEY_BACK)
174103:48:28 T:140030437029952 DEBUG: CAnnouncementManager - Announcement: OnScreensaverDeactivated from xbmc
174203:48:28 T:140030437029952 DEBUG: GOT ANNOUNCEMENT, type: 4, from xbmc, message OnScreensaverDeactivated
174303:48:28 T:140030437029952 DEBUG: OnKey: menu (0xd8) pressed, screen saver/dpms woken up
174403:48:29 T:140030437029952 DEBUG: LIRC: Update - NEW at 5624452:000000037ff07bdc 00 KEY_BACK mceusb (KEY_BACK)
174503:48:29 T:140030437029952 DEBUG: OnKey: menu (0xd8) pressed, action is Back
174603:48:29 T:140029812700928 INFO: CActiveAESink::OpenSink - initialize sink
174703:48:29 T:140030437029952 DEBUG: CGUIMediaWindow::GetDirectory (smb://JAMESZ/Complete/)
174803:48:29 T:140029812700928 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=NVidia,DEV=0
174903:48:29 T:140030437029952 DEBUG: ParentPath = [smb://JAMESZ/]
175003:48:29 T:140029812700928 INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=NVidia,DEV=0"
175103:48:29 T:140027535288064 DEBUG: Thread JobWorker start, auto delete: true
175203:48:29 T:140029812700928 INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=NVidia,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
175303:48:29 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
175403:48:29 T:140029812700928 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
175503:48:29 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
175603:48:29 T:140028738930432 DEBUG: Thread BackgroundLoader start, auto delete: false
175703:48:29 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
175803:48:29 T:140029812700928 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
175903:48:29 T:140030437029952 DEBUG: ------ Window Deinit () ------
176003:48:29 T:140028738930432 DEBUG: Thread BackgroundLoader 140028738930432 terminating
176103:48:29 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
176203:48:29 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
176303:48:29 T:140029812700928 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
176403:48:29 T:140029812700928 DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
176503:48:29 T:140029812700928 DEBUG: Output Device : HDA NVidia
176603:48:29 T:140029812700928 DEBUG: Sample Rate : 44100
176703:48:29 T:140029812700928 DEBUG: Sample Format : AE_FMT_S32NE
176803:48:29 T:140029812700928 DEBUG: Channel Count : 2
176903:48:29 T:140029812700928 DEBUG: Channel Layout: FL,FR
177003:48:29 T:140029812700928 DEBUG: Frames : 2048
177103:48:29 T:140029812700928 DEBUG: Frame Samples : 4096
177203:48:29 T:140029812700928 DEBUG: Frame Size : 8
177303:48:30 T:140030437029952 DEBUG: LIRC: Update - NEW at 5625449:000000037ff07bdc 00 KEY_BACK mceusb (KEY_BACK)
177403:48:30 T:140030437029952 DEBUG: OnKey: menu (0xd8) pressed, action is Back
177503:48:30 T:140030437029952 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
177603:48:30 T:140030437029952 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
177703:48:30 T:140030437029952 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
177803:48:30 T:140030437029952 DEBUG: ------ Window Init (Home.xml) ------
177903:48:30 T:140027250067200 DEBUG: Thread JobWorker start, auto delete: true
178003:48:30 T:140027535288064 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','7','?action=INPROGRESSANDRECOMMENDEDMOVIES&reload=20161226084304')
178103:48:30 T:140027535288064 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=17) plugin...
178203:48:30 T:140028738930432 DEBUG: Thread LanguageInvoker start, auto delete: false
178303:48:30 T:140027250067200 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','8','?action=nextepisodes&reload=20161226084304')
178403:48:30 T:140028738930432 INFO: initializing python engine.
178503:48:30 T:140028738930432 DEBUG: CPythonInvoker(17, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
178603:48:30 T:140027250067200 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=18) plugin...
178703:48:30 T:140028722145024 DEBUG: Thread LanguageInvoker start, auto delete: false
178803:48:30 T:140028722145024 INFO: initializing python engine.
178903:48:30 T:140028722145024 DEBUG: CPythonInvoker(18, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
179003:48:30 T:140028696966912 DEBUG: Thread LanguageInvoker start, auto delete: false
179103:48:30 T:140028696966912 INFO: initializing python engine.
179203:48:30 T:140028696966912 DEBUG: CPythonInvoker(19, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): start processing
179303:48:30 T:140028332201728 DEBUG: Thread JobWorker start, auto delete: true
179403:48:30 T:140028332201728 DEBUG: StartScript - calling plugin Skin Helper Service('plugin://script.skin.helper.service/','9','?action=recentmovies&reload=20161226084304')
179503:48:30 T:140028332201728 DEBUG: WaitOnScriptResult - waiting on the Skin Helper Service (id=20) plugin...
179603:48:30 T:140027526895360 DEBUG: Thread LanguageInvoker start, auto delete: false
179703:48:30 T:140027526895360 INFO: initializing python engine.
179803:48:30 T:140027526895360 DEBUG: CPythonInvoker(20, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): start processing
179903:48:31 T:140027258459904 INFO: CPythonInvoker(16, /home/jamesz/.kodi/addons/script.tv.show.next.aired/default.py): script successfully run
180003:48:31 T:140027258459904 INFO: Python script stopped
180103:48:31 T:140027258459904 DEBUG: Thread LanguageInvoker 140027258459904 terminating
180203:48:31 T:140028738930432 DEBUG: -->Python Interpreter Initialized<--
180303:48:31 T:140028738930432 DEBUG: CPythonInvoker(17, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
180403:48:31 T:140028738930432 DEBUG: CPythonInvoker(17, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
180503:48:31 T:140028738930432 DEBUG: CPythonInvoker(17, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
180603:48:31 T:140028722145024 DEBUG: -->Python Interpreter Initialized<--
180703:48:31 T:140028722145024 DEBUG: CPythonInvoker(18, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
180803:48:31 T:140028738930432 DEBUG: CPythonInvoker(17, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
180903:48:31 T:140028696966912 DEBUG: -->Python Interpreter Initialized<--
181003:48:31 T:140028696966912 DEBUG: CPythonInvoker(19, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): the source file to load is "/home/jamesz/.kodi/addons/script.skinshortcuts/default.py"
181103:48:31 T:140028722145024 DEBUG: CPythonInvoker(18, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
181203:48:31 T:140028722145024 DEBUG: CPythonInvoker(18, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
181303:48:31 T:140028722145024 DEBUG: CPythonInvoker(18, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
181403:48:33 T:140030437029952 DEBUG: LIRC: Update - NEW at 5627849:000000037ff07bde 00 KEY_RIGHT mceusb (KEY_RIGHT)
181503:48:33 T:140030437029952 DEBUG: OnKey: 168 (0xa8) pressed, action is Right
181603:48:33 T:140030437029952 DEBUG: started alarm with name: widgetrotate510
181703:48:33 T:140030437029952 DEBUG: started alarm with name: widgetrotate520
181803:48:33 T:140030437029952 DEBUG: LIRC: Update - NEW at 5628367:000000037ff07bde 00 KEY_RIGHT mceusb (KEY_RIGHT)
181903:48:33 T:140030437029952 DEBUG: OnKey: 168 (0xa8) pressed, action is Right
182003:48:33 T:140028747323136 DEBUG: Thread JobWorker start, auto delete: true
182103:48:33 T:140028747323136 DEBUG: DoWork - took 116 ms to load special://skin/extras/backgrounds/cpu.jpg
182203:48:34 T:140030437029952 DEBUG: LIRC: Update - NEW at 5629084:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
182303:48:34 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
182403:48:34 T:140030437029952 DEBUG: Activating window ID: 10004
182503:48:34 T:140030437029952 DEBUG: ------ Window Deinit (Home.xml) ------
182603:48:34 T:140030437029952 DEBUG: ------ Window Init (Settings.xml) ------
182703:48:34 T:140030437029952 INFO: Loading skin file: Settings.xml, load type: KEEP_IN_MEMORY
182803:48:36 T:140030437029952 DEBUG: started alarm with name: setfocus
182903:48:36 T:140028747323136 DEBUG: DoWork - took 160 ms to load special://skin/extras/backgrounds/appearance.jpg
183003:48:36 T:140028696966912 DEBUG: CPythonInvoker(19, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): setting the Python path to /home/jamesz/.kodi/addons/script.skinshortcuts:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/home/jamesz/.kodi/addons/script.module.unidecode/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
183103:48:36 T:140028696966912 DEBUG: CPythonInvoker(19, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): entering source directory /home/jamesz/.kodi/addons/script.skinshortcuts
183203:48:36 T:140028696966912 DEBUG: CPythonInvoker(19, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): instantiating addon using automatically obtained id of "script.skinshortcuts" dependent on version 2.20.0 of the xbmc.python api
183303:48:37 T:140027526895360 DEBUG: -->Python Interpreter Initialized<--
183403:48:37 T:140027526895360 DEBUG: CPythonInvoker(20, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): the source file to load is "/home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py"
183503:48:37 T:140027526895360 DEBUG: CPythonInvoker(20, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): setting the Python path to /home/jamesz/.kodi/addons/script.skin.helper.service:/home/jamesz/.kodi/addons/script.module.beautifulsoup/lib:/home/jamesz/.kodi/addons/script.module.requests/lib:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/share/kodi/addons/script.module.pil/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
183603:48:37 T:140027526895360 DEBUG: CPythonInvoker(20, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): entering source directory /home/jamesz/.kodi/addons/script.skin.helper.service
183703:48:37 T:140027526895360 DEBUG: CPythonInvoker(20, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): instantiating addon using automatically obtained id of "script.skin.helper.service" dependent on version 2.13.0 of the xbmc.python api
183803:48:37 T:140028738930432 DEBUG: RunQuery took 12 ms for 67 items query: select * from movie_view WHERE (movie_view.idFile IN (SELECT DISTINCT idFile FROM bookmark WHERE type = 1))
183903:48:37 T:140030437029952 DEBUG: LIRC: Update - NEW at 5632316:000000037ff07be1 00 KEY_UP mceusb (KEY_UP)
184003:48:37 T:140030437029952 DEBUG: OnKey: 166 (0xa6) pressed, action is Up
184103:48:38 T:140030437029952 DEBUG: LIRC: Update - NEW at 5632982:000000037ff07be1 00 KEY_UP mceusb (KEY_UP)
184203:48:38 T:140030437029952 DEBUG: OnKey: 166 (0xa6) pressed, action is Up
184303:48:38 T:140027250067200 DEBUG: WaitOnScriptResult- plugin returned successfully
184403:48:38 T:140027250067200 INFO: WEATHER: Downloading weather
184503:48:38 T:140027126015744 DEBUG: Thread LanguageInvoker start, auto delete: false
184603:48:38 T:140027126015744 INFO: initializing python engine.
184703:48:38 T:140027126015744 DEBUG: CPythonInvoker(21, /home/jamesz/.kodi/addons/weather.yahoo/default.py): start processing
184803:48:38 T:140028722145024 INFO: CPythonInvoker(18, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
184903:48:38 T:140030437029952 DEBUG: LIRC: Update - NEW at 5633598:000000037ff07be1 00 KEY_UP mceusb (KEY_UP)
185003:48:38 T:140030437029952 DEBUG: OnKey: 166 (0xa6) pressed, action is Up
185103:48:39 T:140028738930432 DEBUG: RunQuery took 19 ms for 35 items query: select * from movie_view WHERE ((movie_view.playCount IS NULL OR movie_view.playCount = 0)) AND ((CAST(movie_view.c05 as DECIMAL(5,1)) > 7))
185203:48:39 T:140030437029952 DEBUG: LIRC: Update - NEW at 5634542:000000037ff07be1 00 KEY_UP mceusb (KEY_UP)
185303:48:39 T:140030437029952 DEBUG: OnKey: 166 (0xa6) pressed, action is Up
185403:48:40 T:140030437029952 DEBUG: LIRC: Update - NEW at 5635117:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
185503:48:40 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
185603:48:40 T:140030437029952 DEBUG: Activating window ID: 10018
185703:48:40 T:140030437029952 DEBUG: ------ Window Deinit (Settings.xml) ------
185803:48:40 T:140030437029952 DEBUG: ------ Window Init (SettingsCategory.xml) ------
185903:48:40 T:140030437029952 INFO: Loading skin file: SettingsCategory.xml, load type: KEEP_IN_MEMORY
186003:48:42 T:140028722145024 INFO: Python script stopped
186103:48:42 T:140028722145024 DEBUG: Thread LanguageInvoker 140028722145024 terminating
186203:48:43 T:140027126015744 DEBUG: -->Python Interpreter Initialized<--
186303:48:43 T:140027126015744 DEBUG: CPythonInvoker(21, /home/jamesz/.kodi/addons/weather.yahoo/default.py): the source file to load is "/home/jamesz/.kodi/addons/weather.yahoo/default.py"
186403:48:43 T:140027126015744 DEBUG: CPythonInvoker(21, /home/jamesz/.kodi/addons/weather.yahoo/default.py): setting the Python path to /home/jamesz/.kodi/addons/weather.yahoo:/home/jamesz/.kodi/addons/script.module.simplejson/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-x86_64-linux-gnu:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0
186503:48:43 T:140027126015744 DEBUG: CPythonInvoker(21, /home/jamesz/.kodi/addons/weather.yahoo/default.py): entering source directory /home/jamesz/.kodi/addons/weather.yahoo
186603:48:43 T:140027126015744 DEBUG: CPythonInvoker(21, /home/jamesz/.kodi/addons/weather.yahoo/default.py): instantiating addon using automatically obtained id of "weather.yahoo" dependent on version 2.19.0 of the xbmc.python api
186703:48:43 T:140027526895360 DEBUG: RunQuery took 23 ms for 97 items query: select * from movie_view WHERE ((movie_view.playCount IS NULL OR movie_view.playCount = 0))
186803:48:45 T:140027535288064 DEBUG: WaitOnScriptResult- plugin returned successfully
186903:48:45 T:140027535288064 INFO: easy_aquire - Created session to http://www.msftncsi.com
187003:48:45 T:140028738930432 INFO: CPythonInvoker(17, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
187103:48:45 T:140028738930432 INFO: Python script stopped
187203:48:45 T:140028738930432 DEBUG: Thread LanguageInvoker 140028738930432 terminating
187303:48:45 T:140027126015744 DEBUG: weather.yahoo: version 3.3.2 started: ['/home/jamesz/.kodi/addons/weather.yahoo/default.py', '1']
187403:48:45 T:140028696966912 INFO: CPythonInvoker(19, /home/jamesz/.kodi/addons/script.skinshortcuts/default.py): script successfully run
187503:48:45 T:140028696966912 INFO: Python script stopped
187603:48:45 T:140028696966912 DEBUG: Thread LanguageInvoker 140028696966912 terminating
187703:48:46 T:140027126015744 DEBUG: weather.yahoo: weather location: 12761689
187803:48:46 T:140028332201728 DEBUG: WaitOnScriptResult- plugin returned successfully
187903:48:46 T:140027526895360 INFO: CPythonInvoker(20, /home/jamesz/.kodi/addons/script.skin.helper.service/plugin.py): script successfully run
188003:48:46 T:140027526895360 INFO: Python script stopped
188103:48:46 T:140027526895360 DEBUG: Thread LanguageInvoker 140027526895360 terminating
188203:48:47 T:140027126015744 DEBUG: weather.yahoo: forecast data: {"query":{"count":1,"created":"2016-12-26T08:48:46Z","lang":"en-US","results":{"channel":{"units":{"distance":"km","pressure":"mb","speed":"km/h","temperature":"C"},"title":"Yahoo! Weather - Elmont, NY, US","link":"http://us.rd.yahoo.com/dailynews/rss/weather/Country__Country/*https://weather.yahoo.com/country/state/city-12761689/","description":"Yahoo! Weather for Elmont, NY, US","language":"en-us","lastBuildDate":"Mon, 26 Dec 2016 03:48 AM EST","ttl":"60","location":{"city":"Elmont","country":"United States","region":" NY"},"wind":{"chill":"27","direction":"55","speed":"22.53"},"atmosphere":{"humidity":"53","pressure":"35150.73","rising":"0","visibility":"25.91"},"astronomy":{"sunrise":"7:18 am","sunset":"4:34 pm"},"image":{"title":"Yahoo! Weather","width":"142","height":"18","link":"http://weather.yahoo.com","url":"http://l.yimg.com/a/i/brand/purplelogo//uh/us/news-wea.gif"},"item":{"title":"Conditions for Elmont, NY, US at 02:00 AM EST","lat":"40.70134","long":"-73.707787","link":"http://us.rd.yahoo.com/dailynews/rss/weather/Country__Country/*https://weather.yahoo.com/country/state/city-12761689/","pubDate":"Mon, 26 Dec 2016 02:00 AM EST","condition":{"code":"29","date":"Mon, 26 Dec 2016 02:00 AM EST","temp":"1","text":"Partly Cloudy"},"forecast":[{"code":"28","date":"26 Dec 2016","day":"Mon","high":"11","low":"1","text":"Mostly Cloudy"},{"code":"12","date":"27 Dec 2016","day":"Tue","high":"13","low":"6","text":"Rain"},{"code":"32","date":"28 Dec 2016","day":"Wed","high":"5","low":"1","text":"Sunny"},{"code":"39","date":"29 Dec 2016","day":"Thu","high":"8","low":"2","text":"Scattered Showers"},{"code":"23","date":"30 Dec 2016","day":"Fri","high":"4","low":"1","text":"Breezy"},{"code":"30","date":"31 Dec 2016","day":"Sat","high":"2","low":"0","text":"Partly Cloudy"},{"code":"28","date":"01 Jan 2017","day":"Sun","high":"7","low":"3","text":"Mostly Cloudy"},{"code":"39","date":"02 Jan 2017","day":"Mon","high":"6","low":"3","text":"Scattered Showers"},{"code":"39","date":"03 Jan 2017","day":"Tue","high":"8","low":"6","text":"Scattered Showers"},{"code":"28","date":"04 Jan 2017","day":"Wed","high":"6","low":"3","text":"Mostly Cloudy"}],"description":"<![CDATA[<img src=\"http://l.yimg.com/a/i/us/we/52/29.gif\"/>\n<BR />\n<b>Current Conditions:</b>\n<BR />Partly Cloudy\n<BR />\n<BR />\n<b>Forecast:</b>\n<BR /> Mon - Mostly Cloudy. High: 11Low: 1\n<BR /> Tue - Rain. High: 13Low: 6\n<BR /> Wed - Sunny. High: 5Low: 1\n<BR /> Thu - Scattered Showers. High: 8Low: 2\n<BR /> Fri - Breezy. High: 4Low: 1\n<BR />\n<BR />\n<a href=\"http://us.rd.yahoo.com/dailynews/rss/weather/Country__Country/*https://weather.yahoo.com/country/state/city-12761689/\">Full Forecast at Yahoo! Weather</a>\n<BR />\n<BR />\n(provided by <a href=\"http://www.weather.com\" >The Weather Channel</a>)\n<BR />\n]]>","guid":{"isPermaLink":"false"}}}}}}
188303:48:47 T:140027126015744 DEBUG: weather.yahoo: available locations: 1
188403:48:47 T:140027126015744 DEBUG: weather.yahoo: finished
188503:48:47 T:140027126015744 INFO: CPythonInvoker(21, /home/jamesz/.kodi/addons/weather.yahoo/default.py): script successfully run
188603:48:47 T:140027126015744 INFO: Python script stopped
188703:48:47 T:140027126015744 DEBUG: Thread LanguageInvoker 140027126015744 terminating
188803:48:47 T:140027250067200 DEBUG: POParser: loaded 130 weather tokens
188903:48:48 T:140030437029952 DEBUG: LIRC: Update - NEW at 5643241:000000037ff07bdc 00 KEY_BACK mceusb (KEY_BACK)
189003:48:48 T:140030437029952 DEBUG: OnKey: menu (0xd8) pressed, action is PreviousMenu
189103:48:48 T:140030437029952 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
189203:48:48 T:140030437029952 DEBUG: ------ Window Deinit (SettingsCategory.xml) ------
189303:48:48 T:140030437029952 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
189403:48:48 T:140030437029952 DEBUG: ------ Window Init (Settings.xml) ------
189503:48:48 T:140030437029952 DEBUG: started alarm with name: setfocus
189603:48:49 T:140030437029952 DEBUG: LIRC: Update - NEW at 5644518:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
189703:48:49 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
189803:48:50 T:140030437029952 DEBUG: LIRC: Update - NEW at 5645202:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
189903:48:50 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
190003:48:50 T:140030437029952 DEBUG: Activating window ID: 10016
190103:48:50 T:140030437029952 DEBUG: ------ Window Deinit (Settings.xml) ------
190203:48:50 T:140030437029952 DEBUG: ------ Window Init (SettingsCategory.xml) ------
190303:48:52 T:140030437029952 DEBUG: LIRC: Update - NEW at 5646902:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
190403:48:52 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
190503:48:53 T:140030437029952 DEBUG: Previous line repeats 6 times.
190603:48:53 T:140030437029952 DEBUG: LIRC: Update - NEW at 5648435:000000037ff07be1 00 KEY_UP mceusb (KEY_UP)
190703:48:53 T:140030437029952 DEBUG: OnKey: 166 (0xa6) pressed, action is Up
190803:48:54 T:140030437029952 DEBUG: LIRC: Update - NEW at 5649255:000000037ff07be1 00 KEY_UP mceusb (KEY_UP)
190903:48:54 T:140030437029952 DEBUG: OnKey: 166 (0xa6) pressed, action is Up
191003:48:55 T:140030437029952 DEBUG: LIRC: Update - NEW at 5649888:000000037ff07bde 00 KEY_RIGHT mceusb (KEY_RIGHT)
191103:48:55 T:140030437029952 DEBUG: OnKey: 168 (0xa8) pressed, action is Right
191203:48:57 T:140030437029952 DEBUG: LIRC: Update - NEW at 5652303:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
191303:48:57 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
191403:48:58 T:140030437029952 DEBUG: LIRC: Update - NEW at 5652903:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
191503:48:58 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
191603:48:58 T:140030437029952 DEBUG: LIRC: Update - NEW at 5653419:000000037ff07be0 00 KEY_DOWN mceusb (KEY_DOWN)
191703:48:58 T:140030437029952 DEBUG: OnKey: 167 (0xa7) pressed, action is Down
191803:48:59 T:140030437029952 DEBUG: LIRC: Update - NEW at 5654436:000000037ff07bdd 00 KEY_OK mceusb (KEY_OK)
191903:48:59 T:140030437029952 DEBUG: OnKey: 11 (0x0b) pressed, action is Select
192003:48:59 T:140030437029952 NOTICE: Disabled debug logging due to GUI setting. Level 0.
192103:48:59 T:140030437029952 NOTICE: Log level changed to "LOG_LEVEL_NORMAL"
192203:49:11 T:140030437029952 NOTICE: Storing total System Uptime
192303:49:11 T:140030437029952 NOTICE: Saving settings
192403:49:11 T:140030437029952 NOTICE: stop all
192503:49:11 T:140030437029952 NOTICE: stop player
192603:49:11 T:140030437029952 NOTICE: ES: Stopping event server
192703:49:11 T:140030437029952 NOTICE: stopping upnp
192803:49:11 T:140027979872000 NOTICE: ES: UDP Event server stopped
192903:49:12 T:140030437029952 NOTICE: stopping zeroconf publishing
193003:49:12 T:140030437029952 NOTICE: WebServer: Stopped the webserver
193103:49:12 T:140030437029952 NOTICE: stop dvd detect media
193203:49:12 T:140030437029952 NOTICE: stop sap announcement listener
193303:49:12 T:140030437029952 NOTICE: clean cached files!
193403:49:12 T:140030437029952 NOTICE: unload skin
193503:49:12 T:140030437029952 WARNING: Cleanup: Having to cleanup texture diffuse/panel.png
193603:49:12 T:140029263333120 NOTICE: 1Channel: Service: shutting down...
193703:49:12 T:140029280118528 NOTICE: Skin Helper Service --> Shutdown requested !
193803:49:12 T:140029280118528 NOTICE: Skin Helper Service --> BackgroundsUpdater - stop called
193903:49:12 T:140029280118528 NOTICE: Skin Helper Service --> ListItemMonitor - stop called
194003:49:12 T:140029280118528 NOTICE: Skin Helper Service --> WebService - stop called
194103:49:12 T:140029280118528 NOTICE: Skin Helper Service --> skin helper service version 1.0.100 stopped
194203:49:13 T:140029271725824 NOTICE: script.tv.show.next.aired: ### abort requested -- stopping background processing
194303:49:14 T:140030437029952 NOTICE: stopped
194403:49:14 T:140030437029952 NOTICE: destroy
194503:49:14 T:140030437029952 NOTICE: closing down remote control service
194603:49:14 T:140030437029952 NOTICE: unload sections
194703:49:14 T:140030437029952 NOTICE: special://profile/ is mapped to: special://masterprofile/
194803:49:14 T:140030437029952 NOTICE: destroy
194903:49:14 T:140030437029952 WARNING: Attempted to remove window 10013 from the window manager when it didn't exist
195003:49:14 T:140030437029952 WARNING: Attempted to remove window 10014 from the window manager when it didn't exist
195103:49:14 T:140030437029952 WARNING: Attempted to remove window 10015 from the window manager when it didn't exist
195203:49:14 T:140030437029952 WARNING: Attempted to remove window 10016 from the window manager when it didn't exist
195303:49:14 T:140030437029952 WARNING: Attempted to remove window 10017 from the window manager when it didn't exist
195403:49:14 T:140030437029952 WARNING: Attempted to remove window 10018 from the window manager when it didn't exist
195503:49:14 T:140030437029952 WARNING: Attempted to remove window 10019 from the window manager when it didn't exist
195603:49:14 T:140030437029952 WARNING: Attempted to remove window 10021 from the window manager when it didn't exist
195703:49:14 T:140030437029952 WARNING: Attempted to remove window 10107 from the window manager when it didn't exist
195803:49:14 T:140030437029952 WARNING: Attempted to remove window 10115 from the window manager when it didn't exist
195903:49:14 T:140030437029952 WARNING: Attempted to remove window 10104 from the window manager when it didn't exist
196003:49:14 T:140030437029952 NOTICE: closing down remote control service
196103:49:14 T:140030437029952 NOTICE: unload sections
196203:49:14 T:140030437029952 NOTICE: application stopped...