Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bad video and high pitch audio tone #33

Open
yang299kms opened this issue Jan 1, 2013 · 13 comments
Open

bad video and high pitch audio tone #33

yang299kms opened this issue Jan 1, 2013 · 13 comments

Comments

@yang299kms
Copy link

from speedster:

I'm running 5af262e and at random during playback the screen will show a rainbow pattern of lines and audio will change to a high pitched tone.

Seems to happen for h264 video, I haven't had it occur with Xvid. This has happened on two units, one with passthrough enabled and one without.

I've attached a picture and xbmc log for assistance debugging, unfortunately as it occurs at random I haven't had debug logging enabled.

Photo of screen: https://dl.dropbox.com/u/91624507/IMG_0302.JPG
XBMC debug log: https://dl.dropbox.com/u/91624507/xbmc.20121231.log

the same thing happens to me, so far twice since the move to frodo. i think the cause for this also causes the freeze in video having to do w/ usb devices?

@speedst3r
Copy link

I have no external USB devices connected on either of my M1 units when this happens.

I also experience a random video freeze, mainly with h.264 content, where the audio keeps playing. After pausing playback the video will eventually catch up at a faster speed.

@yang299kms
Copy link
Author

just happened to me today, while playing 1080p mkv w/ dts 6.1 audio.
log below:

00:00:17 T:1093865120 NOTICE: -----------------------------------------------------------------------
00:00:17 T:1093865120 WARNING: Unable to determine Linux distribution
00:00:17 T:1093865120 NOTICE: Starting XBMC (12.0-RC3 Git:20130106-a6310e7), Platform: Linux (Unknown, 2.6.34 armv7l). Built on Jan 6 2013
00:00:17 T:1093865120 NOTICE: special://xbmc/ is mapped to: /usr/share/xbmc
00:00:17 T:1093865120 NOTICE: special://xbmcbin/ is mapped to: /usr/lib/xbmc
00:00:17 T:1093865120 NOTICE: special://masterprofile/ is mapped to: /root/.xbmc/userdata
00:00:17 T:1093865120 NOTICE: special://home/ is mapped to: /root/.xbmc
00:00:17 T:1093865120 NOTICE: special://temp/ is mapped to: /root/.xbmc/temp
00:00:17 T:1093865120 NOTICE: The executable running is: /usr/lib/xbmc/xbmc.bin
00:00:17 T:1093865120 NOTICE: Local hostname: opps
00:00:17 T:1093865120 NOTICE: Log File is located: /root/.xbmc/temp/xbmc.log
00:00:17 T:1093865120 NOTICE: -----------------------------------------------------------------------
00:00:17 T:1093865120 DEBUG: ConsoleKit.Manager: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.ConsoleKit was not provided by any .service files
00:00:17 T:1093865120 DEBUG: UPower: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.UPower was not provided by any .service files
00:00:17 T:1093865120 DEBUG: ConsoleKit.Manager: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.ConsoleKit was not provided by any .service files
00:00:17 T:1093865120 DEBUG: DeviceKit.Power: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.DeviceKit.Disks was not provided by any .service files
00:00:17 T:1093865120 DEBUG: Systemd error: org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.login1 was not provided by any .service files
00:00:17 T:1093865120 DEBUG: UPower: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.UPower was not provided by any .service files
00:00:17 T:1093865120 DEBUG: Previous line repeats 1 times.
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.front
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "front" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM sysdefault
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "sysdefault" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround71
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "surround71" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.front
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "front" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM sysdefault
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "sysdefault" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround51
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "surround51" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround71
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "surround71" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.front
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "front" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM sysdefault
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "sysdefault" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround40
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "surround40" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround51
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "surround51" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround71
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "surround71" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.front
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "front" for playback
00:00:17 T:1093865120 INFO: CAESinkALSA - ALSA: pcm.c:2211:(snd_pcm_open_noupdate) Unknown PCM sysdefault
00:00:17 T:1093865120 INFO: CAESinkALSA - Unable to open device "sysdefault" for playback
00:00:17 T:1093865120 ERROR: CAESinkOSS::EnumerateDevicesEx - Failed to open mixer: /dev/mixer
00:00:17 T:1093865120 NOTICE: Enumerated ALSA devices:
00:00:17 T:1093865120 NOTICE: Device 1
00:00:17 T:1093865120 NOTICE: m_deviceName : @
00:00:17 T:1093865120 NOTICE: m_displayName : Default (AML-M1 Analog)
00:00:17 T:1093865120 NOTICE: m_displayNameExtra:
00:00:17 T:1093865120 NOTICE: m_deviceType : AE_DEVTYPE_PCM
00:00:17 T:1093865120 NOTICE: m_channels : FL,FR
00:00:17 T:1093865120 NOTICE: m_sampleRates : 8000,11025,16000,22050,32000,44100,48000,64000,88200,96000
00:00:17 T:1093865120 NOTICE: m_dataFormats : AE_FMT_S16NE,AE_FMT_S16LE
00:00:17 T:1093865120 NOTICE: load settings...
00:00:17 T:1093865120 NOTICE: special://profile/ is mapped to: special://masterprofile/
00:00:17 T:1093865120 NOTICE: Loaded settings file from special://xbmc/system/advancedsettings.xml
00:00:17 T:1093865120 NOTICE: Contents of special://xbmc/system/advancedsettings.xml are...

1
false

lookandfeel.soundskin
videoplayer.rendermethod
videoplayer.adjustrefreshrate
videoplayer.pauseafterrefreshchange
videoplayer.usedisplayasclock
videoplayer.synctype
audiocds
karaoke
videoscreen.screenmode
videoscreen.screen
videoscreen.vsync
videoscreen.testpattern
audiooutput.mode
audiooutput.channellayout
audiooutput.audiodevice
audiooutput.customdevice
audiooutput.passthroughdevice
audiooutput.custompassthrough
input.remoteaskeyboard
audiooutput.guisoundmode


00:00:17 T:1093865120 DEBUG: Configuring hidden settings
00:00:17 T:1093865120 DEBUG: Hiding: [lookandfeel.soundskin]
00:00:17 T:1093865120 DEBUG: Hiding: [videoplayer.rendermethod]
00:00:17 T:1093865120 DEBUG: Hiding: [videoplayer.adjustrefreshrate]
00:00:17 T:1093865120 DEBUG: Hiding: [videoplayer.pauseafterrefreshchange]
00:00:17 T:1093865120 DEBUG: Hiding: [videoplayer.usedisplayasclock]
00:00:17 T:1093865120 DEBUG: Hiding: [videoplayer.synctype]
00:00:17 T:1093865120 DEBUG: Hiding: [audiocds]
00:00:17 T:1093865120 DEBUG: Hiding: [karaoke]
00:00:17 T:1093865120 DEBUG: Hiding: [videoscreen.screenmode]
00:00:17 T:1093865120 DEBUG: Hiding: [videoscreen.screen]
00:00:17 T:1093865120 DEBUG: Hiding: [videoscreen.vsync]
00:00:17 T:1093865120 DEBUG: Hiding: [videoscreen.testpattern]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.mode]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.channellayout]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.audiodevice]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.customdevice]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.passthroughdevice]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.custompassthrough]
00:00:17 T:1093865120 DEBUG: Hiding: [input.remoteaskeyboard]
00:00:17 T:1093865120 DEBUG: Hiding: [audiooutput.guisoundmode]
00:00:17 T:1093865120 NOTICE: Loaded settings file from special://profile/advancedsettings.xml
00:00:17 T:1093865120 NOTICE: Contents of special://profile/advancedsettings.xml are...

0

mysql
10.0.1.18
3306
xbmc
xbmc


mysql
10.0.1.18
3306
xbmc
xbmc




special://masterprofile/favourites.xml
nfs://10.0.1.18/volume1/Media/xbmc/userdata/favourites.xml


special://masterprofile/sources.xml
nfs://10.0.1.18/volume1/Media/xbmc/userdata/sources.xml


special://masterprofile/mediasources.xml
nfs://10.0.1.18/volume1/Media/xbmc/userdata/mediasources.xml



00:00:17 T:1093865120 DEBUG: Configuring path substitutions
00:00:17 T:1093865120 DEBUG: Registering substition pair:
00:00:17 T:1093865120 DEBUG: From: [/root/.xbmc/userdata/favourites.xml]
00:00:17 T:1093865120 DEBUG: To: [nfs://10.0.1.18/volume1/Media/xbmc/userdata/favourites.xml]
00:00:17 T:1093865120 DEBUG: Registering substition pair:
00:00:17 T:1093865120 DEBUG: From: [/root/.xbmc/userdata/sources.xml]
00:00:17 T:1093865120 DEBUG: To: [nfs://10.0.1.18/volume1/Media/xbmc/userdata/sources.xml]
00:00:17 T:1093865120 DEBUG: Registering substition pair:
00:00:17 T:1093865120 DEBUG: From: [/root/.xbmc/userdata/mediasources.xml]
00:00:17 T:1093865120 DEBUG: To: [nfs://10.0.1.18/volume1/Media/xbmc/userdata/mediasources.xml]
00:00:17 T:1093865120 WARNING: VIDEO database configuration is experimental.
00:00:17 T:1093865120 NOTICE: special://profile/ is mapped to: special://masterprofile/
00:00:17 T:1093865120 NOTICE: loading special://masterprofile/guisettings.xml
00:00:17 T:1093865120 NOTICE: Getting hardware information now...
00:00:17 T:1093865120 INFO: Using digital output
00:00:17 T:1093865120 INFO: AC3 pass through is enabled
00:00:17 T:1093865120 INFO: DTS pass through is enabled
00:00:17 T:1093865120 INFO: AAC pass through is disabled
19:00:17 T:1093865120 NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
19:00:17 T:1093865120 DEBUG: CPlayerCoreConfig::: created player DVDPlayer for core 1
19:00:17 T:1093865120 DEBUG: CPlayerCoreConfig::: created player oldmplayercore for core 1
19:00:17 T:1093865120 DEBUG: CPlayerCoreConfig::: created player PAPlayer for core 3
19:00:17 T:1093865120 DEBUG: CPlayerCoreConfig::: created player AMLPlayer for core 4
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: system rules
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: rtv
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: myth/mms
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: lastfm/shout
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: rtsp
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: streams
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: aacp/sdp
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: mp2
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: dvd
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: ifo
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: dvdimage
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: sdp/asf
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: nsv
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: radio
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: rm/rmvb
19:00:17 T:1093865120 DEBUG: CPlayerSelectionRule::Initialize: creating rule: udp
19:00:17 T:1093865120 NOTICE: Loaded playercorefactory configuration
19:00:17 T:1093865120 NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
19:00:17 T:1093865120 NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
19:00:17 T:1093865120 NOTICE: Default DVD Player: dvdplayer
19:00:17 T:1093865120 NOTICE: Default Video Player: dvdplayer
19:00:17 T:1093865120 NOTICE: Default Audio Player: paplayer
19:00:17 T:1093865120 NOTICE: Disabled debug logging due to GUI setting. Level 0.
19:00:17 T:1093865120 NOTICE: Log level changed to 0
19:00:17 T:1093865120 NOTICE: Loading media sources from special://masterprofile/sources.xml
19:00:17 T:1093865120 DEBUG: SECTION:LoadDLL(libnfs.so.1)
19:00:17 T:1093865120 DEBUG: Loading: libnfs.so.1
19:00:17 T:1093865120 DEBUG: NFS: Context for 10.0.1.18/volume1/Media not open - get a new context.
19:00:21 T:1093865120 DEBUG: NFS: Connected to server 10.0.1.18 and export /volume1/Media
19:00:21 T:1093865120 DEBUG: NFS: chunks: r/w 131072/32768
19:00:21 T:1093865120 DEBUG: CNFSFile::Open - opened volume1/Media/xbmc/userdata/sources.xml
19:00:21 T:1093865120 DEBUG: CNFSFile::Close closing file volume1/Media/xbmc/userdata/sources.xml
19:00:21 T:1093865120 INFO: creating subdirectories
19:00:21 T:1093865120 INFO: userdata folder: special://masterprofile/
19:00:21 T:1093865120 INFO: recording folder:
19:00:21 T:1093865120 INFO: screenshots folder:
19:00:21 T:1093865120 INFO: thumbnails folder: special://masterprofile/Thumbnails
19:00:21 T:1093865120 INFO: load language info file: special://xbmc/language/English/langinfo.xml
19:00:21 T:1093865120 DEBUG: trying to set locale to en_US.UTF-8
19:00:21 T:1093865120 INFO: global locale set to en_US.UTF-8
19:00:21 T:1093865120 INFO: load English language file, from path: special://xbmc/language/
19:00:21 T:1093865120 DEBUG: POParser: loaded 2690 strings from file /usr/share/xbmc/language/English/strings.po
19:00:21 T:1093865120 INFO: CSoftAE::InternalOpenSink - sink incompatible, re-starting
19:00:21 T:1093865120 INFO: CAESinkALSA::Initialize - Attempting to open device "default"
19:00:21 T:1093865120 INFO: CAESinkALSA::Initialize - Opened device "default"
19:00:21 T:1093865120 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
19:00:21 T:1093865120 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S16NE
19:00:21 T:1093865120 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 1024, periods 16, bufferSize 16384
19:00:21 T:1093865120 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 1024, periods 16, bufferSize 16384
19:00:21 T:1093865120 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 372 ms
19:00:21 T:1093865120 DEBUG: CSoftAE::InternalOpenSink - ALSA Initialized:
19:00:21 T:1093865120 DEBUG: Output Device : Default (AML-M1 Analog)
19:00:21 T:1093865120 DEBUG: Sample Rate : 44100
19:00:21 T:1093865120 DEBUG: Sample Format : AE_FMT_S16NE
19:00:21 T:1093865120 DEBUG: Channel Count : 2
19:00:21 T:1093865120 DEBUG: Channel Layout: FL,FR
19:00:21 T:1093865120 DEBUG: Frames : 1024
19:00:21 T:1093865120 DEBUG: Frame Samples : 2048
19:00:21 T:1093865120 DEBUG: Frame Size : 4
19:00:21 T:1093865120 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 5.1
19:00:21 T:1093865120 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 8192
19:00:21 T:1104540768 NOTICE: Thread CSoftAE start, auto delete: false
19:00:21 T:1104540768 INFO: CSoftAE::Run - Thread Started
19:00:21 T:1093865120 DEBUG: NetworkManager: PosixNetworkManager created
19:00:23 T:1093865120 DEBUG: NetworkManager: Defaulting to system connection
19:00:23 T:1093865120 DEBUG: NetworkManager: State changed to connected
19:00:23 T:1093865120 DEBUG: NetworkManager: Starting network services
11:54:07 T:1093865120 NOTICE: Webserver: Starting...
11:54:07 T:1093865120 NOTICE: WebServer: Started the webserver
11:54:07 T:1093865120 DEBUG: CZeroconfAvahi::clientCallback: client is up and running
11:54:07 T:1093865120 NOTICE: ES: Starting event server
11:54:07 T:1093865120 INFO: JSONRPC Server: Successfully initialized
11:54:07 T:1093865120 NOTICE: starting zeroconf publishing
11:54:07 T:1093865120 INFO: AIRPLAY Server: Successfully initialized
11:54:07 T:1093865120 DEBUG: SECTION:LoadDLL(libshairport.so.0)
11:54:07 T:1154872416 NOTICE: Thread CEventServer start, auto delete: false
11:54:07 T:1154872416 NOTICE: ES: Starting UDP Event server on 0.0.0.0:9777
11:54:07 T:1154872416 NOTICE: UDP: Listening on port 9777
11:54:07 T:1163261024 NOTICE: Thread CTCPServer start, auto delete: false
11:54:07 T:1171649632 NOTICE: Thread Jobworker start, auto delete: true
11:54:07 T:1180038240 NOTICE: Thread AirPlayServer start, auto delete: false
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.jsonrpc-http type: _xbmc-jsonrpc-h._tcp name:XBMC (Wired) port:80
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::addService() named: XBMC (Wired) type: _xbmc-jsonrpc-h._tcp port:80
11:54:07 T:1093865120 DEBUG: Loading: libshairport.so.0
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.jsonrpc-tpc type: _xbmc-jsonrpc._tcp name:XBMC (Wired) port:9090
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::addService() named: XBMC (Wired) type: _xbmc-jsonrpc._tcp port:9090
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.webserver type: _http._tcp name:XBMC (Wired) port:80
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::addService() named: XBMC (Wired) type: _http._tcp port:80
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.airplay type: _airplay._tcp name:XBMC (Wired) port:36667
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::addService() named: XBMC (Wired) type: _airplay._tcp port:36667
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.eventserver type: _xbmc-events._udp name:XBMC (Wired) port:9777
11:54:07 T:1171649632 DEBUG: CZeroconfAvahi::addService() named: XBMC (Wired) type: _xbmc-events._udp port:9777
11:54:07 T:1093865120 DEBUG: CLastfmScrobbler: Clearing session.
11:54:07 T:1093865120 DEBUG: CLibrefmScrobbler: Clearing session.
11:54:07 T:1196905568 NOTICE: Thread Jobworker start, auto delete: true
11:54:07 T:1196905568 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.airtunes type: _raop._tcp name:000DFE742778@XBMC (Wired) port:36666
11:54:07 T:1188516960 NOTICE: Thread AirTunesServer start, auto delete: false
11:54:07 T:1196905568 DEBUG: CZeroconfAvahi::addService() named: 000DFE742778@XBMC (Wired) type: _raop._tcp port:36666
11:54:07 T:1093865120 NOTICE: Running database version Addons15
11:54:07 T:1093865120 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/libcpluff-arm.so)
11:54:07 T:1093865120 DEBUG: Loading: /usr/lib/xbmc/system/libcpluff-arm.so
11:54:07 T:1146483808 DEBUG: CZeroconfAvahi::groupCallback: Service successfully established
11:54:08 T:1093865120 DEBUG: Previous line repeats 5 times.
11:54:08 T:1093865120 INFO: ADDON: cpluff: 'Could not read plug-in directory /usr/lib/xbmc/addons: No such file or directory'
11:54:08 T:1093865120 INFO: LIRC Initialize: using: /dev/lircd
11:54:08 T:1093865120 INFO: LIRC Initialize: connect failed: No such file or directory
11:54:08 T:1093865120 DEBUG: Failed to connect to LIRC. Retry in 10s.
11:54:08 T:1093865120 DEBUG: LoadMappings - loaded node "Motorola Nyxboard Hybrid"
11:54:08 T:1093865120 DEBUG: LoadMappings - loaded node "Raspberry Pi CEC Adapter"
11:54:08 T:1093865120 DEBUG: LoadMappings - loaded node "Pulse-Eight CEC Adapter"
11:54:08 T:1093865120 DEBUG: LoadMappings - loaded node "iMON HID device"
11:54:08 T:1093865120 DEBUG: CPeripheralBusUSB - initialised udev monitor
11:54:08 T:1093865120 INFO: Found input device /dev/input/event0
11:54:08 T:1093865120 INFO: opened device 'aml_keypad' (file name /dev/input/event0), m_bSkipNonKeyEvents 0
11:54:08 T:1093865120 INFO: Found input device /dev/input/event1
11:54:08 T:1093865120 INFO: opened device 'key_input' (file name /dev/input/event1), m_bSkipNonKeyEvents 0
11:54:08 T:1093865120 INFO: Found input device /dev/input/event2
11:54:08 T:1093865120 INFO: opened device 'Lenovo Multimedia Remote with Keyboard N5902' (file name /dev/input/event2), m_bSkipNonKeyEvents 0
11:54:08 T:1093865120 INFO: CLinuxInputDevice: auto key repeat disabled on device 'Lenovo Multimedia Remote with Keyboard N5902'
11:54:08 T:1093865120 INFO: Found input device /dev/input/event3
11:54:08 T:1093865120 INFO: opened device 'Lenovo Multimedia Remote with Keyboard N5902' (file name /dev/input/event3), m_bSkipNonKeyEvents 0
11:54:08 T:1206908000 NOTICE: Thread XBMC Peripherals start, auto delete: false
11:54:08 T:1093865120 DEBUG: UDisks: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.UDisks was not provided by any .service files
11:54:08 T:1093865120 DEBUG: DeviceKit.Disks: org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.DeviceKit.Disks was not provided by any .service files
11:54:08 T:1093865120 DEBUG: Selected UDev as storage provider
11:54:08 T:1093865120 NOTICE: InitWindowSystem: Using EGL Implementation: amlogic
11:54:08 T:1093865120 NOTICE: Found resolution 1280 x 720 for display 0 with 1280 x 720 @ 60.000000 Hz
11:54:08 T:1093865120 NOTICE: Found resolution 1280 x 720 for display 0 with 1920 x 1080i @ 60.000000 Hz
11:54:08 T:1093865120 NOTICE: Found resolution 1280 x 720 for display 0 with 1920 x 1080 @ 60.000000 Hz
11:54:08 T:1093865120 NOTICE: Checking resolution 18
11:54:08 T:1093865120 DEBUG: CreateWindow: Created surface of size 1280x720
11:54:08 T:1093865120 NOTICE: GL_VENDOR = ARM
11:54:08 T:1093865120 NOTICE: GL_RENDERER = Mali-400 MP
11:54:08 T:1093865120 NOTICE: GL_VERSION = OpenGL ES 2.0
11:54:08 T:1093865120 NOTICE: GL_SHADING_LANGUAGE_VERSION = OpenGL ES GLSL ES 1.00
11:54:08 T:1093865120 DEBUG: GLES: Extension Support Test - GL_NVX_gpu_memory_info NO
11:54:08 T:1093865120 NOTICE: GL_EXTENSIONS = GL_OES_texture_npot GL_OES_compressed_ETC1_RGB8_texture GL_OES_standard_derivatives GL_OES_EGL_image GL_OES_depth24 GL_ARM_rgba8 GL_ARM_mali_shader_binary GL_OES_depth_texture GL_OES_packed_depth_stencil GL_EXT_texture_format_BGRA8888 GL_EXT_blend_minmax GL_OES_EGL_image_external GL_OES_EGL_sync
11:54:08 T:1093865120 DEBUG: GLES: Extension Support Test - GL_EXT_texture_format_BGRA8888 YES
11:54:08 T:1093865120 DEBUG: GLES: Extension Support Test - GL_IMG_texture_format_BGRA8888 NO
11:54:08 T:1093865120 DEBUG: GLES: Extension Support Test - GL_APPLE_texture_format_BGRA8888 NO
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:08 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:08 T:1093865120 DEBUG: GUI Shader [guishader_frag_default.glsl]- Initialise successful : 0x1284d78
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:08 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:08 T:1093865120 DEBUG: GUI Shader [guishader_frag_texture.glsl]- Initialise successful : 0x12cbca8
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:08 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:08 T:1093865120 DEBUG: GUI Shader [guishader_frag_multi.glsl]- Initialise successful : 0x12ceb90
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:08 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GUI Shader [guishader_frag_fonts.glsl]- Initialise successful : 0x12d2188
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GUI Shader [guishader_frag_texture_noblend.glsl]- Initialise successful : 0x12f2110
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GUI Shader [guishader_frag_multi_blendcolor.glsl]- Initialise successful : 0x12ef268
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GUI Shader [guishader_frag_rgba.glsl]- Initialise successful : 0x12f2fe8
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Vertex Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GL: Pixel Shader compilation log:
11:54:09 T:1093865120 DEBUG: GL: Fragment Shader compiled successfully
11:54:09 T:1093865120 DEBUG: GUI Shader [guishader_frag_rgba_blendcolor.glsl]- Initialise successful : 0x12f5218
11:54:09 T:1093865120 DEBUG: CWinSystemEGL::CreateNewWindow: No need to create a new window
11:54:09 T:1093865120 INFO: GLES: Maximum texture width: 4096
11:54:09 T:1093865120 DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
11:54:09 T:1093865120 INFO: load default splash image: /usr/share/xbmc/media/Splash.png
11:54:09 T:1093865120 DEBUG: SECTION:LoadDLL(special://xbmcbin/system/ImageLib-arm.so)
11:54:09 T:1093865120 DEBUG: Loading: /usr/lib/xbmc/system/ImageLib-arm.so
11:54:09 T:1093865120 INFO: load keymapping
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/appcommand.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/gamepad.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.Alienware.Dual.Compatible.Controller.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.AppleRemote.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.Interact.AxisPad.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.Logitech.RumblePad.2.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.360.Controller.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.Controller.S.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.PS3.Remote.Keyboard.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.Sony.PLAYSTATION(R)3.Controller.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/joystick.WiiRemote.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/keyboard.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/mouse.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/nobs.xml
11:54:09 T:1093865120 INFO: Loading special://xbmc/system/keymaps/remote.xml
11:54:10 T:1093865120 INFO: Loading special://masterprofile/keymaps/keyboard.xml
11:54:10 T:1093865120 INFO: Loading special://profile/keymaps/keyboard.xml
11:54:10 T:1093865120 INFO: Loading special://xbmc/system/Lircmap.xml
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'mceusb'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'XboxDVDDongle'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'Microsoft_Xbox'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'PinnacleSysPCTVRemote'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'anysee'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'iMON-PAD'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'Antec_Veris_RM200'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'MCE_via_iMON'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'TwinHanRemote'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'linux-input-layer'
11:54:10 T:1093865120 INFO: * Linking remote mapping for 'linux-input-layer' to 'cx23885_remote'
11:54:10 T:1093865120 INFO: * Linking remote mapping for 'linux-input-layer' to 'devinput'
11:54:10 T:1093865120 INFO: * Adding remote mapping for device 'mediacenter'
11:54:10 T:1093865120 DEBUG: CButtonTranslator::Load - no userdata Lircmap.xml found, skipping
11:54:10 T:1093865120 INFO: GUI format 1280x720, Display 1920x1080 @ 60.00 - Full Screen
11:54:10 T:1093865120 DEBUG: guilib: Fill viewport on change for solving rendering passes
11:54:10 T:1093865120 DEBUG: SECTION:LoadDLL(libcurl.so.4)
11:54:10 T:1093865120 DEBUG: Loading: libcurl.so.4
11:54:10 T:1093865120 NOTICE: Running database version Addons15
11:54:10 T:1093865120 DEBUG: Initialize, updating databases...
11:54:10 T:1093865120 NOTICE: Running database version ViewModes4
11:54:10 T:1093865120 NOTICE: Running database version Textures13
11:54:10 T:1093865120 NOTICE: Running database version MyMusic32
11:54:10 T:1093865120 NOTICE: Running database version MyVideos75
11:54:10 T:1093865120 NOTICE: Running database version TV22
11:54:10 T:1093865120 NOTICE: Running database version Epg7
11:54:10 T:1093865120 DEBUG: Initialize, updating databases... DONE
11:54:10 T:1093865120 NOTICE: start dvd mediatype detection
11:54:10 T:1093865120 NOTICE: initializing playlistplayer
11:54:10 T:1093865120 NOTICE: DONE initializing playlistplayer
11:54:10 T:1093865120 INFO: DPMS: not supported on this platform
11:54:10 T:1225888864 NOTICE: Thread CDetectDVDMedia start, auto delete: false
11:54:10 T:1225888864 DEBUG: Compiled with libcdio Version 0.82
11:54:10 T:1225888864 DEBUG: Thread CDetectDVDMedia 1225888864 terminating
11:54:10 T:1093865120 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
11:54:10 T:1093865120 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
11:54:10 T:1093865120 INFO: Unloading old skin ...
11:54:10 T:1093865120 INFO: load skin from: /usr/share/xbmc/addons/skin.confluence (version: 2.1.3)
11:54:10 T:1093865120 INFO: load fonts for skin...
11:54:10 T:1093865120 INFO: Loading fonts from /usr/share/xbmc/addons/skin.confluence/720p/Font.xml
11:54:10 T:1093865120 DEBUG: POParser: loaded 131 strings from file /usr/share/xbmc/addons/skin.confluence/language/English/strings.po
11:54:10 T:1093865120 INFO: Loading skin includes from /usr/share/xbmc/addons/skin.confluence/720p/includes.xml
11:54:11 T:1093865120 INFO: load new skin...
11:54:11 T:1093865120 INFO: Loading user windows, path /usr/share/xbmc/addons/skin.confluence/720p
11:54:11 T:1093865120 DEBUG: Load Skin XML: 33.80ms
11:54:11 T:1093865120 INFO: initialize new skin...
11:54:11 T:1093865120 DEBUG: guilib: Fill viewport on change for solving rendering passes
11:54:11 T:1093865120 INFO: Loading skin file: Pointer.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load Pointer.xml: 10.65ms
11:54:11 T:1093865120 DEBUG: OpenBundle - Opened bundle /usr/share/xbmc/addons/skin.confluence/media/Textures.xbt
11:54:11 T:1093865120 DEBUG: Alloc resources: 79.44ms (11.02 ms skin load)
11:54:11 T:1093865120 INFO: Loading skin file: DialogVolumeBar.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load DialogVolumeBar.xml: 15.74ms
11:54:11 T:1093865120 DEBUG: Alloc resources: 68.57ms (16.13 ms skin load)
11:54:11 T:1093865120 INFO: Loading skin file: DialogKaiToast.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load DialogKaiToast.xml: 16.18ms
11:54:11 T:1093865120 DEBUG: Alloc resources: 16.62ms (16.61 ms skin load)
11:54:11 T:1093865120 INFO: Loading skin file: DialogMuteBug.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load DialogMuteBug.xml: 7.93ms
11:54:11 T:1093865120 DEBUG: Alloc resources: 8.23ms (8.22 ms skin load)
11:54:11 T:1093865120 INFO: Loading skin file: DialogSeekBar.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load DialogSeekBar.xml: 42.41ms
11:54:11 T:1093865120 DEBUG: Alloc resources: 96.24ms (43.16 ms skin load)
11:54:11 T:1093865120 INFO: Loading skin file: DialogBusy.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load DialogBusy.xml: 9.76ms
11:54:11 T:1093865120 DEBUG: Alloc resources: 10.24ms (10.13 ms skin load)
11:54:11 T:1093865120 INFO: Loading skin file: DialogExtendedProgressBar.xml, load type: LOAD_ON_GUI_INIT
11:54:11 T:1093865120 DEBUG: Load DialogExtendedProgressBar.xml: 10.64ms
11:54:11 T:1093865120 DEBUG: Alloc resources: 11.11ms (11.00 ms skin load)
11:54:11 T:1093865120 INFO: Loading /usr/share/xbmc/addons/skin.confluence/sounds/sounds.xml
11:54:11 T:1093865120 INFO: CAEWAVLoader::Initialize - Sound Loaded: /usr/share/xbmc/addons/skin.confluence/sounds/cursor.wav
11:54:11 T:1093865120 INFO: CAEWAVLoader::Initialize - Sound Loaded: /usr/share/xbmc/addons/skin.confluence/sounds/click.wav
11:54:11 T:1093865120 INFO: CAEWAVLoader::Initialize - Sound Loaded: /usr/share/xbmc/addons/skin.confluence/sounds/back.wav
11:54:11 T:1093865120 DEBUG: AERemap: Downmix normalization is disabled
11:54:11 T:1093865120 INFO: CAEWAVLoader::Initialize - Sound Loaded: /usr/share/xbmc/addons/skin.confluence/sounds/shutter.wav
11:54:11 T:1093865120 INFO: CAEWAVLoader::Initialize - Sound Loaded: /usr/share/xbmc/addons/skin.confluence/sounds/notify.wav
11:54:12 T:1093865120 DEBUG: AERemap: Downmix normalization is disabled
11:54:12 T:1093865120 INFO: CAEWAVLoader::Initialize - Sound Loaded: /usr/share/xbmc/addons/skin.confluence/sounds/out.wav
11:54:12 T:1093865120 DEBUG: AERemap: Downmix normalization is disabled
11:54:12 T:1093865120 INFO: skin loaded...
11:54:12 T:1093865120 INFO: JSONRPC v6.0.0: Successfully initialized
11:54:12 T:1093865120 DEBUG: ADDON: Starting service addons.
11:54:12 T:1093865120 INFO: initializing python engine.
11:54:12 T:1093865120 DEBUG: new python thread created. id=1
11:54:12 T:1248150624 NOTICE: Thread XBPyThread start, auto delete: false
11:54:12 T:1248150624 DEBUG: Python thread: start processing
11:54:12 T:1093865120 INFO: initializing python engine.
11:54:12 T:1093865120 DEBUG: new python thread created. id=2
11:54:12 T:1171649632 NOTICE: PVRManager - starting up
11:54:12 T:1093865120 DEBUG: Activating window ID: 12999
11:54:12 T:1093865120 DEBUG: ------ Window Init (Startup.xml) ------
11:54:12 T:1093865120 INFO: Loading skin file: Startup.xml, load type: LOAD_EVERY_TIME
11:54:12 T:1256539232 NOTICE: Thread XBPyThread start, auto delete: false
11:54:12 T:1256539232 DEBUG: Python thread: start processing
11:54:12 T:1264927840 NOTICE: Thread PVR manager start, auto delete: false
11:54:12 T:1273316448 NOTICE: Thread PVR add-on updater start, auto delete: false
11:54:12 T:1273316448 DEBUG: RegisterClient - registering add-on 'MythTV cmyth PVR Client'
11:54:12 T:1273316448 DEBUG: PVR - Create - creating PVR add-on instance 'MythTV cmyth PVR Client'
11:54:12 T:1273316448 DEBUG: ADDON: Dll Initializing - MythTV cmyth PVR Client
11:54:12 T:1273316448 DEBUG: SECTION:LoadDLL(/usr/lib/xbmc/addons/pvr.mythtv.cmyth/XBMC_MythTV_cmyth.pvr)
11:54:12 T:1273316448 DEBUG: Loading: /usr/lib/xbmc/addons/pvr.mythtv.cmyth/XBMC_MythTV_cmyth.pvr
11:54:12 T:1093865120 DEBUG: Load Startup.xml: 66.57ms
11:54:12 T:1093865120 DEBUG: Alloc resources: 66.93ms (66.91 ms skin load)
11:54:12 T:1093865120 INFO: removing tempfiles
11:54:13 T:1093865120 NOTICE: UpdateLibraries - Starting video library startup scan
11:54:13 T:1281705056 NOTICE: Thread CVideoInfoScanner start, auto delete: false
11:54:13 T:1093865120 DEBUG: ADDON: Starting service addons.
11:54:13 T:1093865120 NOTICE: initialize done
11:54:13 T:1093865120 NOTICE: Running the application...
11:54:13 T:1093865120 DEBUG: ExecuteXBMCAction : Translating ReplaceWindow(Home)
11:54:13 T:1093865120 DEBUG: ExecuteXBMCAction : To ReplaceWindow(Home)
11:54:13 T:1093865120 DEBUG: Activating window ID: 10000
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Creating MythTV cmyth PVR-Client
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Addon compiled with XBMC_PVR_API_VERSION: 1.6.0 and XBMC_PVR_MIN_API_VERSION: 1.6.0
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Register handle @ libXBMC_addon...done
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Checking props...
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Checking props...done
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Register handle @ libXBMC_pvr...
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Register handle @ libXBMC_addon...done
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Register handle @ libXBMC_gui...
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Register handle @ libXBMC_gui...done
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'host'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'port'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'extradebug'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'db_user'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'db_password'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'db_name'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'db_host'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'db_port'
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'livetv'
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Creating PVRClientMythTV...
11:54:13 T:1093865120 DEBUG: ------ Window Init (Pointer.xml) ------
11:54:13 T:1093865120 INFO: GLES: Enabling VSYNC
11:54:13 T:1093865120 ERROR: GLES: Vertical Blank Syncing unsupported
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: Creating PVRClientMythTV...done
11:54:13 T:1273316448 DEBUG: CAddonCallbacksAddon - GetAddonSetting - add-on 'MythTV cmyth PVR Client' requests setting 'livetv_priority'
11:54:13 T:1323557984 DEBUG: AddOnLog: MythTV cmyth PVR Client: Process FileOps Thread Started
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: MythTV cmyth PVR-Client successfully created
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: GetBackendName: MythTV (10.0.1.23)
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: GetConnectionString: 10.0.1.23:6543 - [email protected]:3306
11:54:13 T:1273316448 DEBUG: POParser: loaded 16 strings from file /usr/share/xbmc/addons/pvr.mythtv.cmyth/resources/language/English/strings.po
11:54:13 T:1273316448 DEBUG: AddOnLog: MythTV cmyth PVR Client: GetBackendVersion: Protocol version: 72 - Database version: 1299
11:54:13 T:1264927840 DEBUG: PVRManager - Load - active clients found. continue to start
11:54:13 T:1093865120 DEBUG: ------ Window Deinit (Startup.xml) ------
11:54:13 T:1093865120 DEBUG: ------ Window Init (Home.xml) ------
11:54:13 T:1093865120 INFO: Loading skin file: Home.xml, load type: KEEP_IN_MEMORY
11:54:13 T:1248150624 NOTICE: -->Python Interpreter Initialized<--
11:54:13 T:1248150624 DEBUG: Process - The source file to load is /root/.xbmc/addons/service.skin.widgets/default.py
11:54:13 T:1248150624 DEBUG: Process - Setting the Python path to /root/.xbmc/addons/service.skin.widgets:/root/.xbmc/addons/script.module.cryptopy/lib:/root/.xbmc/addons/script.module.demjson/lib:/usr/share/xbmc/addons/script.module.simplejson/lib:/root/.xbmc/addons/weather.wunderground/resources/lib/wunderground:/root/.xbmc/addons/script.module.beautifulsoup/lib:/usr/share/xbmc/addons/script.module.pil/lib:/root/.xbmc/addons/script.module.free.cable.database/lib:/root/.xbmc/addons/script.module.coveapi/lib:/root/.xbmc/addons/script.module.elementtree/lib:/usr/share/xbmc/addons/script.module.pysqlite/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:
11:54:13 T:1248150624 DEBUG: Process - Entering source directory /root/.xbmc/addons/service.skin.widgets
11:54:14 T:1256539232 NOTICE: -->Python Interpreter Initialized<--
11:54:14 T:1256539232 DEBUG: Process - The source file to load is /root/.xbmc/addons/script.artwork.downloader/service.py
11:54:14 T:1256539232 DEBUG: Process - Setting the Python path to /root/.xbmc/addons/script.artwork.downloader:/root/.xbmc/addons/script.module.cryptopy/lib:/root/.xbmc/addons/script.module.demjson/lib:/usr/share/xbmc/addons/script.module.simplejson/lib:/root/.xbmc/addons/weather.wunderground/resources/lib/wunderground:/root/.xbmc/addons/script.module.beautifulsoup/lib:/usr/share/xbmc/addons/script.module.pil/lib:/root/.xbmc/addons/script.module.free.cable.database/lib:/root/.xbmc/addons/script.module.coveapi/lib:/root/.xbmc/addons/script.module.elementtree/lib:/usr/share/xbmc/addons/script.module.pysqlite/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:
11:54:14 T:1256539232 DEBUG: Process - Entering source directory /root/.xbmc/addons/script.artwork.downloader
11:54:14 T:1248150624 DEBUG: Instantiating addon using automatically obtained id of "service.skin.widgets" dependent on version 2.1.0 of the xbmc.python api
11:54:14 T:1256539232 DEBUG: Instantiating addon using automatically obtained id of "script.artwork.downloader" dependent on version 2.1.0 of the xbmc.python api
11:54:14 T:1093865120 DEBUG: Load Home.xml: 1006.10ms
11:54:15 T:1093865120 DEBUG: Alloc resources: 1363.15ms (1031.25 ms skin load)
11:54:15 T:1196905568 DEBUG: CRecentlyAddedJob::UpdateMusic() - Running RecentlyAdded home screen update
11:54:15 T:1093865120 DEBUG: Process - no profile autoexec.py (/root/.xbmc/userdata/autoexec.py) found, skipping
11:54:15 T:1093865120 DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
11:54:15 T:1093865120 DEBUG: Window DialogExtendedProgressBar.xml was already loaded
11:54:15 T:1093865120 DEBUG: Alloc resources: 0.03m
11:54:15 T:1281705056 NOTICE: VideoInfoScanner: Starting scan ..
11:54:15 T:1281705056 DEBUG: CAnnouncementManager - Announcement: OnScanStarted from xbmc
11:54:15 T:1281705056 DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanStarted
11:54:15 T:1264927840 DEBUG: PVR - Load - loading all radio channel groups
11:54:15 T:1264927840 INFO: PVRChannelGroupInternal - LoadFromDb - no channels in the database
11:54:15 T:1264927840 DEBUG: PVRChannelGroup - Load - 0 channels loaded from the database for group 'All radio channels'
11:54:15 T:1196905568 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
11:54:15 T:1093865120 INFO: Found input device /dev/input/event0
11:54:15 T:1093865120 INFO: opened device 'aml_keypad' (file name /dev/input/event0), m_bSkipNonKeyEvents 0
11:54:15 T:1093865120 INFO: Found input device /dev/input/event1
11:54:15 T:1093865120 INFO: opened device 'key_input' (file name /dev/input/event1), m_bSkipNonKeyEvents 0
11:54:15 T:1093865120 INFO: Found input device /dev/input/event2
11:54:15 T:1093865120 INFO: opened device 'Lenovo Multimedia Remote with Keyboard N5902' (file name /dev/input/event2), m_bSkipNonKeyEvents 0
11:54:15 T:1093865120 INFO: CLinuxInputDevice: auto key repeat disabled on device 'Lenovo Multimedia Remote with Keyboard N5902'
11:54:15 T:1093865120 INFO: Found input device /dev/input/event3
11:54:15 T:1093865120 INFO: opened device 'Lenovo Multimedia Remote with Keyboard N5902' (file name /dev/input/event3), m_bSkipNonKeyEvents 0
11:54:15 T:1264927840 DEBUG: PVR - LoadUserDefinedChannelGroups - 0 user defined radio channel groups fetched from the database
11:54:15 T:1264927840 DEBUG: PVR - LoadUserDefinedChannelGroups - 0 new user defined radio channel groups fetched from clients
11:54:15 T:1264927840 DEBUG: PVR - PersistAll - persisting all changes in channel groups
11:54:15 T:1264927840 DEBUG: PVR - Load - 1 radio channel groups loaded
11:54:15 T:1264927840 DEBUG: PVR - Load - loading all TV channel groups
11:54:15 T:1196905568 DEBUG: GetRecentlyAddedAlbums query: select * from albumview where strAlbum != '' order by idAlbum desc limit 10
11:54:16 T:1264927840 DEBUG: PVRChannelGroup - Load - 63 channels loaded from the database for group 'All TV channels'
11:54:16 T:1093865120 DEBUG: ------ Window Deinit (Pointer.xml) ------
11:54:17 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'WWOR-TV simulcast on WNYW transmitter'.
11:54:17 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'BOUNCE'.
11:54:17 T:1196905568 DEBUG: CRecentlyAddedJob::UpdateVideos() - Running RecentlyAdded home screen update
11:54:17 T:1196905568 DEBUG: RunQuery took 60 ms for 10 items query: select * from movieview ORDER BY dateAdded desc, idMovie desc LIMIT 10
11:54:17 T:1348899936 NOTICE: Thread Jobworker start, auto delete: true
11:54:18 T:1196905568 DEBUG: RunQuery took 29 ms for 10 items query: select * from episodeview ORDER BY dateAdded desc, idEpisode desc LIMIT 10
11:54:18 T:1256539232 DEBUG: LocalizeStrings: no strings.po file exist at /root/.xbmc/addons/script.artwork.downloader/resources/language/English, fallback to strings.xml
11:54:18 T:1093865120 INFO: LIRC Initialize: using: /dev/lircd
11:54:18 T:1093865120 DEBUG: Failed to connect to LIRC. Retry in 20s.
11:54:18 T:1196905568 DEBUG: RunQuery took 26 ms for 0 items query: select * from musicvideoview ORDER BY dateAdded desc, idMVideo desc LIMIT 10
11:54:18 T:1196905568 DEBUG: CRecentlyAddedJob::UpdateTotal() - Running RecentlyAdded home screen update
11:54:19 T:1256539232 NOTICE: Artwork Downloader: ## Service - Run at startup: False
11:54:19 T:1256539232 NOTICE: Artwork Downloader: ## Service - Delayed startup: minutes
11:54:19 T:1256539232 NOTICE: Artwork Downloader: ## Service - Run as service: False
11:54:19 T:1256539232 NOTICE: Artwork Downloader: ## Service - Time: :00
11:54:19 T:1256539232 INFO: Scriptresult: Success
11:54:19 T:1256539232 INFO: Python script stopped
11:54:19 T:1256539232 DEBUG: Thread XBPyThread 1256539232 terminating
11:54:19 T:1093865120 DEBUG: waiting for python thread 2 (/root/.xbmc/addons/script.artwork.downloader/service.py) to stop
11:54:19 T:1093865120 DEBUG: python thread 2 (/root/.xbmc/addons/script.artwork.downloader/service.py) destructed
11:54:19 T:1248150624 DEBUG: Skin Widgets: script version 0.0.19 started
11:54:19 T:1248150624 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x1b03bd0
11:54:20 T:1248150624 DEBUG: Previous line repeats 2 times.
11:54:20 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "VideoLibrary.GetMovies", "params": {"properties": ["title", "playcount", "year", "genre", "studio", "tagline", "plot", "runtime", "file", "plotoutline", "lastplayed", "trailer", "rating", "resume", "art", "streamdetails"], "limits": {"end": 20}, "sort": {"method": "random" }, "filter": {"field": "playcount", "operator": "lessthan", "value": "1"}}}
11:54:20 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.getmovies
11:54:20 T:1248150624 DEBUG: RunQuery took 189 ms for 132 items query: select * from movieview WHERE ((movieview.playCount IS NULL OR movieview.playCount < 1))
11:54:22 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "VideoLibrary.GetEpisodes", "params": { "properties": ["title", "playcount", "season", "episode", "showtitle", "plot", "file", "rating", "resume", "tvshowid", "art", "streamdetails"], "limits": {"end": 20}, "sort": {"method": "random" }, "filter": {"field": "playcount", "operator": "lessthan", "value": "1"}}}
11:54:22 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.getepisodes
11:54:22 T:1248150624 DEBUG: RunQuery took 20 ms for 15 items query: select * from episodeview WHERE ((episodeview.playCount IS NULL OR episodeview.playCount < 1))
11:54:23 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "VideoLibrary.GetMusicVideos", "params": {"properties": ["title", "artist", "playcount", "year", "plot", "genre", "runtime", "fanart", "thumbnail", "file", "streamdetails"], "limits": {"end": 20}, "sort": {"method": "random"}}}
11:54:23 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.getmusicvideos
11:54:23 T:1248150624 DEBUG: RunQuery took 3 ms for 0 items query: select * from musicvideoview
11:54:23 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "AudioLibrary.GetAlbums", "params": {"properties": ["title", "description", "albumlabel", "artist", "genre", "year", "thumbnail", "fanart", "rating", "playcount"], "limits": {"end": 20}, "sort": {"method": "random"}}}
11:54:23 T:1248150624 DEBUG: JSONRPC: Calling audiolibrary.getalbums
11:54:23 T:1248150624 DEBUG: GetAlbumsByWhere query: SELECT albumview.* FROM albumview WHERE albumview.strAlbum <> ''
11:54:23 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'CCTV Sp'.
11:54:23 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'CCTV 4'.
11:54:23 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'CCTV Ne'.
11:54:23 T:1248150624 DEBUG: GetAlbumsByWhere - query took 154 ms
11:54:24 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "method": "AudioLibrary.GetArtists", "params": {"properties": ["genre", "description", "fanart", "thumbnail"], "sort": {"method": "random"}, "limits": {"end": 20}}, "id": 1}
11:54:24 T:1248150624 DEBUG: JSONRPC: Calling audiolibrary.getartists
11:54:24 T:1248150624 DEBUG: GetArtistsByWhere query: SELECT artistview.* FROM artistview WHERE (artistview.idArtist IN (SELECT song_artist.idArtist FROM song_artist) OR artistview.idArtist IN (SELECT album_artist.idArtist FROM album_artist)) and artistview.strArtist != '' and artistview.idArtist <> 1
11:54:24 T:1248150624 DEBUG: Time to retrieve artists from dataset = 226
11:54:24 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "AudioLibrary.GetSongs", "params": {"properties": ["title", "playcount", "artist", "album", "year", "file", "thumbnail", "fanart", "rating"], "filter": {"field": "playcount", "operator": "lessthan", "value": "1"}, "limits": {"end": 20}, "sort": {"method": "random"}}}
11:54:24 T:1248150624 DEBUG: JSONRPC: Calling audiolibrary.getsongs
11:54:24 T:1248150624 DEBUG: GetSongsByWhere query = SELECT songview.* FROM songview WHERE ((CAST(songview.iTimesPlayed as DECIMAL(5,1)) < 1))
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'Channel 1451'.
11:54:25 T:1281705056 DEBUG: VideoInfoScanner: Scanning dir 'nfs://10.0.1.18/volume1/Media/Movies/' as not in the database
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'Antenna'.
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'ThisTV'.
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'NJTV-HD'.
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'LIVWELL'.
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'LivWell'.
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'WNYW simulcast on WWOR-TV transmitter'.
11:54:25 T:1264927840 DEBUG: EPG - Load - no database entries found for table 'Nonstop'.
11:54:25 T:1248150624 DEBUG: GetSongsByWhere() - took 1175 ms
11:54:26 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "method": "Addons.GetAddons", "params": {"properties": ["name", "author", "summary", "version", "fanart", "thumbnail"]}, "id": 1}
11:54:26 T:1248150624 DEBUG: JSONRPC: Calling addons.getaddons
11:54:27 T:1248150624 DEBUG: Skin Widgets: Total time needed to request random queries: 0:00:07.473004
11:54:27 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "VideoLibrary.GetMovies", "params": {"properties": ["title", "playcount", "year", "genre", "studio", "tagline", "plot", "runtime", "file", "plotoutline", "lastplayed", "trailer", "rating", "resume", "art", "streamdetails"], "limits": {"end": 20}, "sort": {"order": "descending", "method": "lastplayed"}, "filter": {"field": "inprogress", "operator": "true", "value": ""}}}
11:54:27 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.getmovies
11:54:27 T:1248150624 DEBUG: RunQuery took 22 ms for 12 items query: select * from movieview WHERE (movieview.idFile IN (select idFile from bookmark where type = 1))
11:54:28 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "method": "VideoLibrary.GetTVShows", "params": {"properties": ["title", "studio", "file", "art"], "sort": {"order": "descending", "method": "lastplayed"}, "filter": {"field": "inprogress", "operator": "true", "value": ""}, "limits": {"end": 20}}, "id": 1}
11:54:28 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.gettvshows
11:54:29 T:1264927840 DEBUG: PVR - Get - group 'All TV channels' loaded from the database
11:54:29 T:1264927840 DEBUG: PVR - LoadUserDefinedChannelGroups - 0 user defined TV channel groups fetched from the database
11:54:29 T:1264927840 DEBUG: PVR - LoadUserDefinedChannelGroups - 0 new user defined TV channel groups fetched from clients
11:54:29 T:1264927840 DEBUG: PVR - PersistAll - persisting all changes in channel groups
11:54:29 T:1264927840 DEBUG: CPVRChannelGroup - Persist - persisting channel group 'All TV channels' with 63 channels
11:54:29 T:1248150624 DEBUG: RunQuery took 52 ms for 0 items query: SELECT * FROM tvshowview WHERE (tvshowview.idShow IN (select tvshowview.idShow from tvshowview where (watchedcount > 0 AND watchedcount < totalCount) OR (watchedcount = 0 AND tvshowview.idShow IN (select episodeview.idShow from episodeview WHERE episodeview.idShow = tvshowview.idShow AND episodeview.resumeTimeInSeconds > 0))))
11:54:29 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "AudioLibrary.GetAlbums", "params": {"properties": ["title", "description", "albumlabel", "artist", "genre", "year", "thumbnail", "fanart", "rating", "playcount"], "limits": {"end": 20}, "sort": {"order": "descending", "method": "playcount" }}}
11:54:29 T:1248150624 DEBUG: JSONRPC: Calling audiolibrary.getalbums
11:54:29 T:1248150624 DEBUG: GetAlbumsByWhere query: SELECT albumview.* FROM albumview WHERE albumview.strAlbum <> ''
11:54:29 T:1248150624 DEBUG: GetAlbumsByWhere - query took 133 ms
11:54:29 T:1093865120 DEBUG: Keyboard: scancode: 6a, sym: 0113, unicode: 0000, modifier: 0
11:54:29 T:1093865120 DEBUG: OnKey: right (f083) pressed, action is Right
11:54:29 T:1264927840 DEBUG: PVR - Load - 1 TV channel groups loaded
11:54:29 T:1264927840 DEBUG: CPVRTimers - Update - updating timers
11:54:29 T:1264927840 DEBUG: PVRTimers - UpdateEntries - added timer 0 on client 1
11:54:29 T:1264927840 DEBUG: PVRTimers - UpdateEntries - added timer 131072 on client 1
11:54:29 T:1264927840 DEBUG: PVRTimers - UpdateEntries - added timer 65536 on client 1
11:54:29 T:1264927840 DEBUG: PVRTimers - UpdateEntries - added timer 1 on client 1
11:54:29 T:1264927840 DEBUG: PVRTimers - UpdateEntries - added timer 131073 on client 1
11:54:29 T:1264927840 DEBUG: CPVRRecordings - Update - updating recordings
11:54:29 T:1256539232 NOTICE: Thread PVR GUI info updater start, auto delete: false
11:54:29 T:1264927840 DEBUG: PVRManager - Process - entering main loop
11:54:29 T:1357288544 NOTICE: Thread EPG updater start, auto delete: false
11:54:29 T:1264927840 NOTICE: Start - EPG thread started
11:54:29 T:1357288544 INFO: EPG - UpdateFromScraper - updating EPG for channel 'CCTV Sp' from client '1'
11:54:30 T:1093865120 DEBUG: Keyboard: scancode: 6a, sym: 0113, unicode: 0000, modifier: 0
11:54:30 T:1093865120 DEBUG: OnKey: right (f083) pressed, action is Right
11:54:30 T:1365677152 NOTICE: Thread Jobworker start, auto delete: true
11:54:30 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "VideoLibrary.GetMusicVideos", "params": {"properties": ["title", "artist", "playcount", "year", "plot", "genre", "runtime", "fanart", "thumbnail", "file", "streamdetails"], "limits": {"end": 20}, "sort": {"order": "descending", "method": "playcount" }}}
11:54:30 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.getmusicvideos
11:54:30 T:1248150624 DEBUG: RunQuery took 12 ms for 0 items query: select * from musicvideoview
11:54:30 T:1248150624 DEBUG: Skin Widgets: Total time needed to request recommended queries: 0:00:02.903158
11:54:30 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "VideoLibrary.GetMovies", "params": {"properties": ["title", "playcount", "year", "genre", "studio", "tagline", "plot", "runtime", "file", "plotoutline", "lastplayed", "trailer", "rating", "resume", "art", "streamdetails"], "limits": {"end": 20}, "sort": {"order": "descending", "method": "dateadded"}, "filter": {"field": "playcount", "operator": "is", "value": "0"}}}
11:54:30 T:1248150624 DEBUG: JSONRPC: Calling videolibrary.getmovies
11:54:30 T:1196905568 DEBUG: DoWork - took 384 ms to load special://masterprofile/Thumbnails/b/bd0a0b53.jpg
11:54:30 T:1171649632 DEBUG: DoWork - took 366 ms to load special://masterprofile/Thumbnails/6/61737d70.jpg
11:54:30 T:1348899936 DEBUG: DoWork - took 410 ms to load special://masterprofile/Thumbnails/8/8465a342.jpg
11:54:30 T:1365677152 DEBUG: DoWork - took 379 ms to load special://masterprofile/Thumbnails/1/163dd568.jpg
11:54:30 T:1248150624 DEBUG: RunQuery took 194 ms for 132 items query: select * from movieview WHERE ((movieview.playCount IS NULL OR movieview.playCount = 0))
11:54:30 T:1093865120 DEBUG: Keyboard: scancode: 6a, sym: 0113, unicode: 0000, modifier: 0
11:54:30 T:1093865120 DEBUG: OnKey: right (f083) pressed, action is Right
11:54:30 T:1196905568 DEBUG: DoWork - took 236 ms to load special://masterprofile/Thumbnails/d/decbf5d5.jpg
11:54:31 T:1348899936 DEBUG: DoWork - took 126 ms to load special://masterprofile/Thumbnails/6/61adf60a.jpg
11:54:31 T:1365677152 DEBUG: DoWork - took 139 ms to load special://masterprofile/Thumbnails/6/64e3e05e.jpg
11:54:32 T:1093865120 DEBUG: Keyboard: scancode: 69, sym: 0114, unicode: 0000, modifier: 0
11:54:32 T:1093865120 DEBUG: OnKey: left (f082) pressed, action is Left
11:54:32 T:1248150624 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id"

@davilla
Copy link
Contributor

davilla commented Jan 6, 2013

was that a freeze, hang, crash or did a magic bunny appear ?

@yang299kms
Copy link
Author

to me it was like the box crashed, my ssh session died and i couldn't get back in. i had to pull the plug to get the bunny to appear =)

@HotBlack77
Copy link

I am getting the same freezing, high pitched tone, no SSH and rainbow pattern. Would you like more logs on this issue. I can't reliably reproduce it, i.e. playing the same file will not crash at the same point or possibly at all.

@josebiro
Copy link
Contributor

I triggered the problem, but no working theory at this point. I managed to produce a mosaic with high pitched squealing by sending a jsonrpc message to the device. I'd sent the same command twice to the device:
{"jsonrpc":"2.0","id":0,"method":"GUI.ShowNotification","params":["Test","Testing 123"]}

The first notification played as expected. The second triggered the magic bunny, which I will now forever use to mean a hard irrecoverable crash with bright colors and loud noises . Some things are just too good to pass up.

My logs don't even the second JSONRPC log entry for the request, the device locked up hard before it could write the log entry. Subsequent tests show that repeatedly sending that command with the same ID number has no effect. I can't trigger it again.

@davilla
Copy link
Contributor

davilla commented Feb 11, 2013

how are you sending the json commands ?

@josebiro
Copy link
Contributor

Telnet to port 9090 copy/paste the command in the crash case. I'd sent probably a half dozen malformed commands to the server prior to the crash case via a test golang based client. In these cases the server was well behaved and dropped the requests as expected (with logs).

@davilla
Copy link
Contributor

davilla commented Feb 11, 2013

davilla@rootcoder:~/shared/json-test$ telnet 192.168.2.62 9090
Trying 192.168.2.62...
Connected to 192.168.2.62.
Escape character is '^]'.
{"jsonrpc":"2.0","id":0,"method":"GUI.ShowNotification","params":["Test","Testing 123"]}
{"id":0,"jsonrpc":"2.0","result":"OK"}
{"jsonrpc":"2.0","id":0,"method":"GUI.ShowNotification","params":["Test","Testing 123"]}
{"id":0,"jsonrpc":"2.0","result":"OK"}

works :)
also a binary that send the same command also works.

Are you telnet'ing from a) linux, b) osx, c) windows ?

@josebiro
Copy link
Contributor

Nope, you're right, I don't have anything conclusive, just a strange coincidence that both sensite's logs and my experience look like an RPC may have triggered the crash. I have some more experiments to run when I get home later.

in all cases, I was telnetting from osx 10.8 - golang client rpcs were sent from a linux box.

@davilla
Copy link
Contributor

davilla commented Feb 11, 2013

https://www.dropbox.com/s/m1fwgvt6utg6enm/json-test.c

build it with gcc -g json-test.c -ljson -o json-test

change the IPs to match yours

@josebiro
Copy link
Contributor

Well, there goes that theory. I've been hammering the box for over 24 hours and it's held up like a champ. Clearly this is not a viable way of triggering the issue, even if it worked, which it does not. Back to the drawing board.

@davilla
Copy link
Contributor

davilla commented Feb 14, 2013

well, I did learn an easy way to send json strings :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants