search

Pulse-Eight / libcec

USB CEC Adapter communication Library http://libcec.pulse-eight.com/
Other
713 stars 287 forks source link

Onkyo Reciever Shuts Off a few seconds after being woken up from resume #143

Closed josh4trunks closed 8 years ago

josh4trunks commented 8 years ago

OS - OpenELEC 5.95.5 x64 CPU/Motherboard - Asrock J1900 CEC - Pulse-Eight USB adapter with v4 firmware Receiver - Onkyo TX-SR309 TV - Panasonic TC-50PU54

Description When I wakeup my openelec box from suspend I wait a few seconds until I hear the click of the TV and reciever being woken from CEC. But, after a few more seconds the receiever shuts off. This was not a problem with version 5.0.8

Debug Log

19:59:53 T:140583711201152  NOTICE: special://profile/ is mapped to: special://masterprofile/
19:59:53 T:140583711201152  NOTICE: -----------------------------------------------------------------------
19:59:53 T:140583711201152  NOTICE: Starting Kodi (15.1 Git:f4dda26). Platform: Linux x86 64-bit
19:59:53 T:140583711201152  NOTICE: Using Release Kodi x64 build
19:59:53 T:140583711201152  NOTICE: Kodi compiled Sep  4 2015 by GCC 4.9.3 for Linux x86 64-bit version 4.1.6 (262406)
19:59:53 T:140583711201152  NOTICE: Running on OpenELEC (official) - Version: 5.95.5 6.0, kernel: Linux x86 64-bit version 4.1.6
19:59:53 T:140583711201152  NOTICE: FFmpeg version: 2.6.4
19:59:53 T:140583711201152  NOTICE: WARNING: unsupported ffmpeg version detected
19:59:53 T:140583711201152  NOTICE: Host CPU: Intel(R) Celeron(R) CPU J1800 @ 2.41GHz, 2 cores available
19:59:53 T:140583711201152  NOTICE: special://xbmc/ is mapped to: /usr/share/kodi
19:59:53 T:140583711201152  NOTICE: special://xbmcbin/ is mapped to: /usr/lib/kodi
19:59:53 T:140583711201152  NOTICE: special://masterprofile/ is mapped to: /storage/.kodi/userdata
19:59:53 T:140583711201152  NOTICE: special://home/ is mapped to: /storage/.kodi
19:59:53 T:140583711201152  NOTICE: special://temp/ is mapped to: /storage/.kodi/temp
19:59:53 T:140583711201152  NOTICE: The executable running is: /usr/lib/kodi/kodi.bin
19:59:53 T:140583711201152  NOTICE: Local hostname: OpenELEC
19:59:53 T:140583711201152  NOTICE: Log File is located: /storage/.kodi/temp/kodi.log
19:59:53 T:140583711201152  NOTICE: -----------------------------------------------------------------------
19:59:53 T:140583711201152   ERROR: DBus: Error org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.UPower was not provided by any .service files
19:59:53 T:140583711201152  NOTICE: load settings...
19:59:53 T:140583711184640  NOTICE: Thread FDEventMonitor start, auto delete: false
19:59:53 T:140583711201152  NOTICE: Found 1 Lists of Devices
19:59:53 T:140583711201152  NOTICE: Enumerated ALSA devices:
19:59:53 T:140583711201152  NOTICE:     Device 1
19:59:53 T:140583711201152  NOTICE:         m_deviceName      : @
19:59:53 T:140583711201152  NOTICE:         m_displayName     : Default (HDA Intel PCH ALC662 rev1 Analog)
19:59:53 T:140583711201152  NOTICE:         m_displayNameExtra:
19:59:53 T:140583711201152  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
19:59:53 T:140583711201152  NOTICE:         m_channels        : FL,FR
19:59:53 T:140583711201152  NOTICE:         m_sampleRates     : 48000
19:59:53 T:140583711201152  NOTICE:         m_dataFormats     : AE_FMT_S32NE
19:59:53 T:140583711201152  NOTICE:     Device 2
19:59:53 T:140583711201152  NOTICE:         m_deviceName      : @:CARD=PCH,DEV=0
19:59:53 T:140583711201152  NOTICE:         m_displayName     : HDA Intel PCH
19:59:53 T:140583711201152  NOTICE:         m_displayNameExtra: ALC662 rev1 Analog
19:59:53 T:140583711201152  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
19:59:53 T:140583711201152  NOTICE:         m_channels        : FL,FR
19:59:53 T:140583711201152  NOTICE:         m_sampleRates     : 48000
19:59:53 T:140583711201152  NOTICE:         m_dataFormats     : AE_FMT_S32NE
19:59:53 T:140583711201152  NOTICE:     Device 3
19:59:53 T:140583711201152  NOTICE:         m_deviceName      : hdmi:CARD=PCH,DEV=0
19:59:53 T:140583711201152  NOTICE:         m_displayName     : HDA Intel PCH
19:59:53 T:140583711201152  NOTICE:         m_displayNameExtra: ONK TX-SR309 on HDMI
19:59:53 T:140583711201152  NOTICE:         m_deviceType      : AE_DEVTYPE_HDMI
19:59:53 T:140583711201152  NOTICE:         m_channels        : FL,FR,LFE,FC,BL,BR
19:59:53 T:140583711201152  NOTICE:         m_sampleRates     : 32000,44100,48000,88200,96000,176400,192000
19:59:53 T:140583711201152  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
19:59:53 T:140583711201152  NOTICE:     Device 4
19:59:53 T:140583711201152  NOTICE:         m_deviceName      : hdmi:CARD=PCH,DEV=1
19:59:53 T:140583711201152  NOTICE:         m_displayName     : HDA Intel PCH
19:59:53 T:140583711201152  NOTICE:         m_displayNameExtra: HDMI
19:59:53 T:140583711201152  NOTICE:         m_deviceType      : AE_DEVTYPE_HDMI
19:59:53 T:140583711201152  NOTICE:         m_channels        : FL,FR,LFE,FC,BC,BL,BR,FLOC,FROC,BLOC,BROC,TFC,TC,TFL,TFR,UNKNOWN1
19:59:53 T:140583711201152  NOTICE:         m_sampleRates     : 32000,44100,48000,88200,96000,176400,192000
19:59:53 T:140583711201152  NOTICE:         m_dataFormats     : AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE,AE_FMT_LPCM,AE_FMT_DTSHD,AE_FMT_TRUEHD,AE_FMT_EAC3,AE_FMT_DTS,AE_FMT_AC3,AE_FMT_AAC
19:59:53 T:140583711201152  NOTICE: Loaded settings file from special://xbmc/system/advancedsettings.xml
19:59:53 T:140583711201152  NOTICE: Contents of special://xbmc/system/advancedsettings.xml are...
                                            <?xml version="1.0" encoding="UTF-8" ?>
                                            <advancedsettings>
                                              <showexitbutton>false</showexitbutton>
                                              <cputempcommand>cputemp</cputempcommand>
                                              <gputempcommand>gputemp</gputempcommand>
                                              <video>
                                                <latency>
                                                  <delay>0</delay>
                                                  <refresh>
                                                    <min>23</min>
                                                    <max>24</max>
                                                    <delay>175</delay>
                                                  </refresh>
                                                </latency>
                                                <busydialogdelayms>750</busydialogdelayms>
                                              </video>
                                              <samba>
                                                <clienttimeout>30</clienttimeout>
                                              </samba>
                                              <network>
                                                <readbufferfactor>4.0</readbufferfactor>
                                              </network>
                                            </advancedsettings>
19:59:53 T:140583711201152  NOTICE: No settings file to load (special://masterprofile/advancedsettings.xml)
19:59:53 T:140583711201152  NOTICE: Default DVD Player: dvdplayer
19:59:53 T:140583711201152  NOTICE: Default Video Player: dvdplayer
19:59:53 T:140583711201152  NOTICE: Default Audio Player: paplayer
19:59:53 T:140583711201152  NOTICE: Enabled debug logging due to GUI setting (2)
19:59:53 T:140583711201152  NOTICE: Log level changed to "LOG_LEVEL_DEBUG_FREEMEM"
19:59:53 T:140583711201152  NOTICE: CMediaSourceSettings: loading media sources from special://masterprofile/sources.xml
19:59:53 T:140583711201152   DEBUG: CMediaSourceSettings: <programs> tag is missing or sources.xml is malformed
19:59:53 T:140583711201152   DEBUG: CMediaSourceSettings: <files> tag is missing or sources.xml is malformed
19:59:53 T:140583711201152  NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
19:59:53 T:140583711201152   DEBUG: CPlayerCoreConfig::<ctor>: created player DVDPlayer for core 1
19:59:53 T:140583711201152   DEBUG: CPlayerCoreConfig::<ctor>: created player oldmplayercore for core 1
19:59:53 T:140583711201152   DEBUG: CPlayerCoreConfig::<ctor>: created player PAPlayer for core 3
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: system rules
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: hdhomerun/mms/udp
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: lastfm/shout
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: rtmp
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: rtsp
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: streams
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: aacp/sdp
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: mp2
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: dvd
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: dvdimage
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: sdp/asf
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: nsv
19:59:53 T:140583711201152   DEBUG: CPlayerSelectionRule::Initialize: creating rule: radio
19:59:53 T:140583711201152  NOTICE: Loaded playercorefactory configuration
19:59:53 T:140583711201152  NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
19:59:53 T:140583711201152  NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
19:59:53 T:140583711201152    INFO: creating subdirectories
19:59:53 T:140583711201152    INFO: userdata folder: special://masterprofile/
19:59:53 T:140583711201152    INFO: recording folder:
19:59:53 T:140583711201152    INFO: screenshots folder: /storage/screenshots/
19:59:53 T:140583700645632  NOTICE: Thread ActiveAE start, auto delete: false
19:59:53 T:140583692252928  NOTICE: Thread AESink start, auto delete: false
19:59:53 T:140583692252928    INFO: CActiveAESink::OpenSink - initialize sink
19:59:53 T:140583692252928   DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=PCH,DEV=0
19:59:53 T:140583692252928    INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=PCH,DEV=0"
19:59:53 T:140583692252928    INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=PCH,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
19:59:53 T:140583692252928    INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
19:59:53 T:140583692252928    INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
19:59:53 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
19:59:53 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
19:59:53 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
19:59:53 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
19:59:53 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
19:59:53 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
19:59:53 T:140583692252928   DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
19:59:53 T:140583692252928   DEBUG:   Output Device : HDA Intel PCH
19:59:53 T:140583692252928   DEBUG:   Sample Rate   : 44100
19:59:53 T:140583692252928   DEBUG:   Sample Format : AE_FMT_S32NE
19:59:53 T:140583692252928   DEBUG:   Channel Count : 2
19:59:53 T:140583692252928   DEBUG:   Channel Layout: FL,FR
19:59:53 T:140583692252928   DEBUG:   Frames        : 2048
19:59:53 T:140583692252928   DEBUG:   Frame Samples : 4096
19:59:53 T:140583692252928   DEBUG:   Frame Size    : 8
19:59:53 T:140583711201152  NOTICE: Running database version Addons19
19:59:53 T:140583711201152   DEBUG: SECTION:LoadDLL(special://xbmcbin/system/libcpluff-x86_64-linux.so)
19:59:53 T:140583711201152   DEBUG: Loading: /usr/lib/kodi/system/libcpluff-x86_64-linux.so
19:59:53 T:140583711201152    INFO: ADDON: cpluff: 'Could not read plug-in directory /usr/lib/kodi/addons: No such file or directory'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.json has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.audio.pandora has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.fanart.tv has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.audioencoder has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in webinterface.default has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in repository.xbmc.org has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in kodi.audiodecoder has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in program.plexus has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in visualization.vortex has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in service.openelec.settings has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in screensaver.xbmc.builtin.black has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in kodi.guilib has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in audioencoder.xbmc.builtin.wma has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in plugin.video.twit has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in repository.emby.kodi has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in screensaver.xbmc.builtin.dim has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.module.beautifulsoup4 has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.themoviedb.org has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.metadata has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in skin.confluence has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in kodi.resource has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.gui has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.module.pil has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.common.plugin.cache has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in repository.openelec.tv has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in os.openelec.tv has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.musicvideos.theaudiodb.com has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.module.simple.downloader has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.core has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in plugin.video.youtube has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.module.requests has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.pvr has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in audioencoder.xbmc.builtin.aac has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.album.universal has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.htbackdrops.com has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in plugin.video.emby has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in resource.language.en_gb has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.allmusic.com has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.musicbrainz.org has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.tvdb.com has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.local has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.webinterface has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in resource.uisounds.confluence has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.last.fm has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.themoviedb.org has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.theaudiodb.com has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in script.module.parsedom has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.artists.universal has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.python has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in metadata.common.imdb.com has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in plugin.video.SportsDevil has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.addon has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Plug-in xbmc.codec has been installed.'
19:59:53 T:140583711201152   DEBUG: ADDON: cpluff: 'Not all directories were successfully scanned.'
19:59:53 T:140583711201152  NOTICE: ADDONS: Using repository repository.xbmc.org
19:59:53 T:140583711201152  NOTICE: ADDONS: Using repository program.plexus
19:59:53 T:140583711201152  NOTICE: ADDONS: Using repository repository.emby.kodi
19:59:53 T:140583711201152  NOTICE: ADDONS: Using repository repository.openelec.tv
19:59:53 T:140583711201152   DEBUG: LoadMappings - loaded node "Motorola Nyxboard Hybrid"
19:59:53 T:140583711201152   DEBUG: LoadMappings - loaded node "CEC Adapter"
19:59:53 T:140583711201152   DEBUG: LoadMappings - loaded node "Pulse-Eight CEC Adapter"
19:59:53 T:140583711201152   DEBUG: LoadMappings - loaded node "iMON HID device"
19:59:53 T:140583711201152   DEBUG: CPeripheralBusUSB - initialised udev monitor
19:59:53 T:140583711201152   DEBUG: SECTION:LoadDLL(libcec.so.3.0)
19:59:53 T:140583711201152   DEBUG: Loading: libcec.so.3.0
19:59:53 T:140583711201152   DEBUG: GetMappingForDevice - device (2548:1002) mapped to CEC Adapter (type = cec)
19:59:53 T:140583711201152   DEBUG: InitialiseFeature - using libCEC v3.0.0
19:59:53 T:140583711201152   DEBUG: Initialise - initialised peripheral on '/dev/ttyACM0' with 2 features and 0 sub devices
19:59:53 T:140583711201152  NOTICE: Register - new cec device registered on cec->/dev/ttyACM0: CEC Adapter (2548:1002)
19:59:53 T:140583456724736  NOTICE: Thread CECAdapter start, auto delete: false
19:59:53 T:140583456724736   DEBUG: OpenConnection - opening a connection to the CEC adapter: /dev/ttyACM0
19:59:53 T:140583448332032  NOTICE: Thread PeripBusCEC start, auto delete: false
19:59:53 T:140583465117440   DEBUG: CecLogMessage - Broadcast (F): osd name set to 'Broadcast'
19:59:53 T:140583465117440   DEBUG: CecLogMessage - connection opened, clearing any previous input and waiting for active transmissions to end before starting
19:59:53 T:140583465117440   DEBUG: CecLogMessage - communication thread started
19:59:53 T:140583465117440   DEBUG: CecLogMessage - turning controlled mode on
19:59:53 T:140583711201152   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
19:59:53 T:140583423153920  NOTICE: Thread PeripBusUSBUdev start, auto delete: false
19:59:53 T:140583070856960  NOTICE: Thread RemoteControl start, auto delete: false
19:59:53 T:140583070856960    INFO: LIRC Process: using: /run/lirc/lircd
19:59:53 T:140583070856960    INFO: LIRC Connect: successfully started
19:59:53 T:140583070856960   DEBUG: Thread RemoteControl 140583070856960 terminating
19:59:53 T:140583711201152    INFO: CKeyboardLayoutManager: loading keyboard layouts from special://xbmc/system/keyboardlayouts...
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Arabic QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Bulgarian ЯВЕРТЪ" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Bulgarian АБВ" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Danish QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "English QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "English AZERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "English ABC" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "German QWERTZ" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Greek QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Hebrew QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Hebrew ABC" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Hungarian QWERTZ" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Lithuanian AZERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Lithuanian QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Norwegian QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Polish QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Portuguese (Portugal) QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Romanian QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Russian ЙЦУКЕН" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Russian АБВ" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Spanish QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Swedish QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Turkish QWERTY" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Ukrainian ЙЦУКЕН" successfully loaded
19:59:53 T:140583711201152   DEBUG: CKeyboardLayoutManager: keyboard layout "Ukrainian АБВ" successfully loaded
19:59:53 T:140583465117440   DEBUG: CecLogMessage - connection opened
19:59:53 T:140583711201152   DEBUG: UDisks: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.UDisks was not provided by any .service files
19:59:53 T:140583711201152   DEBUG: DeviceKit.Disks: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.DeviceKit.Disks was not provided by any .service files
19:59:53 T:140583711201152   DEBUG: Selected UDev as storage provider
19:59:53 T:140583711201152  NOTICE: Setup SDL
19:59:53 T:140583465117440   DEBUG: CecLogMessage - << Broadcast (F) -> TV (0): POLL
19:59:53 T:140583465117440   DEBUG: CecLogMessage - << f0
19:59:53 T:140583465117440   DEBUG: CecLogMessage - setting the line timeout to 3
19:59:53 T:140583465117440   DEBUG: CecLogMessage - processor thread started
19:59:53 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
19:59:53 T:140583465117440   DEBUG: CecLogMessage - >> POLL sent
19:59:53 T:140583465117440   DEBUG: CecLogMessage - TV (0): device status changed into 'present'
19:59:53 T:140583465117440   DEBUG: CecLogMessage - << requesting vendor ID of 'TV' (0)
19:59:53 T:140583465117440   DEBUG: CecLogMessage - << f0:8c
19:59:53 T:140583711201152    INFO: Available videomodes (xrandr):
19:59:53 T:140583711201152    INFO: Output 'HDMI1' has 20 modes
19:59:53 T:140583711201152    INFO: ID:0x49 Name:1920x1080 Refresh:60.000000 Width:1920 Height:1080
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xe8 Name:1920x1080 Refresh:59.940201 Width:1920 Height:1080
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xea Name:1920x1080 Refresh:24.000000 Width:1920 Height:1080
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xec Name:1920x1080 Refresh:23.976080 Width:1920 Height:1080
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xe9 Name:1920x1080i Refresh:30.000000 Width:1920 Height:1080
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xeb Name:1920x1080i Refresh:29.970100 Width:1920 Height:1080
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xed Name:2880x480 Refresh:60.000000 Width:2880 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 0.296769
19:59:53 T:140583711201152    INFO: ID:0xee Name:2880x480 Refresh:59.940060 Width:2880 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 0.296769
19:59:53 T:140583711201152    INFO: ID:0xef Name:2880x480i Refresh:30.000000 Width:2880 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 0.296769
19:59:53 T:140583711201152    INFO: ID:0xf0 Name:2880x480i Refresh:29.970030 Width:2880 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 0.296769
19:59:53 T:140583711201152    INFO: ID:0xf1 Name:1280x720 Refresh:60.000000 Width:1280 Height:720
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xf2 Name:1280x720 Refresh:59.940201 Width:1280 Height:720
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.001594
19:59:53 T:140583711201152    INFO: ID:0xf3 Name:1440x480 Refresh:60.000000 Width:1440 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 0.593537
19:59:53 T:140583711201152    INFO: ID:0xf4 Name:1440x480 Refresh:59.940060 Width:1440 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 0.593537
19:59:53 T:140583711201152    INFO: ID:0xf5 Name:720x480 Refresh:60.000000 Width:720 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.187075
19:59:53 T:140583711201152    INFO: ID:0xf6 Name:720x480 Refresh:59.940060 Width:720 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.187075
19:59:53 T:140583711201152    INFO: ID:0xf7 Name:720x480i Refresh:29.998890 Width:720 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.187075
19:59:53 T:140583711201152    INFO: ID:0xf8 Name:720x480i Refresh:29.970030 Width:720 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.187075
19:59:53 T:140583711201152    INFO: ID:0xf9 Name:640x480 Refresh:60.000000 Width:640 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.335459
19:59:53 T:140583711201152    INFO: ID:0xfa Name:640x480 Refresh:59.940479 Width:640 Height:480
19:59:53 T:140583711201152    INFO: Pixel Ratio: 1.335459
19:59:53 T:140583711201152  NOTICE: Checking resolution 16
19:59:54 T:140583711201152   DEBUG: Window Manager Name: Fluxbox
19:59:54 T:140583711201152   ERROR: CWinSystemX11::XErrorHandler: BadAtom (invalid Atom parameter), type:0, serial:38, error_code:5, request_code:18 minor_code:0
19:59:54 T:140583711201152   DEBUG: SECTION:LoadDLL(special://xbmcbin/system/ImageLib-x86_64-linux.so)
19:59:54 T:140583711201152   DEBUG: Loading: /usr/lib/kodi/system/ImageLib-x86_64-linux.so
19:59:54 T:140583711201152  NOTICE: Using visual 0x20
19:59:54 T:140583711201152    INFO: GL: Maximum texture width: 8192
19:59:54 T:140583711201152   DEBUG: GLX_EXTENSIONS: GLX_ARB_create_context GLX_ARB_create_context_profile GLX_ARB_create_context_robustness GLX_ARB_fbconfig_float GLX_ARB_framebuffer_sRGB GLX_ARB_get_proc_address GLX_ARB_multisample GLX_EXT_import_context GLX_EXT_visual_info GLX_EXT_visual_rating GLX_EXT_framebuffer_sRGB GLX_EXT_create_context_es2_profile GLX_MESA_copy_sub_buffer GLX_MESA_multithread_makecurrent GLX_MESA_query_renderer GLX_MESA_swap_control GLX_OML_swap_method GLX_OML_sync_control GLX_SGI_make_current_read GLX_SGI_swap_control GLX_SGI_video_sync GLX_SGIS_multisample GLX_SGIX_fbconfig GLX_SGIX_pbuffer GLX_SGIX_visual_select_group GLX_EXT_texture_from_pixmap GLX_INTEL_swap_event
19:59:54 T:140583711201152  NOTICE: GL_VENDOR = Intel Open Source Technology Center
19:59:54 T:140583711201152  NOTICE: GL_RENDERER = Mesa DRI Intel(R) Bay Trail
19:59:54 T:140583711201152  NOTICE: GL_VERSION = 3.0 Mesa 10.6.5
19:59:54 T:140583711201152  NOTICE: GL_SHADING_LANGUAGE_VERSION = 1.30
19:59:54 T:140583711201152  NOTICE: GL_EXTENSIONS = GL_ARB_multisample GL_EXT_abgr GL_EXT_bgra GL_EXT_blend_color GL_EXT_blend_minmax GL_EXT_blend_subtract GL_EXT_copy_texture GL_EXT_polygon_offset GL_EXT_subtexture GL_EXT_texture_object GL_EXT_vertex_array GL_EXT_compiled_vertex_array GL_EXT_texture GL_EXT_texture3D GL_IBM_rasterpos_clip GL_ARB_point_parameters GL_EXT_draw_range_elements GL_EXT_packed_pixels GL_EXT_point_parameters GL_EXT_rescale_normal GL_EXT_separate_specular_color GL_EXT_texture_edge_clamp GL_SGIS_generate_mipmap GL_SGIS_texture_border_clamp GL_SGIS_texture_edge_clamp GL_SGIS_texture_lod GL_ARB_framebuffer_sRGB GL_ARB_multitexture GL_EXT_framebuffer_sRGB GL_IBM_multimode_draw_arrays GL_IBM_texture_mirrored_repeat GL_3DFX_texture_compression_FXT1 GL_ARB_texture_cube_map GL_ARB_texture_env_add GL_ARB_transpose_matrix GL_EXT_blend_func_separate GL_EXT_fog_coord GL_EXT_multi_draw_arrays GL_EXT_secondary_color GL_EXT_texture_env_add GL_EXT_texture_filter_anisotropic GL_EXT_texture_lod_bias GL_INGR_blend_func_separate GL_NV_blend_square GL_NV_light_max_exponent GL_NV_texgen_reflection GL_NV_texture_env_combine4 GL_S3_s3tc GL_SUN_multi_draw_arrays GL_ARB_texture_border_clamp GL_ARB_texture_compression GL_EXT_framebuffer_object GL_EXT_texture_env_combine GL_EXT_texture_env_dot3 GL_MESA_window_pos GL_NV_packed_depth_stencil GL_NV_texture_rectangle GL_ARB_depth_texture GL_ARB_occlusion_query GL_ARB_shadow GL_ARB_texture_env_combine GL_ARB_texture_env_crossbar GL_ARB_texture_env_dot3 GL_ARB_texture_mirrored_repeat GL_ARB_window_pos GL_EXT_stencil_two_side GL_EXT_texture_cube_map GL_NV_depth_clamp GL_APPLE_packed_pixels GL_APPLE_vertex_array_object GL_ARB_draw_buffers GL_ARB_fragment_program GL_ARB_fragment_shader GL_ARB_shader_objects GL_ARB_vertex_program GL_ARB_vertex_shader GL_ATI_draw_buffers GL_ATI_texture_env_combine3 GL_ATI_texture_float GL_EXT_shadow_funcs GL_EXT_stencil_wrap GL_MESA_pack_invert GL_NV_primitive_restart GL_ARB_depth_clamp GL_ARB_fragment_program_shadow GL_ARB_half_float_pixel GL_ARB_occlusion_query2 GL_ARB_point_sprite GL_ARB_shading_language_100 GL_ARB_sync GL_ARB_texture_non_power_of_two GL_ARB_vertex_buffer_object GL_ATI_blend_equation_separate GL_EXT_blend_equation_separate GL_OES_read_format GL_ARB_color_buffer_float GL_ARB_pixel_buffer_object GL_ARB_texture_compression_rgtc GL_ARB_texture_float GL_ARB_texture_rectangle GL_EXT_packed_float GL_EXT_pixel_buffer_object GL_EXT_texture_compression_dxt1 GL_EXT_texture_compression_rgtc GL_EXT_texture_rectangle GL_EXT_texture_sRGB GL_EXT_texture_shared_exponent GL_ARB_framebuffer_object GL_EXT_framebuffer_blit GL_EXT_framebuffer_multisample GL_EXT_packed_depth_stencil GL_APPLE_object_purgeable GL_ARB_vertex_array_object GL_ATI_separate_stencil GL_EXT_draw_buffers2 GL_EXT_draw_instanced GL_EXT_gpu_program_parameters GL_EXT_texture_array GL_EXT_texture_integer GL_EXT_texture_sRGB_decode GL_EXT_timer_query GL_OES_EGL_image GL_AMD_performance_monitor GL_ARB_copy_buffer GL_ARB_depth_buffer_float GL_ARB_draw_instanced GL_ARB_half_float_vertex GL_ARB_instanced_arrays GL_ARB_map_buffer_range GL_ARB_texture_rg GL_ARB_texture_swizzle GL_ARB_vertex_array_bgra GL_EXT_texture_swizzle GL_EXT_vertex_array_bgra GL_NV_conditional_render GL_AMD_conservative_depth GL_AMD_draw_buffers_blend GL_AMD_seamless_cubemap_per_texture GL_ARB_ES2_compatibility GL_ARB_blend_func_extended GL_ARB_debug_output GL_ARB_draw_buffers_blend GL_ARB_draw_elements_base_vertex GL_ARB_explicit_attrib_location GL_ARB_fragment_coord_conventions GL_ARB_provoking_vertex GL_ARB_sample_shading GL_ARB_sampler_objects GL_ARB_seamless_cube_map GL_ARB_shader_texture_lod GL_ARB_texture_cube_map_array GL_ARB_texture_gather GL_ARB_texture_multisample GL_ARB_texture_query_lod GL_ARB_texture_rgb10_a2ui GL_ARB_uniform_buffer_object GL_ARB_vertex_type_2_10_10_10_rev GL_EXT_provoking_vertex GL_EXT_texture_snorm GL_MESA_texture_signed_rgba GL_ARB_get_program_binary GL_ARB_robustness GL_ARB_separate_shader_objects GL_ARB_shader_bit_encoding GL_ARB_texture_compression_bptc GL_ARB_timer_query GL_ARB_transform_feedback2 GL_ARB_transform_feedback3 GL_ANGLE_texture_compression_dxt3 GL_ANGLE_texture_compression_dxt5 GL_ARB_compressed_texture_pixel_storage GL_ARB_conservative_depth GL_ARB_internalformat_query GL_ARB_map_buffer_alignment GL_ARB_shader_atomic_counters GL_ARB_shading_language_420pack GL_ARB_shading_language_packing GL_ARB_texture_storage GL_ARB_transform_feedback_instanced GL_EXT_framebuffer_multisample_blit_scaled GL_EXT_transform_feedback GL_AMD_shader_trinary_minmax GL_ARB_ES3_compatibility GL_ARB_clear_buffer_object GL_ARB_copy_image GL_ARB_explicit_uniform_location GL_ARB_invalidate_subdata GL_ARB_program_interface_query GL_ARB_texture_query_levels GL_ARB_texture_storage_multisample GL_ARB_texture_view GL_ARB_vertex_attrib_binding GL_KHR_debug GL_ARB_buffer_storage GL_ARB_clear_texture GL_ARB_multi_bind GL_ARB_seamless_cubemap_per_texture GL_ARB_texture_mirror_clamp_to_edge GL_ARB_vertex_type_10f_11f_11f_rev GL_EXT_shader_integer_mix GL_INTEL_performance_query GL_ARB_clip_control GL_ARB_conditional_render_inverted GL_ARB_derivative_control GL_ARB_pipeline_statistics_query GL_EXT_polygon_offset_clamp GL_KHR_context_flush_control
19:59:54 T:140583711201152    INFO: GL: Maximum texture width: 8192
19:59:54 T:140583711201152   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> 0f:87:00:80:45
19:59:54 T:140583465117440   DEBUG: CecLogMessage - TV (0): vendor = Panasonic (008045)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - expected response received (87: device vendor id)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - replacing the command handler for device 'TV' (0)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): device vendor id (87)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - registering new CEC client - v3.0.0
19:59:54 T:140583465117440   DEBUG: CecLogMessage - detecting logical address for type 'playback device'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - trying logical address 'Playback 1'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Playback 1 (4): POLL
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 44
19:59:54 T:140583711201152    INFO: load keymapping
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/appcommand.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/gamepad.xml
19:59:54 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 44
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Alienware.Dual.Compatible.Controller.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.AppleRemote.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Harmony.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Interact.AxisPad.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Logitech.RumblePad.2.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.360.Controller.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.Controller.S.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Nintendo.Wii.U.Pro.Controller.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Ouya.Controller.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.PS3.Remote.Keyboard.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.PS4.Controller.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.Sony.PLAYSTATION(R)3.Controller.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/joystick.WiiRemote.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/keyboard.xml
19:59:54 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using logical address 'Playback 1'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): device status changed into 'handled by libCEC'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): power status changed from 'unknown' to 'on'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): vendor = Pulse Eight (001582)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): CEC version 1.4
19:59:54 T:140583465117440   DEBUG: CecLogMessage - AllocateLogicalAddresses - device '0', type 'playback device', LA '4'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - setting ackmask to 10
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): osd name set to 'Kodi'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): menu language set to 'eng'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - trying to get the physical address via ADL
19:59:54 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - ADL returned physical address 0000
19:59:54 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - trying to get the physical address via nvidia driver
19:59:54 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - nvidia driver returned physical address 0000
19:59:54 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - trying to get the physical address from the OS
19:59:54 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - OS returned physical address 1100
19:59:54 T:140583465117440   DEBUG: CecLogMessage - AutodetectPhysicalAddress - autodetected physical address '1100'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): physical address changed from ffff to 1100
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): physical adddress 1100
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 4f:84:11:00:04
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/mouse.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/remote.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/keymaps/touchscreen.xml
19:59:54 T:140583711201152    INFO: Loading special://xbmc/system/Lircmap.xml
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'mceusb'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'XboxDVDDongle'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'Microsoft_Xbox'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'PinnacleSysPCTVRemote'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'anysee'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'iMON-PAD'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'Antec_Veris_RM200'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'MCE_via_iMON'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'TwinHanRemote'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'linux-input-layer'
19:59:54 T:140583711201152    INFO: * Linking remote mapping for 'linux-input-layer' to 'cx23885_remote'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'mediacenter'
19:59:54 T:140583711201152    INFO: * Adding remote mapping for device 'devinput'
19:59:54 T:140583711201152   DEBUG: CButtonTranslator::Load - no userdata Lircmap.xml found, skipping
19:59:54 T:140583711201152    INFO: GUI format 1920x1080, Display 1920x1080@ 60.00 - Full Screen
19:59:54 T:140583711201152   DEBUG: guilib: Fill viewport on change for solving rendering passes
19:59:54 T:140583711201152    INFO: CLangInfo: loading resource.language.en_gb language information...
19:59:54 T:140583711201152   DEBUG: trying to set locale to en_US.UTF-8
19:59:54 T:140583711201152    INFO: global locale set to C
19:59:54 T:140583711201152    INFO: CLangInfo: loading resource.language.en_gb language strings...
19:59:54 T:140583711201152   DEBUG: POParser: loaded 3314 strings from file resource://resource.language.en_gb/strings.po
19:59:54 T:140583711201152   DEBUG: SECTION:LoadDLL(libcurl.so.4)
19:59:54 T:140583711201152   DEBUG: Loading: libcurl.so.4
19:59:54 T:140583711201152  NOTICE: Running database version Addons19
19:59:54 T:140583711201152   DEBUG: Initialize, updating databases...
19:59:54 T:140583711201152  NOTICE: Running database version ViewModes6
19:59:54 T:140583711201152  NOTICE: Running database version Textures13
19:59:54 T:140583711201152  NOTICE: Running database version MyMusic52
19:59:54 T:140583711201152  NOTICE: Running database version MyVideos93
19:59:54 T:140583711201152  NOTICE: Running database version TV29
19:59:54 T:140583711201152  NOTICE: Running database version Epg10
19:59:54 T:140583711201152   DEBUG: Initialize, updating databases... DONE
19:59:54 T:140583711201152  NOTICE: start dvd mediatype detection
19:59:54 T:140583675623168  NOTICE: Thread DetectDVDMedia start, auto delete: false
19:59:54 T:140583675623168   DEBUG: Compiled with libcdio Version 0.92
19:59:54 T:140583711201152   DEBUG: DPMS: supported power-saving modes: SUSPEND OFF STANDBY
19:59:54 T:140583675623168   DEBUG: Thread DetectDVDMedia 140583675623168 terminating
19:59:54 T:140583711201152   DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
19:59:54 T:140583711201152   DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
19:59:54 T:140583711201152   DEBUG: Activating window ID: 12997
19:59:54 T:140583711201152   DEBUG: ------ Window Init () ------
19:59:54 T:140583711201152    INFO: load splash image: /usr/share/kodi/media/Splash.png
19:59:54 T:140583711201152    INFO: Unloading old skin ...
19:59:54 T:140583711201152    INFO:   load skin from: /usr/share/kodi/addons/skin.confluence (version: 2.7.4)
19:59:54 T:140583711201152    INFO:   load fonts for skin...
19:59:54 T:140583711201152    INFO: Loading fonts from /usr/share/kodi/addons/skin.confluence/720p/Font.xml
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted autonomous mode setting: 'enabled'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted CEC version setting: '1.4'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted logical address setting: 'Playback 1'
19:59:54 T:140583711201152   DEBUG: POParser: loaded 149 strings from file /usr/share/kodi/addons/skin.confluence/language/resource.language.en_gb/strings.po
19:59:54 T:140583711201152    INFO: Loading skin includes from /usr/share/kodi/addons/skin.confluence/720p/includes.xml
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted device type setting: 'playback device'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted logical address mask setting: '910'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted device name setting: 'Kodi'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - using persisted physical address setting: '1100'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - making Playback 1 (4) the active source
19:59:54 T:140583465117440   DEBUG: CecLogMessage - TV (0): power status changed from 'unknown' to 'in transition from standby to on'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - marking the adapter as active source
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - scheduling active source message for 'Playback 1'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - CEC client registered: libCEC version = 3.0.0, client version = 3.0.0, firmware version = 4, firmware build date: Thu Dec  6 11:15:20 2012 +0000, logical address(es) = Playback 1 (4) , physical address: 1.1.0.0, compiled on Linux-1, features: P8_USB, P8_detect, randr
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): vendor = Panasonic (008045)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - replacing the command handler for device 'Playback 1' (4)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): OSD name 'Kodi'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 40:47:4b:6f:64:69
19:59:54 T:140583711201152    INFO:   load new skin...
19:59:54 T:140583711201152    INFO: Loading user windows, path /usr/share/kodi/addons/skin.confluence/720p
19:59:54 T:140583711201152   DEBUG: Load Skin XML: 4.44ms
19:59:54 T:140583711201152    INFO:   initialize new skin...
19:59:54 T:140583711201152   DEBUG: guilib: Fill viewport on change for solving rendering passes
19:59:54 T:140583711201152    INFO: Loading skin file: Pointer.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152   DEBUG: OpenBundle - Opened bundle /usr/share/kodi/addons/skin.confluence/media/Textures.xbt
19:59:54 T:140583711201152    INFO: Loading skin file: DialogVolumeBar.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152    INFO: Loading skin file: DialogKaiToast.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152    INFO: Loading skin file: DialogMuteBug.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152    INFO: Loading skin file: DialogSeekBar.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152    INFO: Loading skin file: DialogBusy.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152    INFO: Loading skin file: DialogExtendedProgressBar.xml, load type: LOAD_ON_GUI_INIT
19:59:54 T:140583711201152    INFO: Loading resource://resource.uisounds.confluence/sounds.xml
19:59:54 T:140583711201152    INFO:   skin loaded...
19:59:54 T:140583711201152   DEBUG: Activating window ID: 12997
19:59:54 T:140583711201152   DEBUG: ------ Window Init () ------
19:59:54 T:140583711201152    INFO: load splash image: /usr/share/kodi/media/Splash.png
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << requesting power status of 'TV' (0)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 40:8f
19:59:54 T:140583711201152   DEBUG: JSONRPC: JSON schema type broadcastnext references an unknown type PVR.Details.Broadcast
19:59:54 T:140583711201152 WARNING: JSONRPC: Could not parse type "PVR.Details.Channel"
19:59:54 T:140583711201152    INFO: JSONRPC: Adding type "PVR.Details.Channel" to list of incomplete definitions (waiting for "PVR.Details.Broadcast")
19:59:54 T:140583711201152   DEBUG: JSONRPC: JSON schema type  references an unknown type PVR.Details.Channel
19:59:54 T:140583711201152   DEBUG: Invalid item definition in "items" for type channels
19:59:54 T:140583711201152 WARNING: JSONRPC: Could not parse type "PVR.Details.ChannelGroup.Extended"
19:59:54 T:140583711201152    INFO: JSONRPC: Adding type "PVR.Details.ChannelGroup.Extended" to list of incomplete definitions (waiting for "PVR.Details.Channel")
19:59:54 T:140583711201152    INFO: JSONRPC: Resolving incomplete types/methods referencing PVR.Details.Broadcast
19:59:54 T:140583711201152    INFO: JSONRPC: Resolving incomplete types/methods referencing PVR.Details.Channel
19:59:54 T:140583711201152   DEBUG: JSONRPC: JSON schema type stereoscopicmode references an unknown type GUI.Stereoscopy.Mode
19:59:54 T:140583711201152 WARNING: JSONRPC: Could not parse type "GUI.Property.Value"
19:59:54 T:140583711201152    INFO: JSONRPC: Adding type "GUI.Property.Value" to list of incomplete definitions (waiting for "GUI.Stereoscopy.Mode")
19:59:54 T:140583711201152    INFO: JSONRPC: Resolving incomplete types/methods referencing GUI.Stereoscopy.Mode
19:59:54 T:140583711201152   DEBUG: JSONRPC: JSON schema type definition references an unknown type Setting.Details.Setting
19:59:54 T:140583711201152 WARNING: JSONRPC: Could not parse type "Setting.Details.SettingList"
19:59:54 T:140583711201152    INFO: JSONRPC: Adding type "Setting.Details.SettingList" to list of incomplete definitions (waiting for "Setting.Details.Setting")
19:59:54 T:140583711201152    INFO: JSONRPC: Resolving incomplete types/methods referencing Setting.Details.Setting
19:59:54 T:140583711201152    INFO: JSONRPC v6.25.2: Successfully initialized
19:59:54 T:140583711201152   DEBUG: ADDON: Starting service addons.
19:59:54 T:140583711201152   DEBUG: Activating window ID: 12999
19:59:54 T:140583711201152   DEBUG: ------ Window Init (Startup.xml) ------
19:59:54 T:140583711201152    INFO: Loading skin file: Startup.xml, load type: LOAD_EVERY_TIME
19:59:54 T:140583711201152    INFO: removing tempfiles
19:59:54 T:140583711201152   DEBUG: ADDON: Starting service addons.
19:59:54 T:140583711201152  NOTICE: initialize done
19:59:54 T:140583711201152  NOTICE: Running the application...
19:59:54 T:140583711201152   DEBUG: Activating window ID: 10000
19:59:54 T:140583013144320  NOTICE: Thread LanguageInvoker start, auto delete: false
19:59:54 T:140583013144320    INFO: initializing python engine.
19:59:54 T:140583021537024  NOTICE: Thread LanguageInvoker start, auto delete: false
19:59:54 T:140583021537024    INFO: initializing python engine.
19:59:54 T:140582928246528  NOTICE: Thread LanguageInvoker start, auto delete: false
19:59:54 T:140582928246528    INFO: initializing python engine.
19:59:54 T:140582936639232  NOTICE: Thread LanguageInvoker start, auto delete: false
19:59:54 T:140582936639232    INFO: initializing python engine.
19:59:54 T:140583711201152   DEBUG: ------ Window Init () ------
19:59:54 T:140583021537024   DEBUG: CPythonInvoker(0, /storage/.kodi/addons/script.module.simple.downloader/default.py): start processing
19:59:54 T:140582928246528   DEBUG: CPythonInvoker(3, /storage/.kodi/addons/script.common.plugin.cache/default.py): start processing
19:59:54 T:140583013144320   DEBUG: CPythonInvoker(1, /storage/.kodi/addons/plugin.video.emby/service.py): start processing
19:59:54 T:140582936639232   DEBUG: CPythonInvoker(2, /usr/share/kodi/addons/service.openelec.settings/service.py): start processing
19:59:54 T:140583711201152   DEBUG: ------ Window Deinit (Startup.xml) ------
19:59:54 T:140583711201152   DEBUG: ------ Window Init (Home.xml) ------
19:59:54 T:140583711201152    INFO: Loading skin file: Home.xml, load type: KEEP_IN_MEMORY
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> 04:00:47:00
19:59:54 T:140583465117440   DEBUG: CecLogMessage - marking opcode 'set osd name' as unsupported feature for device 'TV'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): feature abort ( 0)
19:59:54 T:140583021537024  NOTICE: -->Python Interpreter Initialized<--
19:59:54 T:140583021537024   DEBUG: CPythonInvoker(0, /storage/.kodi/addons/script.module.simple.downloader/default.py): the source file to load is "/storage/.kodi/addons/script.module.simple.downloader/default.py"
19:59:54 T:140583013144320  NOTICE: -->Python Interpreter Initialized<--
19:59:54 T:140583013144320   DEBUG: CPythonInvoker(1, /storage/.kodi/addons/plugin.video.emby/service.py): the source file to load is "/storage/.kodi/addons/plugin.video.emby/service.py"
19:59:54 T:140583013144320   DEBUG: CPythonInvoker(1, /storage/.kodi/addons/plugin.video.emby/service.py): setting the Python path to /storage/.kodi/addons/plugin.video.emby:/storage/.kodi/addons/script.module.requests/lib:/usr/lib/python27.zip:/usr/lib/python2.7:/usr/lib/python2.7/plat-linux2:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/lib/python2.7/site-packages:/usr/lib/python2.7/site-packages/gtk-2.0
19:59:54 T:140583013144320   DEBUG: CPythonInvoker(1, /storage/.kodi/addons/plugin.video.emby/service.py): entering source directory /storage/.kodi/addons/plugin.video.emby
19:59:54 T:140583013144320   DEBUG: CPythonInvoker(1, /storage/.kodi/addons/plugin.video.emby/service.py): instantiating addon using automatically obtained id of "plugin.video.emby" dependent on version 2.1.0 of the xbmc.python api
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> 04:90:00
19:59:54 T:140583465117440   DEBUG: CecLogMessage - TV (0): power status changed from 'in transition from standby to on' to 'on'
19:59:54 T:140583456724736   DEBUG: OpenConnection - connection to the CEC adapter opened
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): report power status (90)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - expected response received (90: report power status)
19:59:54 T:140583456724736   DEBUG: SetConfigurationFromLibCEC - settings updated by libCEC
19:59:54 T:140582894774016  NOTICE: Thread CECAdapterUpdate start, auto delete: false
19:59:54 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4) was already marked as active source
19:59:54 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - sending active source message for 'Playback 1'
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 40:89:10:02:ff:ff:00:05:05:45:55:5c:58:32
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
19:59:54 T:140583465117440   DEBUG: CecLogMessage - << 40:04
19:59:54 T:140582903166720  NOTICE: Thread JobWorker start, auto delete: true
19:59:54 T:140582903166720   DEBUG: CRecentlyAddedJob::UpdateMusic() - Running RecentlyAdded home screen update
19:59:54 T:140583711201152   DEBUG: no profile autoexec.py (/storage/.kodi/userdata/autoexec.py) found, skipping
19:59:54 T:140583711201152   DEBUG: NetworkMessage - Starting network services
19:59:54 T:140583711201152   DEBUG: CZeroconfAvahi::clientCallback: client is up and running
19:59:54 T:140583711201152  NOTICE: starting zeroconf publishing
19:59:54 T:140583711201152  NOTICE: Webserver: Starting...
19:59:54 T:140582877988608  NOTICE: Thread JobWorker start, auto delete: true
19:59:54 T:140583711201152  NOTICE: WebServer: Started the webserver
19:59:54 T:140583711201152  NOTICE: starting upnp client
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::doPublishService identifier: servers.webserver type: _http._tcp name:Kodi (OpenELEC) port:80
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::addService() named: Kodi (OpenELEC) type: _http._tcp port:80
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::doPublishService identifier: servers.jsonrpc-http type: _xbmc-jsonrpc-h._tcp name:Kodi (OpenELEC) port:80
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::addService() named: Kodi (OpenELEC) type: _xbmc-jsonrpc-h._tcp port:80
19:59:54 T:140583021537024   DEBUG: CPythonInvoker(0, /storage/.kodi/addons/script.module.simple.downloader/default.py): setting the Python path to /storage/.kodi/addons/script.module.simple.downloader:/storage/.kodi/addons/script.common.plugin.cache/lib:/storage/.kodi/addons/script.module.parsedom/lib:/usr/lib/python27.zip:/usr/lib/python2.7:/usr/lib/python2.7/plat-linux2:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/lib/python2.7/site-packages:/usr/lib/python2.7/site-packages/gtk-2.0
19:59:54 T:140583021537024   DEBUG: CPythonInvoker(0, /storage/.kodi/addons/script.module.simple.downloader/default.py): entering source directory /storage/.kodi/addons/script.module.simple.downloader
19:59:54 T:140583021537024   DEBUG: CPythonInvoker(0, /storage/.kodi/addons/script.module.simple.downloader/default.py): instantiating addon using automatically obtained id of "script.module.simple.downloader" dependent on version 2.1.0 of the xbmc.python api
19:59:54 T:140582903166720   DEBUG: GetRecentlyAddedAlbumSongs() query: SELECT songview.* FROM (SELECT idAlbum FROM albumview ORDER BY idAlbum DESC LIMIT 10) AS recentalbums JOIN songview ON songview.idAlbum=recentalbums.idAlbum
19:59:54 T:140582936639232  NOTICE: -->Python Interpreter Initialized<--
19:59:54 T:140582903166720   DEBUG: GetRecentlyAddedAlbums query: select * from albumview where strAlbum != '' order by idAlbum desc limit 10
19:59:54 T:140582936639232   DEBUG: CPythonInvoker(2, /usr/share/kodi/addons/service.openelec.settings/service.py): the source file to load is "/usr/share/kodi/addons/service.openelec.settings/service.py"
19:59:54 T:140582903166720   DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update
19:59:54 T:140582936639232   DEBUG: CPythonInvoker(2, /usr/share/kodi/addons/service.openelec.settings/service.py): setting the Python path to /usr/share/kodi/addons/service.openelec.settings:/usr/lib/python27.zip:/usr/lib/python2.7:/usr/lib/python2.7/plat-linux2:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/lib/python2.7/site-packages:/usr/lib/python2.7/site-packages/gtk-2.0
19:59:54 T:140582936639232   DEBUG: CPythonInvoker(2, /usr/share/kodi/addons/service.openelec.settings/service.py): entering source directory /usr/share/kodi/addons/service.openelec.settings
19:59:54 T:140582936639232   DEBUG: CPythonInvoker(2, /usr/share/kodi/addons/service.openelec.settings/service.py): instantiating addon using automatically obtained id of "service.openelec.settings" dependent on version 2.1.0 of the xbmc.python api
19:59:54 T:140583711201152  NOTICE: ES: Starting event server
19:59:54 T:140583711201152    INFO: JSONRPC Server: Successfully initialized
19:59:54 T:140583711201152   DEBUG: ------ Window Init (DialogKaiToast.xml) ------
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::doPublishService identifier: servers.jsonrpc-tpc type: _xbmc-jsonrpc._tcp name:Kodi (OpenELEC) port:9090
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::addService() named: Kodi (OpenELEC) type: _xbmc-jsonrpc._tcp port:9090
19:59:54 T:140582399768320  NOTICE: Thread TCPServer start, auto delete: false
19:59:54 T:140582483629824  NOTICE: Thread EventServer start, auto delete: false
19:59:54 T:140582483629824  NOTICE: ES: Starting UDP Event server on 0.0.0.0:9777
19:59:54 T:140582483629824  NOTICE: UDP: Listening on port 9777
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::doPublishService identifier: servers.eventserver type: _xbmc-events._udp name:Kodi (OpenELEC) port:9777
19:59:54 T:140582877988608   DEBUG: CZeroconfAvahi::addService() named: Kodi (OpenELEC) type: _xbmc-events._udp port:9777
19:59:54 T:140582903166720   DEBUG: RunQuery took 2 ms for 10 items query: select * from movie_view  ORDER BY dateAdded desc, idMovie desc LIMIT 10
19:59:54 T:140582903166720   DEBUG: RunQuery took 29 ms for 10 items query: select * from episode_view  ORDER BY dateAdded desc, idEpisode desc LIMIT 10
19:59:54 T:140582903166720   DEBUG: RunQuery took 1 ms for 0 items query: select * from musicvideo_view  ORDER BY dateAdded desc, idMVideo desc LIMIT 10
19:59:54 T:140582903166720   DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update
19:59:55 T:140582936639232  NOTICE: ## OpenELEC Addon ## 0.6.8
19:59:55 T:140582928246528  NOTICE: -->Python Interpreter Initialized<--
19:59:55 T:140582928246528   DEBUG: CPythonInvoker(3, /storage/.kodi/addons/script.common.plugin.cache/default.py): the source file to load is "/storage/.kodi/addons/script.common.plugin.cache/default.py"
19:59:55 T:140583711201152   DEBUG: LogindUPowerSyscall - Received unknown signal NameAcquired
19:59:55 T:140583711201152   DEBUG: Checking repositories for updates (triggered by Plexus)
19:59:55 T:140582877988608   DEBUG: CFileCache::Open - opening <addons/gotham/addons.xml.md5> using cache
19:59:55 T:140582877988608   DEBUG: CurlFile::Open(0x4c701b0) http://mirrors.kodi.tv/addons/gotham/addons.xml.md5
19:59:55 T:140582877988608    INFO: easy_aquire - Created session to http://mirrors.kodi.tv
19:59:55 T:140583021537024    INFO: CPythonInvoker(0, /storage/.kodi/addons/script.module.simple.downloader/default.py): script successfully run
19:59:55 T:140583021537024    INFO: Python script stopped
19:59:55 T:140583021537024   DEBUG: Thread LanguageInvoker 140583021537024 terminating
19:59:55 T:140582928246528   DEBUG: CPythonInvoker(3, /storage/.kodi/addons/script.common.plugin.cache/default.py): setting the Python path to /storage/.kodi/addons/script.common.plugin.cache:/usr/lib/python27.zip:/usr/lib/python2.7:/usr/lib/python2.7/plat-linux2:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/lib/python2.7/site-packages:/usr/lib/python2.7/site-packages/gtk-2.0
19:59:55 T:140582928246528   DEBUG: CPythonInvoker(3, /storage/.kodi/addons/script.common.plugin.cache/default.py): entering source directory /storage/.kodi/addons/script.common.plugin.cache
19:59:55 T:140582928246528   DEBUG: CPythonInvoker(3, /storage/.kodi/addons/script.common.plugin.cache/default.py): instantiating addon using automatically obtained id of "script.common.plugin.cache" dependent on version 2.1.0 of the xbmc.python api
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1100)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:11:00
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): menu state 'activated'
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 40:8e:00
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 40:04
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Audio (5): POLL
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 45
19:59:55 T:140583465117440   DEBUG: CecLogMessage - >> POLL sent
19:59:55 T:140583465117440   DEBUG: CecLogMessage - Audio (5): device status changed into 'present'
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << requesting vendor ID of 'Audio' (5)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 45:8c
19:59:55 T:140582391375616  NOTICE: Thread FileCache start, auto delete: false
19:59:55 T:140582391375616    INFO: CFileCache::Process - Hit eof.
19:59:55 T:140582391375616   DEBUG: Thread FileCache 140582391375616 terminating
19:59:55 T:140582877988608   DEBUG: CFileCache::Open - opening <addons/helix/addons.xml.md5> using cache
19:59:55 T:140582877988608   DEBUG: CurlFile::Open(0x4c701b0) http://mirrors.kodi.tv/addons/helix/addons.xml.md5
19:59:55 T:140583465117440   DEBUG: CecLogMessage - >> 5f:87:00:09:b0
19:59:55 T:140583465117440   DEBUG: CecLogMessage - Audio (5): vendor = Onkyo (0009b0)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): device vendor id (87)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - expected response received (87: device vendor id)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - replacing the command handler for device 'Audio' (5)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << requesting power status of 'Audio' (5)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 45:8f
19:59:55 T:140582928246528  NOTICE:  StorageServer Module loaded RUN
19:59:55 T:140582928246528  NOTICE: StorageClient-2.5.4 Starting server
19:59:55 T:140583013144320  NOTICE: EMBY Service -> Starting Monitor
19:59:55 T:140583013144320  NOTICE: EMBY Service -> ======== START EMBY ========
19:59:55 T:140583013144320  NOTICE: EMBY Service -> Platform: Linux/RPi
19:59:55 T:140583013144320  NOTICE: EMBY Service -> KODI Version: 15.1 Git:f4dda26
19:59:55 T:140583013144320  NOTICE: EMBY Service -> EMBY Version: 1.1.39
19:59:55 T:140582886381312   DEBUG: CZeroconfAvahi::groupCallback: Service successfully established
19:59:55 T:140582391375616   DEBUG: Previous line repeats 1 times.
19:59:55 T:140582391375616  NOTICE: Thread FileCache start, auto delete: false
19:59:55 T:140582391375616    INFO: CFileCache::Process - Hit eof.
19:59:55 T:140582886381312   DEBUG: CZeroconfAvahi::groupCallback: Service successfully established
19:59:55 T:140583465117440   DEBUG: Previous line repeats 1 times.
19:59:55 T:140583465117440   DEBUG: CecLogMessage - >> 54:90:00
19:59:55 T:140583465117440   DEBUG: CecLogMessage - Audio (5): power status changed from 'unknown' to 'on'
19:59:55 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Playback 1 (4): report power status (90)
19:59:55 T:140582894774016   DEBUG: UpdateMenuLanguage - using TV menu language is disabled
19:59:55 T:140583465117440   DEBUG: CecLogMessage - expected response received (90: report power status)
19:59:55 T:140583465117440   DEBUG: CecLogMessage - 'Audio' (5) is already 'on'
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Recorder 1 (1): POLL
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 41
19:59:55 T:140583013144320  NOTICE: File_Lock_On /storage/.kodi/addons/plugin.video.emby/machine_guid.lock obtained
19:59:55 T:140582877988608   DEBUG: CFileCache::Open - opening <addons/isengard/addons.xml.md5> using cache
19:59:55 T:140582877988608   DEBUG: CurlFile::Open(0x4c701b0) http://mirrors.kodi.tv/addons/isengard/addons.xml.md5
19:59:55 T:140582391375616   DEBUG: Thread FileCache 140582391375616 terminating
19:59:55 T:140583013144320  NOTICE: File_Lock_On /storage/.kodi/addons/plugin.video.emby/machine_guid.lock released
19:59:55 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 41
19:59:55 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:55 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:55 T:140583465117440   DEBUG: CecLogMessage - Recorder 1 (1): device status changed into 'not present'
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Recorder 2 (2): POLL
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 42
19:59:55 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:55 T:140583465117440   DEBUG: CecLogMessage - << 42
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Recorder 2 (2): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 1 (3): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 43
19:59:56 T:140582391375616  NOTICE: Thread FileCache start, auto delete: false
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 43
19:59:56 T:140582391375616    INFO: CFileCache::Process - Hit eof.
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Tuner 1 (3): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 2 (6): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 46
19:59:56 T:140582391375616   DEBUG: Thread FileCache 140582391375616 terminating
19:59:56 T:140582877988608   DEBUG: Checksum for repository repository.xbmc.org not changed.
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 46
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Tuner 2 (6): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 3 (7): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 47
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 47
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Tuner 3 (7): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Playback 2 (8): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 48
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 48
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Playback 2 (8): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Recorder 3 (9): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 49
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 49
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Recorder 3 (9): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 4 (A): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4a
19:59:56 T:140582877988608   DEBUG: CFileCache::Open - opening <svn/trunk/Addon/addons.xml.md5> using cache
19:59:56 T:140582877988608   DEBUG: CurlFile::Open(0x4dd7810) https://plexus.svn.codeplex.com/svn/trunk/Addon/addons.xml.md5
19:59:56 T:140582877988608    INFO: easy_aquire - Created session to https://plexus.svn.codeplex.com
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4a
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Tuner 4 (A): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Playback 3 (B): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4b
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4b
19:59:56 T:140582382982912  NOTICE: EMBY UserClient -> |---- Starting UserClient ----|
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Playback 3 (B): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Reserved 1 (C): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4c
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4c
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Reserved 1 (C): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Reserved 2 (D): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4d
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4d
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Reserved 2 (D): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Free use (E): POLL
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4e
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 4e
19:59:56 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
19:59:56 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
19:59:56 T:140583465117440   DEBUG: CecLogMessage - Free use (E): device status changed into 'not present'
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << requesting OSD name of 'Audio' (5)
19:59:56 T:140583465117440   DEBUG: CecLogMessage - << 45:46
19:59:56 T:140582382982912  NOTICE: EMBY UserClient -> Current user: Emby
19:59:56 T:140582382982912  NOTICE: EMBY UserClient -> Current userId: e0ba8d266a5fc11a85f18a849f85037a
19:59:56 T:140582382982912  NOTICE: EMBY UserClient -> Current accessToken: 4c0fd7e6d327412db67572d040bf062b
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> 54:47:54:58:2d:53:52:33:30:39
19:59:57 T:140583465117440   DEBUG: CecLogMessage - Audio (5): osd name set to 'TX-SR309'
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Playback 1 (4): set osd name (47)
19:59:57 T:140582894774016   DEBUG: UpdateAudioSystemStatus - CEC capable amplifier found (TX-SR309). volume will be controlled on the amp
19:59:57 T:140582894774016   DEBUG: CAnnouncementManager - Announcement: OnVolumeChanged from xbmc
19:59:57 T:140582894774016   DEBUG: GOT ANNOUNCEMENT, type: 64, from xbmc, message OnVolumeChanged
19:59:57 T:140583465117440   DEBUG: CecLogMessage - expected response received (47: set osd name)
19:59:57 T:140583711201152   DEBUG: LIRC: Update - NEW at 3553:69 0 KEY_LEFT devinput (KEY_LEFT)
19:59:57 T:140583711201152   DEBUG: OnKey: 169 (0xa9) pressed, action is Left
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> 04:00:89:03
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): feature abort ( 0)
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> 04:8c
19:59:57 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): vendor id Panasonic (8045)
19:59:57 T:140583465117440   DEBUG: CecLogMessage - << 4f:87:00:80:45
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): give device vendor id (8C)
19:59:57 T:140582348371712  NOTICE: Thread JobWorker start, auto delete: true
19:59:57 T:140583711201152   DEBUG: LIRC: Update - NEW at 3910:69 0 KEY_LEFT_UP devinput (KEY_LEFT_UP)
19:59:57 T:140582323193600  NOTICE: EMBY LibrarySync -> --- Starting Library Sync Thread ---
19:59:57 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> 04:89:10:01:05
19:59:57 T:140583465117440   DEBUG: CecLogMessage - << 40:89:10:02:ff:ff:00:05:05:45:55:5c:58:32
19:59:57 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4) was already marked as active source
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command (89)
19:59:57 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
19:59:57 T:140583465117440   DEBUG: CecLogMessage - scheduling active source message for 'Playback 1'
19:59:57 T:140582323193600   DEBUG: LocalizeStrings: no strings.po file exist at /storage/.kodi/addons/plugin.video.emby/resources/language/English, fallback to strings.xml
19:59:58 T:140583465117440   DEBUG: CecLogMessage - >> 04:a0:00:80:45:06:05
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1100)
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:11:00
19:59:58 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command with id (A0)
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << 40:04
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1100)
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:11:00
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): menu state 'activated'
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << 40:8e:00
19:59:58 T:140583711201152   DEBUG: LIRC: Update - NEW at 5093:73 0 KEY_VOLUMEUP devinput (KEY_VOLUMEUP)
19:59:58 T:140583711201152   DEBUG: OnKey: leftctrl (0xd0) pressed, action is VolumeUp
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << 45:44:41
19:59:58 T:140583465117440   DEBUG: CecLogMessage - >> 50:7a:32
19:59:58 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5): audio status changed from 7f to 32
19:59:58 T:140582877988608   ERROR: CCurlFile::Open failed with code 404 for https://plexus.svn.codeplex.com/svn/trunk/Addon/addons.xml.md5
19:59:58 T:140582877988608   ERROR: Open - failed to open source <https://plexus.svn.codeplex.com/svn/trunk/Addon/addons.xml.md5>
19:59:58 T:140582877988608   ERROR: Failed to fetch checksum for directory listing https://plexus.svn.codeplex.com/svn/trunk/Addon/addons.xml for repository program.plexus.
19:59:58 T:140582877988608   DEBUG: CFileCache::Open - opening <downloads/addons/xbmb3c/kodi-repo/addons.xml.md5> using cache
19:59:58 T:140582877988608   DEBUG: CurlFile::Open(0x4ee5330) http://www.mb3admin.com/downloads/addons/xbmb3c/kodi-repo/addons.xml.md5
19:59:58 T:140582877988608    INFO: easy_aquire - Created session to http://www.mb3admin.com
19:59:58 T:140583465117440   DEBUG: CecLogMessage - << 45:45
19:59:59 T:140583711201152   DEBUG: LIRC: Update - NEW at 5503:73 0 KEY_VOLUMEUP_UP devinput (KEY_VOLUMEUP_UP)
19:59:59 T:140582314800896  NOTICE: Thread FileCache start, auto delete: false
19:59:59 T:140582314800896    INFO: CFileCache::Process - Hit eof.
19:59:59 T:140582314800896   DEBUG: Thread FileCache 140582314800896 terminating
19:59:59 T:140582877988608   DEBUG: Checksum for repository repository.emby.kodi not changed.
19:59:59 T:140582877988608   DEBUG: CFileCache::Open - opening <6.0/Generic/x86_64/addons.xml.md5> using cache
19:59:59 T:140582877988608   DEBUG: CurlFile::Open(0x4dd8c70) http://addons.openelec.tv/6.0/Generic/x86_64/addons.xml.md5
19:59:59 T:140582877988608    INFO: easy_aquire - Created session to http://addons.openelec.tv
19:59:59 T:140583465117440   DEBUG: CecLogMessage - >> 04:a0:00:80:45:06:05
19:59:59 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1100)
19:59:59 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:11:00
19:59:59 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command with id (A0)
19:59:59 T:140582323193600  NOTICE: EMBY LibrarySync -> Sync Database, Incremental Sync Using Client Time -5 min: 2015-09-29T02:54:59Z
19:59:59 T:140582323193600  NOTICE: EMBY LibrarySync -> Sync Database, Incremental Sync Setting Last Run Time Saved: 2015-09-29T02:54:59Z
19:59:59 T:140582323193600  NOTICE: Sync DB -> syncDatabase Exiting
19:59:59 T:140583711201152   DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
19:59:59 T:140582348371712  NOTICE: VideoInfoScanner: Starting scan ..
19:59:59 T:140582348371712   DEBUG: CAnnouncementManager - Announcement: OnScanStarted from xbmc
19:59:59 T:140582348371712   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanStarted
19:59:59 T:140582348371712  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
19:59:59 T:140582348371712   DEBUG: CAnnouncementManager - Announcement: OnScanFinished from xbmc
19:59:59 T:140582348371712   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanFinished
19:59:59 T:140582903166720   DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update
19:59:59 T:140582903166720   DEBUG: RunQuery took 2 ms for 10 items query: select * from movie_view  ORDER BY dateAdded desc, idMovie desc LIMIT 10
19:59:59 T:140582903166720   DEBUG: RunQuery took 13 ms for 10 items query: select * from episode_view  ORDER BY dateAdded desc, idEpisode desc LIMIT 10
19:59:59 T:140582903166720   DEBUG: RunQuery took 1 ms for 0 items query: select * from musicvideo_view  ORDER BY dateAdded desc, idMVideo desc LIMIT 10
19:59:59 T:140582903166720   DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update
19:59:59 T:140583711201152   DEBUG: ------ Window Deinit (DialogExtendedProgressBar.xml) ------
19:59:59 T:140582314800896  NOTICE: Thread FileCache start, auto delete: false
19:59:59 T:140582314800896    INFO: CFileCache::Process - Hit eof.
19:59:59 T:140582877988608   DEBUG: Checksum for repository repository.openelec.tv not changed.
19:59:59 T:140582314800896   DEBUG: Thread FileCache 140582314800896 terminating
20:00:00 T:140583711201152   DEBUG: LIRC: Update - NEW at 6504:72 0 KEY_VOLUMEDOWN devinput (KEY_VOLUMEDOWN)
20:00:00 T:140583711201152   DEBUG: OnKey: rightctrl (0xd1) pressed, action is VolumeDown
20:00:00 T:140583465117440   DEBUG: CecLogMessage - << 45:44:42
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[script.linphone]: requires xbmc.python version 1.0 which is not available
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[skin.ace]: requires xbmc.gui version 5.0.0 which is not available
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[skin.aeonmq5]: requires xbmc.gui version 5.0.0 which is not available
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[skin.hybrid]: requires xbmc.gui version 5.0.0 which is not available
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[skin.metroid]: requires xbmc.gui version 5.0.1 which is not available
20:00:00 T:140583465117440   DEBUG: CecLogMessage - >> 50:7a:30
20:00:00 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5): audio status changed from 32 to 30
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[skin.quartz]: requires xbmc.gui version 5.0.1 which is not available
20:00:00 T:140583711201152   DEBUG: ------ Window Deinit (DialogKaiToast.xml) ------
20:00:00 T:140582877988608   DEBUG: CAddonInstallJob[skin.xtv-saf]: requires xbmc.gui version 5.0.1 which is not available
20:00:00 T:140583465117440   DEBUG: CecLogMessage - << 45:45
20:00:00 T:140582877988608    INFO: ADDON: cpluff: 'Could not read plug-in directory /usr/lib/kodi/addons: No such file or directory'
20:00:00 T:140582877988608   DEBUG: ADDON: cpluff: 'Not all directories were successfully scanned.'
20:00:00 T:140583711201152   DEBUG: LIRC: Update - NEW at 6846:72 0 KEY_VOLUMEDOWN_UP devinput (KEY_VOLUMEDOWN_UP)
20:00:00 T:140583465117440   DEBUG: CecLogMessage - >> 04:a0:00:80:45:06:05
20:00:00 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command with id (A0)
20:00:00 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1100)
20:00:00 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:11:00
20:00:00 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:02 T:140583711201152  NOTICE: Previous line repeats 1 times.
20:00:02 T:140583711201152   DEBUG: LIRC: Update - NEW at 8504:6c 0 KEY_DOWN devinput (KEY_DOWN)
20:00:02 T:140583711201152   DEBUG: OnKey: 167 (0xa7) pressed, action is Down
20:00:02 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:02 T:140583711201152   DEBUG: LIRC: Update - NEW at 9068:6c 0 KEY_DOWN_UP devinput (KEY_DOWN_UP)
20:00:02 T:140583711201152   DEBUG: LIRC: Update - NEW at 9148:6c 0 KEY_DOWN devinput (KEY_DOWN)
20:00:02 T:140583711201152   DEBUG: OnKey: 167 (0xa7) pressed, action is Down
20:00:03 T:140583711201152   DEBUG: LIRC: Update - NEW at 9481:6c 0 KEY_DOWN_UP devinput (KEY_DOWN_UP)
20:00:03 T:140583711201152   DEBUG: LIRC: Update - NEW at 9657:6c 0 KEY_DOWN devinput (KEY_DOWN)
20:00:03 T:140583711201152   DEBUG: OnKey: 167 (0xa7) pressed, action is Down
20:00:03 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:03 T:140583711201152   DEBUG: LIRC: Update - NEW at 10102:6c 0 KEY_DOWN_UP devinput (KEY_DOWN_UP)
20:00:04 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:04 T:140583711201152   DEBUG: LIRC: Update - NEW at 11118:160 0 KEY_OK devinput (KEY_OK)
20:00:04 T:140583711201152   DEBUG: OnKey: 11 (0x0b) pressed, action is Select
20:00:04 T:140583711201152   DEBUG: Activating window ID: 10111
20:00:04 T:140583711201152   DEBUG: ------ Window Init (DialogButtonMenu.xml) ------
20:00:04 T:140583711201152    INFO: Loading skin file: DialogButtonMenu.xml, load type: KEEP_IN_MEMORY
20:00:05 T:140583711201152   DEBUG: LIRC: Update - NEW at 11491:160 0 KEY_OK_UP devinput (KEY_OK_UP)
20:00:05 T:140583711201152   DEBUG: LIRC: Update - NEW at 11872:6c 0 KEY_DOWN devinput (KEY_DOWN)
20:00:05 T:140583711201152   DEBUG: OnKey: 167 (0xa7) pressed, action is Down
20:00:05 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:05 T:140583711201152   DEBUG: LIRC: Update - NEW at 12249:6c 0 KEY_DOWN_UP devinput (KEY_DOWN_UP)
20:00:05 T:140583711201152   DEBUG: LIRC: Update - NEW at 12290:6c 0 KEY_DOWN devinput (KEY_DOWN)
20:00:05 T:140583711201152   DEBUG: OnKey: 167 (0xa7) pressed, action is Down
20:00:06 T:140583711201152   DEBUG: LIRC: Update - NEW at 12669:6c 0 KEY_DOWN_UP devinput (KEY_DOWN_UP)
20:00:06 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:06 T:140583711201152   DEBUG: LIRC: Update - NEW at 13186:160 0 KEY_OK devinput (KEY_OK)
20:00:06 T:140583711201152   DEBUG: OnKey: 11 (0x0b) pressed, action is Select
20:00:06 T:140583711201152   DEBUG: ------ Window Deinit (DialogButtonMenu.xml) ------
20:00:06 T:140583711201152   DEBUG: LogindUPowerSyscall: Received PrepareForSleep with arg 1
20:00:06 T:140583711201152   DEBUG: CAnnouncementManager - Announcement: OnSleep from xbmc
20:00:06 T:140583711201152   DEBUG: GOT ANNOUNCEMENT, type: 8, from xbmc, message OnSleep
20:00:07 T:140582894774016   DEBUG: Thread CECAdapterUpdate 140582894774016 terminating
20:00:07 T:140583456724736   DEBUG: Process - sending standby commands
20:00:07 T:140583465117440   DEBUG: CecLogMessage - << putting 'TV' (0) in standby mode
20:00:07 T:140583465117440   DEBUG: CecLogMessage - << 40:36
20:00:07 T:140583465117440   DEBUG: CecLogMessage - << putting 'Audio' (5) in standby mode
20:00:07 T:140583465117440   DEBUG: CecLogMessage - << 45:36
20:00:07 T:140583465117440   DEBUG: CecLogMessage - unregistering all CEC clients
20:00:07 T:140583465117440   DEBUG: CecLogMessage - unregistering client: libCEC version = 3.0.0, client version = 3.0.0, firmware version = 4, firmware build date: Thu Dec  6 11:15:20 2012 +0000, logical address(es) = Playback 1 (4) , physical address: 1.1.0.0, compiled on Linux-1, features: P8_USB, P8_detect, randr
20:00:07 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): power status changed from 'on' to 'unknown'
20:00:07 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): vendor = Unknown (000000)
20:00:07 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): CEC version unknown
20:00:07 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): osd name set to 'Playback 1'
20:00:07 T:140583465117440   DEBUG: CecLogMessage - marking Playback 1 (4) as inactive source
20:00:07 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): device status changed into 'unknown'
20:00:07 T:140583465117440   DEBUG: CecLogMessage - setting ackmask to  0
20:00:07 T:140583465117440   DEBUG: CecLogMessage - turning controlled mode off
20:00:07 T:140583465117440   DEBUG: CecLogMessage - unregistering all CEC clients
20:00:07 T:140582331586304  NOTICE: EMBY LibrarySync -> Doing LibraryChanged : Processing Deleted : [u'de808bbee83277306a5004ac5c6418ac', u'f76db10a79dbef722218cb8756eebf1c', u'660b212e3ff7c5377655ccd8dededba2', u'75faafbc57b601d254765d4a7c80dc4c', u'92fbe779a6e2d7142bcd7bba31eb0733', u'06908c5b0cae8150b3a210e44e6a800e', u'ce0eb985edc8beab68ff719de41b3ebc', u'7871b8d2a9ad7e9e81603bb9899f535c', u'b366e2e584687635c9d0ffc04613d2a4', u'1b233fe05b41db0873ef2d6eabfc3c99', u'82ced709adcb11bf32bb20f4970c97b6', u'1a719a684d6ce30334541a8569e5b53d', u'fd1b6b3c1ec5254bafc442daa39f43dc', u'de4a5c7890ccb51992c0d50c218440b5', u'243d46715e2336cd865d60806ce182db', u'35c24856d2ab4da2fa703c9e16779c2c', u'879d054243ce736081c6a39f69eb6b45', u'812d2ee34d4c8b8a8b488b68f85e1f22']
20:00:07 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:07 T:140582323193600  NOTICE: EMBY LibrarySync -> Sync Database, Incremental Sync Using Client Time -5 min: 2015-09-29T02:55:07Z
20:00:07 T:140582323193600  NOTICE: EMBY LibrarySync -> Sync Database, Incremental Sync Setting Last Run Time Saved: 2015-09-29T02:55:07Z
20:00:07 T:140583465117440   DEBUG: CecLogMessage - communication thread ended
20:00:08 T:140583456724736   DEBUG: Process - CEC adapter processor thread ended
20:00:08 T:140583456724736   DEBUG: Thread CECAdapter 140583456724736 terminating
20:00:08 T:140583711201152   DEBUG: ------ Window Init (DialogBusy.xml) ------
20:00:08 T:140583711201152  NOTICE: OnSleep: Running sleep jobs
20:00:08 T:140583711201152  NOTICE: OnSleep: Stopping lirc
20:00:08 T:140583711201152    INFO: LIRC SetEnabled: disabled
20:00:08 T:140583711201152   DEBUG: CApplication::CloseNetworkShares: Closing all network shares
20:00:08 T:140583711201152   DEBUG: LogindUPowerSyscall - delay lock released
20:00:08 T:140583711201152    INFO: LIRC SetEnabled: disabled
20:00:08 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:08 T:140582323193600   DEBUG: Previous line repeats 11 times.
20:00:08 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:08 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:14 T:140583448332032   DEBUG: Previous line repeats 11 times.
20:00:14 T:140583448332032  NOTICE: UnregisterRemovedDevices - device removed from cec//dev/ttyACM0: CEC Adapter (2548:1002)
20:00:14 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:14 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:14 T:140583711201152   DEBUG: ------ Window Init (DialogKaiToast.xml) ------
20:00:14 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:14 T:140583456724736   DEBUG: Previous line repeats 8 times.
20:00:14 T:140583456724736  NOTICE: Thread RemoteControl start, auto delete: false
20:00:14 T:140583456724736    INFO: LIRC Process: using: /run/lirc/lircd
20:00:14 T:140583456724736    INFO: LIRC Connect: successfully started
20:00:14 T:140583456724736   DEBUG: Thread RemoteControl 140583456724736 terminating
20:00:14 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:15 T:140583448332032   DEBUG: Previous line repeats 8 times.
20:00:15 T:140583448332032   DEBUG: GetMappingForDevice - device (2548:1002) mapped to CEC Adapter (type = cec)
20:00:15 T:140583448332032   DEBUG: InitialiseFeature - using libCEC v3.0.0
20:00:15 T:140583448332032   DEBUG: Initialise - initialised peripheral on '/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3' with 2 features and 0 sub devices
20:00:15 T:140583448332032  NOTICE: Register - new cec device registered on cec->/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3: CEC Adapter (2548:1002)
20:00:15 T:140583456724736  NOTICE: Thread CECAdapter start, auto delete: false
20:00:15 T:140583456724736   DEBUG: OpenConnection - opening a connection to the CEC adapter: /sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3
20:00:15 T:140583465117440   DEBUG: CecLogMessage - Broadcast (F): osd name set to 'Broadcast'
20:00:15 T:140583711201152   DEBUG: LogindUPowerSyscall: Received PrepareForSleep with arg 0
20:00:15 T:140583711201152  NOTICE: OnWake: Running resume jobs
20:00:15 T:140583711201152  NOTICE: OnWake: Restarting lirc
20:00:15 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:15 T:140583700645632   DEBUG: Previous line repeats 1 times.
20:00:15 T:140583700645632    INFO: CAESinkALSA - Unable to open device "surround21:CARD=PCH,DEV=0" for playback
20:00:15 T:140583700645632   DEBUG: CAESinkALSA - HDMI device "hdmi:CARD=PCH,DEV=1" may be unconnected (no ELD data)
20:00:15 T:140583700645632  NOTICE: Found 1 Lists of Devices
20:00:15 T:140583700645632  NOTICE: Enumerated ALSA devices:
20:00:15 T:140583700645632  NOTICE:     Device 1
20:00:15 T:140583700645632  NOTICE:         m_deviceName      : @
20:00:15 T:140583700645632  NOTICE:         m_displayName     : Default (HDA Intel PCH ALC662 rev1 Analog)
20:00:15 T:140583700645632  NOTICE:         m_displayNameExtra:
20:00:15 T:140583700645632  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
20:00:15 T:140583700645632  NOTICE:         m_channels        : FL,FR
20:00:15 T:140583700645632  NOTICE:         m_sampleRates     : 48000
20:00:15 T:140583700645632  NOTICE:         m_dataFormats     : AE_FMT_S32NE
20:00:15 T:140583700645632  NOTICE:     Device 2
20:00:15 T:140583700645632  NOTICE:         m_deviceName      : @:CARD=PCH,DEV=0
20:00:15 T:140583700645632  NOTICE:         m_displayName     : HDA Intel PCH
20:00:15 T:140583700645632  NOTICE:         m_displayNameExtra: ALC662 rev1 Analog
20:00:15 T:140583700645632  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
20:00:15 T:140583700645632  NOTICE:         m_channels        : FL,FR
20:00:15 T:140583700645632  NOTICE:         m_sampleRates     : 48000
20:00:15 T:140583700645632  NOTICE:         m_dataFormats     : AE_FMT_S32NE
20:00:15 T:140583700645632  NOTICE:     Device 3
20:00:15 T:140583700645632  NOTICE:         m_deviceName      : hdmi:CARD=PCH,DEV=0
20:00:15 T:140583700645632  NOTICE:         m_displayName     : HDA Intel PCH
20:00:15 T:140583700645632  NOTICE:         m_displayNameExtra: ONK TX-SR309 on HDMI
20:00:15 T:140583700645632  NOTICE:         m_deviceType      : AE_DEVTYPE_HDMI
20:00:15 T:140583700645632  NOTICE:         m_channels        : FL,FR,LFE,FC,BL,BR
20:00:15 T:140583700645632  NOTICE:         m_sampleRates     : 32000,44100,48000,88200,96000,176400,192000
20:00:15 T:140583700645632  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
20:00:15 T:140583700645632  NOTICE:     Device 4
20:00:15 T:140583700645632  NOTICE:         m_deviceName      : hdmi:CARD=PCH,DEV=1
20:00:15 T:140583700645632  NOTICE:         m_displayName     : HDA Intel PCH
20:00:15 T:140583700645632  NOTICE:         m_displayNameExtra: HDMI
20:00:15 T:140583700645632  NOTICE:         m_deviceType      : AE_DEVTYPE_HDMI
20:00:15 T:140583700645632  NOTICE:         m_channels        : FL,FR,LFE,FC,BC,BL,BR,FLOC,FROC,BLOC,BROC,TFC,TC,TFL,TFR,UNKNOWN1
20:00:15 T:140583700645632  NOTICE:         m_sampleRates     : 32000,44100,48000,88200,96000,176400,192000
20:00:15 T:140583700645632  NOTICE:         m_dataFormats     : AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE,AE_FMT_LPCM,AE_FMT_DTSHD,AE_FMT_TRUEHD,AE_FMT_EAC3,AE_FMT_DTS,AE_FMT_AC3,AE_FMT_AAC
20:00:15 T:140583692252928    INFO: CActiveAESink::OpenSink - initialize sink
20:00:15 T:140583692252928   DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=PCH,DEV=0
20:00:15 T:140583692252928    INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=PCH,DEV=0"
20:00:15 T:140583692252928    INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=PCH,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
20:00:15 T:140583692252928    INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
20:00:15 T:140583692252928    INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
20:00:15 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
20:00:15 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:15 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
20:00:15 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
20:00:15 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
20:00:15 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
20:00:15 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
20:00:15 T:140583692252928   DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
20:00:15 T:140583692252928   DEBUG:   Output Device : HDA Intel PCH
20:00:15 T:140583692252928   DEBUG:   Sample Rate   : 44100
20:00:15 T:140583692252928   DEBUG:   Sample Format : AE_FMT_S32NE
20:00:15 T:140583692252928   DEBUG:   Channel Count : 2
20:00:15 T:140583692252928   DEBUG:   Channel Layout: FL,FR
20:00:15 T:140583692252928   DEBUG:   Frames        : 2048
20:00:15 T:140583692252928   DEBUG:   Frame Samples : 4096
20:00:15 T:140583692252928   DEBUG:   Frame Size    : 8
20:00:15 T:140583700645632   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
20:00:15 T:140583711201152   DEBUG: CAnnouncementManager - Announcement: OnWake from xbmc
20:00:15 T:140583711201152   DEBUG: GOT ANNOUNCEMENT, type: 8, from xbmc, message OnWake
20:00:15 T:140583711201152   DEBUG: LogindUPowerSyscall - inhibit lock taken, fd 65
20:00:15 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:15 T:140583711201152   DEBUG: Previous line repeats 3 times.
20:00:15 T:140583711201152   DEBUG: ------ Window Deinit (DialogBusy.xml) ------
20:00:15 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:18 T:140583711201152  NOTICE: Previous line repeats 1 times.
20:00:18 T:140583711201152   DEBUG: NotifyXRREvent - notify display reset event
20:00:18 T:140583711201152   ERROR: WinSystemX11::RefreshWindow - failed to query xrandr
20:00:18 T:140583711201152   DEBUG: NotifyXRREvent - notify display reset event
20:00:18 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:18 T:140583711201152   ERROR: WinSystemX11::RefreshWindow - failed to query xrandr
20:00:18 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:19 T:140583465117440   ERROR: CecLogMessage - error opening serial port '/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3': Couldn't lock the serial port
20:00:19 T:140583465117440   ERROR: CecLogMessage - could not open a connection (try 1)
20:00:19 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:20 T:140583448332032  NOTICE: Previous line repeats 1 times.
20:00:20 T:140583448332032  NOTICE: UnregisterRemovedDevices - device removed from cec//sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3: CEC Adapter (2548:1002)
20:00:21 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:22 T:140583465117440   ERROR: CecLogMessage - error opening serial port '/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3': Couldn't lock the serial port
20:00:22 T:140583465117440   ERROR: CecLogMessage - could not open a connection (try 2)
20:00:22 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:24 T:140583465117440  NOTICE: Previous line repeats 1 times.
20:00:24 T:140583465117440   ERROR: CecLogMessage - error opening serial port '/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3': Couldn't lock the serial port
20:00:24 T:140583465117440   ERROR: CecLogMessage - could not open a connection (try 3)
20:00:24 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:25 T:140583465117440   ERROR: CecLogMessage - error opening serial port '/sys/devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.2/1-1.2.3': Couldn't lock the serial port
20:00:25 T:140583465117440   ERROR: CecLogMessage - could not open a connection (try 4)
20:00:25 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:26 T:140583711201152   DEBUG: ------ Window Deinit (DialogKaiToast.xml) ------
20:00:26 T:140583456724736   ERROR: OpenConnection - could not opening a connection to the CEC adapter
20:00:26 T:140583465117440   DEBUG: CecLogMessage - connection opened
20:00:26 T:140583456724736   DEBUG: Thread CECAdapter 140583456724736 terminating
20:00:26 T:140583465117440   ERROR: CecLogMessage - could not start CEC communications
20:00:26 T:140583711201152   DEBUG: ------ Window Init (DialogKaiToast.xml) ------
20:00:26 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:26 T:140582323193600  NOTICE: EMBY LibrarySync -> Doing_Db_Sync Post Resume: syncDatabase (Started)
20:00:26 T:140583448332032   DEBUG: GetMappingForDevice - device (2548:1002) mapped to CEC Adapter (type = cec)
20:00:26 T:140583448332032   DEBUG: InitialiseFeature - using libCEC v3.0.0
20:00:26 T:140583448332032   DEBUG: Initialise - initialised peripheral on '/dev/ttyACM0' with 2 features and 0 sub devices
20:00:26 T:140583448332032  NOTICE: Register - new cec device registered on cec->/dev/ttyACM0: CEC Adapter (2548:1002)
20:00:26 T:140583456724736  NOTICE: Thread CECAdapter start, auto delete: false
20:00:26 T:140583456724736   DEBUG: OpenConnection - opening a connection to the CEC adapter: /dev/ttyACM0
20:00:26 T:140583465117440   DEBUG: CecLogMessage - Broadcast (F): osd name set to 'Broadcast'
20:00:26 T:140583465117440   DEBUG: CecLogMessage - connection opened, clearing any previous input and waiting for active transmissions to end before starting
20:00:26 T:140583465117440   DEBUG: CecLogMessage - communication thread started
20:00:26 T:140583465117440   DEBUG: CecLogMessage - turning controlled mode on
20:00:26 T:140583465117440   DEBUG: CecLogMessage - connection opened
20:00:26 T:140583465117440   DEBUG: CecLogMessage - << Broadcast (F) -> TV (0): POLL
20:00:26 T:140583465117440   DEBUG: CecLogMessage - << f0
20:00:26 T:140583465117440   DEBUG: CecLogMessage - setting the line timeout to 3
20:00:26 T:140583465117440   DEBUG: CecLogMessage - processor thread started
20:00:26 T:140583465117440   DEBUG: CecLogMessage - >> POLL sent
20:00:26 T:140583465117440   DEBUG: CecLogMessage - TV (0): device status changed into 'present'
20:00:26 T:140583465117440   DEBUG: CecLogMessage - << requesting vendor ID of 'TV' (0)
20:00:26 T:140583465117440   DEBUG: CecLogMessage - << f0:8c
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> 0f:87:00:80:45
20:00:27 T:140583465117440   DEBUG: CecLogMessage - TV (0): vendor = Panasonic (008045)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - expected response received (87: device vendor id)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - replacing the command handler for device 'TV' (0)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - registering new CEC client - v3.0.0
20:00:27 T:140583465117440   DEBUG: CecLogMessage - detecting logical address for type 'playback device'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - trying logical address 'Playback 1'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Playback 1 (4): POLL
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 44
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): device vendor id (87)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 44
20:00:27 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using logical address 'Playback 1'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): device status changed into 'handled by libCEC'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): power status changed from 'unknown' to 'on'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): vendor = Pulse Eight (001582)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): CEC version 1.4
20:00:27 T:140583465117440   DEBUG: CecLogMessage - AllocateLogicalAddresses - device '0', type 'playback device', LA '4'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - setting ackmask to 10
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): osd name set to 'Kodi'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): menu language set to 'eng'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - trying to get the physical address via ADL
20:00:27 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - ADL returned physical address 0000
20:00:27 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - trying to get the physical address via nvidia driver
20:00:27 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - nvidia driver returned physical address 0000
20:00:27 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - trying to get the physical address from the OS
20:00:27 T:140583465117440   DEBUG: CecLogMessage - GetPhysicalAddress - OS returned physical address 0000
20:00:27 T:140583465117440   DEBUG: CecLogMessage - setting HDMI port to 1 on device TV (0)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): physical address changed from ffff to 1000
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): physical adddress 1000
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 4f:84:10:00:04
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted autonomous mode setting: 'enabled'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted CEC version setting: '1.4'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted logical address setting: 'Playback 1'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted device type setting: 'playback device'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted logical address mask setting: '910'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted device name setting: 'Kodi'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - using persisted physical address setting: '1100'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - setting the physical address to 1000 (previous: 1100)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - making Playback 1 (4) the active source
20:00:27 T:140583465117440   DEBUG: CecLogMessage - TV (0): power status changed from 'unknown' to 'in transition from standby to on'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - marking the adapter as active source
20:00:27 T:140583465117440   DEBUG: CecLogMessage - writing settings in the EEPROM
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - scheduling active source message for 'Playback 1'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - CEC client registered: libCEC version = 3.0.0, client version = 3.0.0, firmware version = 4, firmware build date: Thu Dec  6 11:15:20 2012 +0000, logical address(es) = Playback 1 (4) , base device: TV (0), HDMI port number: 1, physical address: 1.0.0.0, compiled on Linux-1, features: P8_USB, P8_detect, randr
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4): vendor = Panasonic (008045)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - replacing the command handler for device 'Playback 1' (4)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): OSD name 'Kodi'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 40:47:4b:6f:64:69
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << requesting power status of 'TV' (0)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 40:8f
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> 04:90:01
20:00:27 T:140583465117440   DEBUG: CecLogMessage - TV (0): power status changed from 'in transition from standby to on' to 'standby'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - expected response received (90: report power status)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): report power status (90)
20:00:27 T:140583456724736   DEBUG: OpenConnection - connection to the CEC adapter opened
20:00:27 T:140582894774016  NOTICE: Thread CECAdapterUpdate start, auto delete: false
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4) was already marked as active source
20:00:27 T:140583465117440   DEBUG: CecLogMessage - TV (0): power status changed from 'standby' to 'in transition from standby to on'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - sending active source message for 'Playback 1'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << requesting power status of 'Playback 1' (0)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 40:8f
20:00:27 T:140583465117440   DEBUG: CecLogMessage - source switch is currently not allowed by command handler
20:00:27 T:140583465117440   DEBUG: CecLogMessage - failed to make 'Playback 1' the active source. will retry later
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Audio (5): POLL
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 45
20:00:27 T:140583465117440   DEBUG: CecLogMessage - >> POLL sent
20:00:27 T:140583465117440   DEBUG: CecLogMessage - Audio (5): device status changed into 'present'
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << requesting vendor ID of 'Audio' (5)
20:00:27 T:140583465117440   DEBUG: CecLogMessage - << 45:8c
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> 5f:87:00:09:b0
20:00:28 T:140583465117440   DEBUG: CecLogMessage - Audio (5): vendor = Onkyo (0009b0)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): device vendor id (87)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - expected response received (87: device vendor id)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - replacing the command handler for device 'Audio' (5)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << requesting power status of 'Audio' (5)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << 45:8f
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> 54:90:01
20:00:28 T:140583465117440   DEBUG: CecLogMessage - Audio (5): power status changed from 'unknown' to 'standby'
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Playback 1 (4): report power status (90)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - expected response received (90: report power status)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << powering on 'Audio' (5)
20:00:28 T:140583465117440   DEBUG: CecLogMessage - source switch is currently not allowed by command handler
20:00:28 T:140583465117440   DEBUG: CecLogMessage - failed to make 'Playback 1' the active source. will retry later
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << 45:44:40
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << 45:45
20:00:28 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:28 T:140583465117440   DEBUG: CecLogMessage - << 45:45
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> 50:7a:30
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5): audio status changed from 7f to 30
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> 0f:a0:00:80:45:20:00:00
20:00:28 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): vendor command with id (A0)
20:00:29 T:140583465117440   DEBUG: CecLogMessage - >> 50:a0:00:00:39:02
20:00:29 T:140583465117440   DEBUG: CecLogMessage - >> 04:90:02
20:00:29 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): report power status (90)
20:00:29 T:140582323193600  NOTICE: EMBY LibrarySync -> Sync Database, Incremental Sync Using Client Time -5 min: 2015-09-29T02:55:29Z
20:00:29 T:140583711201152   DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
20:00:29 T:140582348371712  NOTICE: VideoInfoScanner: Starting scan ..
20:00:29 T:140582348371712   DEBUG: CAnnouncementManager - Announcement: OnScanStarted from xbmc
20:00:29 T:140582348371712   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanStarted
20:00:29 T:140582348371712  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
20:00:29 T:140582348371712   DEBUG: CAnnouncementManager - Announcement: OnScanFinished from xbmc
20:00:29 T:140582348371712   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanFinished
20:00:29 T:140582323193600  NOTICE: EMBY LibrarySync -> Sync Database, Incremental Sync Setting Last Run Time Saved: 2015-09-29T02:55:29Z
20:00:29 T:140582877988608   DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update
20:00:29 T:140582877988608   DEBUG: RunQuery took 1 ms for 10 items query: select * from movie_view  ORDER BY dateAdded desc, idMovie desc LIMIT 10
20:00:29 T:140582877988608   DEBUG: RunQuery took 12 ms for 10 items query: select * from episode_view  ORDER BY dateAdded desc, idEpisode desc LIMIT 10
20:00:29 T:140582877988608   DEBUG: RunQuery took 2 ms for 0 items query: select * from musicvideo_view  ORDER BY dateAdded desc, idMVideo desc LIMIT 10
20:00:29 T:140582877988608   DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update
20:00:29 T:140582323193600  NOTICE: Sync DB -> syncDatabase Exiting
20:00:29 T:140583711201152   DEBUG: ------ Window Deinit (DialogExtendedProgressBar.xml) ------
20:00:29 T:140582323193600  NOTICE: EMBY LibrarySync -> Doing_Db_Sync Post Resume: syncDatabase (Finished) True
20:00:30 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:30 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:30 T:140583465117440   DEBUG: CecLogMessage - source switch is currently not allowed by command handler
20:00:30 T:140583465117440   DEBUG: CecLogMessage - failed to make 'Playback 1' the active source. will retry later
20:00:30 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:30 T:140583423153920   DEBUG: GetMappingForDevice - device (2548:1002) mapped to Pulse-Eight CEC Adapter (type = cec)
20:00:30 T:140583711201152   DEBUG: NotifyXRREvent - notify display reset event
20:00:30 T:140583711201152    INFO: Available videomodes (xrandr):
20:00:30 T:140583711201152    INFO: Output 'HDMI1' has 23 modes
20:00:30 T:140583711201152    INFO: ID:0xe9 Name:1920x1080i Refresh:30.000000 Width:1920 Height:1080
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xfc Name:1920x1080i Refresh:25.000000 Width:1920 Height:1080
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xeb Name:1920x1080i Refresh:29.970100 Width:1920 Height:1080
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0x49 Name:1920x1080 Refresh:60.000000 Width:1920 Height:1080
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xfb Name:1920x1080 Refresh:50.000000 Width:1920 Height:1080
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xe8 Name:1920x1080 Refresh:59.940201 Width:1920 Height:1080
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xfd Name:2880x576 Refresh:50.000000 Width:2880 Height:576
20:00:30 T:140583711201152    INFO: Pixel Ratio: 0.355779
20:00:30 T:140583711201152    INFO: ID:0xed Name:2880x480 Refresh:60.000000 Width:2880 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 0.296482
20:00:30 T:140583711201152    INFO: ID:0xee Name:2880x480 Refresh:59.940060 Width:2880 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 0.296482
20:00:30 T:140583711201152    INFO: ID:0xf1 Name:1280x720 Refresh:60.000000 Width:1280 Height:720
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xfe Name:1280x720 Refresh:50.000000 Width:1280 Height:720
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xf2 Name:1280x720 Refresh:59.940201 Width:1280 Height:720
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.000628
20:00:30 T:140583711201152    INFO: ID:0xff Name:1440x576 Refresh:50.000000 Width:1440 Height:576
20:00:30 T:140583711201152    INFO: Pixel Ratio: 0.711558
20:00:30 T:140583711201152    INFO: ID:0xf3 Name:1440x480 Refresh:60.000000 Width:1440 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 0.592965
20:00:30 T:140583711201152    INFO: ID:0xf4 Name:1440x480 Refresh:59.940060 Width:1440 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 0.592965
20:00:30 T:140583711201152    INFO: ID:0x100 Name:720x576 Refresh:50.000000 Width:720 Height:576
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.423116
20:00:30 T:140583711201152    INFO: ID:0x101 Name:720x576i Refresh:25.000000 Width:720 Height:576
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.423116
20:00:30 T:140583711201152    INFO: ID:0xf5 Name:720x480 Refresh:60.000000 Width:720 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.185930
20:00:30 T:140583711201152    INFO: ID:0xf6 Name:720x480 Refresh:59.940060 Width:720 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.185930
20:00:30 T:140583711201152    INFO: ID:0xf7 Name:720x480i Refresh:29.998890 Width:720 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.185930
20:00:30 T:140583711201152    INFO: ID:0xf8 Name:720x480i Refresh:29.970030 Width:720 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.185930
20:00:30 T:140583711201152    INFO: ID:0xf9 Name:640x480 Refresh:60.000000 Width:640 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.334171
20:00:30 T:140583711201152    INFO: ID:0xfa Name:640x480 Refresh:59.940479 Width:640 Height:480
20:00:30 T:140583711201152    INFO: Pixel Ratio: 1.334171
20:00:30 T:140583711201152   DEBUG: RecreateWindow - current output: HDMI1, mode: 0x49, refresh: 60.000
20:00:30 T:140583711201152   DEBUG: OnLostDevice - notify display change event
20:00:30 T:140583711201152   DEBUG: Window Manager Name: Fluxbox
20:00:30 T:140583711201152   ERROR: CWinSystemX11::XErrorHandler: BadAtom (invalid Atom parameter), type:0, serial:3339, error_code:5, request_code:18 minor_code:0
20:00:30 T:140583711201152   DEBUG: CWinSystemX11::RefreshGlxContext: refreshing context
20:00:30 T:140583700645632   DEBUG: CActiveAE - display reset event
20:00:30 T:140583692252928    INFO: CActiveAESink::OpenSink - initialize sink
20:00:30 T:140583692252928   DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=PCH,DEV=0
20:00:30 T:140583692252928    INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=PCH,DEV=0"
20:00:30 T:140583692252928    INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=PCH,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x00"
20:00:30 T:140583692252928    INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
20:00:30 T:140583692252928    INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
20:00:30 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 2048, bufferSize 8192
20:00:30 T:140583711201152    INFO: GL: Maximum texture width: 8192
20:00:30 T:140583711201152   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
20:00:30 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 2048, bufferSize 8192
20:00:30 T:140583692252928   DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 186 ms
20:00:30 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 2 Output Channel Count: 2
20:00:30 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR
20:00:30 T:140583692252928   DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR (ALSA: FL FR)
20:00:30 T:140583692252928   DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
20:00:30 T:140583692252928   DEBUG:   Output Device : HDA Intel PCH
20:00:30 T:140583692252928   DEBUG:   Sample Rate   : 44100
20:00:30 T:140583692252928   DEBUG:   Sample Format : AE_FMT_S32NE
20:00:30 T:140583692252928   DEBUG:   Channel Count : 2
20:00:30 T:140583692252928   DEBUG:   Channel Layout: FL,FR
20:00:30 T:140583692252928   DEBUG:   Frames        : 2048
20:00:30 T:140583692252928   DEBUG:   Frame Samples : 4096
20:00:30 T:140583692252928   DEBUG:   Frame Size    : 8
20:00:30 T:140583700645632   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
20:00:30 T:140583711201152    INFO: CheckIdle - Closing session to http://mirrors.kodi.tv (easy=0x4bebf60, multi=0x4c70800)
20:00:31 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:31 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:31 T:140583465117440   DEBUG: CecLogMessage - source switch is currently not allowed by command handler
20:00:31 T:140583465117440   DEBUG: CecLogMessage - failed to make 'Playback 1' the active source. will retry later
20:00:31 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:32 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:32 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:32 T:140583465117440   DEBUG: CecLogMessage - source switch is currently not allowed by command handler
20:00:32 T:140583465117440   DEBUG: CecLogMessage - failed to make 'Playback 1' the active source. will retry later
20:00:32 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:32 T:140583465117440   DEBUG: CecLogMessage - >> 0f:a0:00:80:45:20:00:00
20:00:32 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): vendor command with id (A0)
20:00:33 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:33 T:140583465117440   DEBUG: CecLogMessage - << requesting power status of 'TV' (0)
20:00:33 T:140583465117440   DEBUG: CecLogMessage - << 40:8f
20:00:33 T:140583465117440   DEBUG: CecLogMessage - expected response received (90: report power status)
20:00:33 T:140583465117440   DEBUG: CecLogMessage - >> 05:70:00:00
20:00:33 T:140583465117440   DEBUG: CecLogMessage - TV (0): power status changed from 'in transition from standby to on' to 'on'
20:00:33 T:140583465117440   DEBUG: CecLogMessage - << 40:89:10:02:ff:ff:00:05:05:45:55:5c:58:32
20:00:33 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:33 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:33 T:140583711201152   DEBUG: ------ Window Deinit (DialogKaiToast.xml) ------
20:00:34 T:140583711201152    INFO: CheckIdle - Closing session to https://plexus.svn.codeplex.com (easy=0x5129c60, multi=0x4c61e00)
20:00:34 T:140583711201152    INFO: CheckIdle - Closing session to http://www.mb3admin.com (easy=0x539f5b0, multi=0x526b720)
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1000)
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:10:00
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): menu state 'activated'
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 40:8e:00
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> 04:90:00
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): report power status (90)
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> 04:00:89:03
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): feature abort ( 0)
20:00:34 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:34 T:140583711201152    INFO: CheckIdle - Closing session to http://addons.openelec.tv (easy=0x513b4c0, multi=0x5362ff0)
20:00:34 T:140582894774016   DEBUG: UpdateMenuLanguage - using TV menu language is disabled
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Recorder 1 (1): POLL
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 41
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> 05:70:00:00
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 41
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:34 T:140583465117440   DEBUG: CecLogMessage - Recorder 1 (1): device status changed into 'not present'
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Recorder 2 (2): POLL
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 42
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 42
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:34 T:140583465117440   DEBUG: CecLogMessage - Recorder 2 (2): device status changed into 'not present'
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 1 (3): POLL
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 43
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 43
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:34 T:140583465117440   DEBUG: CecLogMessage - Tuner 1 (3): device status changed into 'not present'
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 2 (6): POLL
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 46
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 46
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:34 T:140583465117440   DEBUG: CecLogMessage - Tuner 2 (6): device status changed into 'not present'
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 3 (7): POLL
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 47
20:00:34 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:34 T:140583465117440   DEBUG: CecLogMessage - << 47
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Tuner 3 (7): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Playback 2 (8): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 48
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 48
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Playback 2 (8): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Recorder 3 (9): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 49
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 49
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Recorder 3 (9): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Tuner 4 (A): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4a
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4a
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Tuner 4 (A): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Playback 3 (B): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4b
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4b
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Playback 3 (B): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Reserved 1 (C): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4c
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4c
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Reserved 1 (C): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Reserved 2 (D): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4d
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4d
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Reserved 2 (D): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Free use (E): POLL
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4e
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 4e
20:00:35 T:140583465117440   DEBUG: CecLogMessage - CEC transmission - received response - TRANSMIT_FAILED_ACK
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> POLL not sent
20:00:35 T:140583465117440   DEBUG: CecLogMessage - Free use (E): device status changed into 'not present'
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << requesting OSD name of 'Audio' (5)
20:00:35 T:140583465117440   DEBUG: CecLogMessage - << 45:46
20:00:35 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> 5f:72:01
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): set system audio mode (72)
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> 05:70:00:00
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> 05:71
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> 5f:72:01
20:00:35 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): set system audio mode (72)
20:00:36 T:140583465117440   DEBUG: CecLogMessage - >> 54:47:54:58:2d:53:52:33:30:39
20:00:36 T:140583465117440   DEBUG: CecLogMessage - Audio (5): osd name set to 'TX-SR309'
20:00:36 T:140582894774016   DEBUG: UpdateAudioSystemStatus - CEC capable amplifier found (TX-SR309). volume will be controlled on the amp
20:00:36 T:140582894774016   DEBUG: CAnnouncementManager - Announcement: OnVolumeChanged from xbmc
20:00:36 T:140583465117440   DEBUG: CecLogMessage - expected response received (47: set osd name)
20:00:36 T:140582894774016   DEBUG: GOT ANNOUNCEMENT, type: 64, from xbmc, message OnVolumeChanged
20:00:36 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Playback 1 (4): set osd name (47)
20:00:36 T:140583711201152   DEBUG: ------ Window Init (DialogKaiToast.xml) ------
20:00:36 T:140583465117440   DEBUG: CecLogMessage - >> 5f:72:01
20:00:36 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): set system audio mode (72)
20:00:36 T:140583465117440   DEBUG: CecLogMessage - >> 50:7a:30
20:00:36 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:37 T:140583465117440   DEBUG: CecLogMessage - >> 50
20:00:37 T:140583465117440   DEBUG: CecLogMessage - << POLL: Audio (5) -> TV (0)
20:00:37 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:39 T:140583465117440  NOTICE: Previous line repeats 1 times.
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> 55
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << POLL: Audio (5) -> Audio (5)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> 55
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << POLL: Audio (5) -> Audio (5)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> 50
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << POLL: Audio (5) -> TV (0)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> 50:83
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> 0f:84:00:00:00
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): physical adddress 1000
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << 4f:84:10:00:04
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): report physical address (84)
20:00:39 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> 5f:84:10:00:05
20:00:39 T:140583465117440   DEBUG: CecLogMessage - Audio (5): physical address changed from ffff to 1000
20:00:39 T:140583465117440   DEBUG: CecLogMessage - setting physical address to '1000'
20:00:39 T:140583465117440   DEBUG: CecLogMessage - marking Playback 1 (4) as inactive source
20:00:39 T:140583465117440   DEBUG: CecLogMessage - marking the adapter as inactive source
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): report physical address (84)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> source deactivated: Playback 1 (4)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): physical adddress 1000
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << 4f:84:10:00:04
20:00:39 T:140583465117440   DEBUG: CecLogMessage - making Playback 1 (4) the active source
20:00:39 T:140583465117440   DEBUG: CecLogMessage - marking the adapter as active source
20:00:39 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - powering up the AVR
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << powering on 'Audio' (5)
20:00:39 T:140583465117440   DEBUG: CecLogMessage - << 45:44:40
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << 45:45
20:00:40 T:140583465117440   DEBUG: CecLogMessage - sending active source message for 'Playback 1'
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1000)
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:10:00
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): menu state 'activated'
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << 40:8e:00
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> 50:8c
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> 0f:87:00:80:45
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> Broadcast (F): vendor id Panasonic (8045)
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << 4f:87:00:80:45
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Broadcast (F): device vendor id (87)
20:00:40 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> 5f:87:00:09:b0
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): device vendor id (87)
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> 04:8c
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): vendor id Panasonic (8045)
20:00:40 T:140583465117440   DEBUG: CecLogMessage - << 4f:87:00:80:45
20:00:40 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): give device vendor id (8C)
20:00:41 T:140583465117440   DEBUG: CecLogMessage - >> 04:89:10:01:05
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << 40:89:10:02:ff:ff:00:05:05:45:55:5c:58:32
20:00:41 T:140583465117440   DEBUG: CecLogMessage - Playback 1 (4) was already marked as active source
20:00:41 T:140583465117440   DEBUG: CecLogMessage - >> source activated: Playback 1 (4)
20:00:41 T:140583465117440   DEBUG: CecLogMessage - scheduling active source message for 'Playback 1'
20:00:41 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command (89)
20:00:41 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:41 T:140583711201152   DEBUG: ------ Window Deinit (DialogKaiToast.xml) ------
20:00:41 T:140583465117440   DEBUG: CecLogMessage - >> 04:a0:00:80:45:06:05
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1000)
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:10:00
20:00:41 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command with id (A0)
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << powering on 'TV' (0)
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << 40:04
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1000)
20:00:41 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:10:00
20:00:42 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> TV (0): menu state 'activated'
20:00:42 T:140583465117440   DEBUG: CecLogMessage - << 40:8e:00
20:00:42 T:140583465117440   DEBUG: CecLogMessage - >> 50:9f
20:00:42 T:140583465117440   DEBUG: CecLogMessage - >> 05:9e:05
20:00:42 T:140583465117440   DEBUG: CecLogMessage - TV (0): CEC version 1.4
20:00:42 T:140583465117440   DEBUG: CecLogMessage - >> 50:a0:00:00:39:02
20:00:42 T:140583465117440   DEBUG: CecLogMessage - >> 05:00:a0:03
20:00:42 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:42 T:140583465117440   DEBUG: CecLogMessage - >> 04:a0:00:80:45:06:05
20:00:42 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1000)
20:00:42 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:10:00
20:00:42 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command with id (A0)
20:00:43 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:44 T:140583465117440   DEBUG: CecLogMessage - >> 04:a0:00:80:45:06:05
20:00:44 T:140583465117440   DEBUG: CecLogMessage - << Playback 1 (4) -> broadcast (F): active source (1000)
20:00:44 T:140583465117440   DEBUG: CecLogMessage - << 4f:82:10:00
20:00:44 T:140583465117440   DEBUG: CecLogMessage - >> TV (0) -> Playback 1 (4): vendor command with id (A0)
20:00:44 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:45 T:140583465117440   DEBUG: CecLogMessage - >> 05:8c
20:00:45 T:140583465117440   DEBUG: CecLogMessage - >> 5f:87:00:09:b0
20:00:45 T:140583465117440   DEBUG: CecLogMessage - >> Audio (5) -> Broadcast (F): device vendor id (87)
20:00:45 T:140583465117440   DEBUG: CecLogMessage - >> 05:a0:00:80:45:06:05
20:00:45 T:140583465117440   DEBUG: CecLogMessage - >> 50:00:a0:04
20:00:45 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:50 T:140583465117440  NOTICE: Previous line repeats 4 times.
20:00:50 T:140583465117440   DEBUG: CecLogMessage - >> 50:8f
20:00:50 T:140583465117440   DEBUG: CecLogMessage - >> 05:90:00
20:00:50 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:00:59 T:140582903166720  NOTICE: Previous line repeats 8 times.
20:00:59 T:140582903166720   DEBUG: Thread JobWorker 140582903166720 terminating (autodelete)
20:00:59 T:140582348371712   DEBUG: Thread JobWorker 140582348371712 terminating (autodelete)
20:00:59 T:140582877988608   DEBUG: Thread JobWorker 140582877988608 terminating (autodelete)
20:00:59 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:01:00 T:140583465117440   DEBUG: CecLogMessage - >> 50:8f
20:01:00 T:140583465117440   DEBUG: CecLogMessage - >> 05:90:00
20:01:00 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:01:01 T:140583711201152   DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-x86_64-linux.so)
20:01:01 T:140583711201152   DEBUG: Unloading: /ImageLib-x86_64-linux.so
20:01:01 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:01:09 T:140582483629824  NOTICE: Previous line repeats 7 times.
20:01:09 T:140582483629824  NOTICE: ES: Client  from 127.0.0.1 timed out
20:01:10 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:01:10 T:140583465117440   DEBUG: CecLogMessage - >> 50:8f
20:01:10 T:140583465117440   DEBUG: CecLogMessage - >> 05:90:00
20:01:11 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
20:01:15 T:140582483629824  NOTICE: Previous line repeats 4 times.
20:01:15 T:140582483629824  NOTICE: ES: Client  from 127.0.0.1 timed out
20:01:16 T:140582323193600  NOTICE: EMBY LibrarySync -> DB Version: 1.1.39
josh4trunks commented 8 years ago

I also posted this here. https://github.com/OpenELEC/OpenELEC.tv/issues/4346

Popsikill commented 8 years ago

Just wanted to add I am getting this also! HTPC: RPi2 OS: Openelec 6.0 TV: Sony KDL-55W800B Soundplate: Sony HTXT1

SSuuuuuper annoying

opdenkamp commented 8 years ago

@josh4trunks this is an issue with the EDID that's being read from your TV or with the OpenELEC build that you're using. libCEC doesn't get a valid EDID from xrandr, and then defaults to HDMI 1 of the TV. Which your AVR is using too. This is confusing the devices.

Try upgrading to the latest OpenELEC build and, if it still occurs, go to system -> input devices -> peripherals -> CEC adapter and set "connected to HDMI device" to "AVR" and the correct HDMI port number. Then press ok.

josh4trunks commented 8 years ago

@opdenkamp I am on the latest stable build I believe 6.0.0. I have changed that to AVR in my testing, which I do remember seeming to work temporarily. Then it usually resets itself and the option to choose connected device goes away after a few reboots/wakeups from suspend. But I don't remember exactly.

I'll try again and document my results and take pictures of the menu. Thanks

dsebastien commented 8 years ago

@opdenkamp I wanted to try your solution, but I don't find "connected to HDMI device" anywhere. Has this changed in recent versions? I'm using OpenElec 6.0.1

opdenkamp commented 7 years ago

Late response: if connected to HDMI device or HDMI port number is not displayed in Kodi, then it's auto-detected from the EDID, which contains the physical address. If this value is incorrect (e.g. TV switching to the wrong input when starting Kodi), then you can override the value, with the physical address setting (uint16_t)