2013-04-23, 18:32
Hi All,
My setup: Bodhi Linux, Frodo, Ace skin.
Reproducible Steps:
1. Create a new audio smartlist with a genre selected (probably not relevant) and where playcount = 0 (also probably not relevant but....it's what I have)
2. Go to playlist using keyboard only
3. Using keyboard only go to 1st item in playlist
4. Push Enter
Expected: Highlighted song plays
Observed: It looks like the 4th song plays every time, items 1-3 are just skipped
Interesting note: If you push stop, then using keyboard go to homescreen, then go back to playlist and push enter on song #1, it'll start from #1
Appending log even though I doubt it'll be useful
Further info, it's not consistent, I just closed XBMC and did the steps again, and it worked....makes it much harder to triage so if there is additional steps you want me to test, just say
My setup: Bodhi Linux, Frodo, Ace skin.
Reproducible Steps:
1. Create a new audio smartlist with a genre selected (probably not relevant) and where playcount = 0 (also probably not relevant but....it's what I have)
2. Go to playlist using keyboard only
3. Using keyboard only go to 1st item in playlist
4. Push Enter
Expected: Highlighted song plays
Observed: It looks like the 4th song plays every time, items 1-3 are just skipped
Interesting note: If you push stop, then using keyboard go to homescreen, then go back to playlist and push enter on song #1, it'll start from #1
Appending log even though I doubt it'll be useful
Code:
09:26:05 T:140080701515648 NOTICE: -----------------------------------------------------------------------
09:26:05 T:140080701515648 NOTICE: Starting XBMC (12.0 Git:fb595f2), Platform: Linux (Bodhi 2.3.0, 3.2.0-26-generic x86_64). Built on Jan 28 2013
09:26:05 T:140080701515648 NOTICE: special://xbmc/ is mapped to: /usr/share/xbmc
09:26:05 T:140080701515648 NOTICE: special://xbmcbin/ is mapped to: /usr/lib/xbmc
09:26:05 T:140080701515648 NOTICE: special://masterprofile/ is mapped to: /home/joel/.xbmc/userdata
09:26:05 T:140080701515648 NOTICE: special://home/ is mapped to: /home/joel/.xbmc
09:26:05 T:140080701515648 NOTICE: special://temp/ is mapped to: /home/joel/.xbmc/temp
09:26:05 T:140080701515648 NOTICE: The executable running is: /usr/lib/xbmc/xbmc.bin
09:26:05 T:140080701515648 NOTICE: Local hostname: joel-Studio-1737
09:26:05 T:140080701515648 NOTICE: Log File is located: /home/joel/.xbmc/temp/xbmc.log
09:26:05 T:140080701515648 NOTICE: -----------------------------------------------------------------------
09:26:05 T:140080701515648 ERROR: CAESinkOSS::EnumerateDevicesEx - Failed to open mixer: /dev/mixer
09:26:05 T:140080701515648 NOTICE: Enumerated ALSA devices:
09:26:05 T:140080701515648 NOTICE: Device 1
09:26:05 T:140080701515648 NOTICE: m_deviceName : default
09:26:05 T:140080701515648 NOTICE: m_displayName : Playback/recording through the PulseAudio sound server
09:26:05 T:140080701515648 NOTICE: m_displayNameExtra:
09:26:05 T:140080701515648 NOTICE: m_deviceType : AE_DEVTYPE_PCM
09:26:05 T:140080701515648 NOTICE: m_channels : FL,FR,BL,BR,FC,LFE,SL,SR,UNKNOWN1,UNKNOWN2,UNKNOWN3,UNKNOWN4,UNKNOWN5,UNKNOWN6,UNKNOWN7,UNKNOWN8
09:26:05 T:140080701515648 NOTICE: m_sampleRates : 5512,8000,11025,16000,22050,32000,44100,48000,64000,88200,96000,176400,192000
09:26:05 T:140080701515648 NOTICE: m_dataFormats : AE_FMT_FLOAT,AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE,AE_FMT_S16BE,AE_FMT_U8
09:26:05 T:140080701515648 NOTICE: Device 2
09:26:05 T:140080701515648 NOTICE: m_deviceName : hdmi:CARD=Intel,DEV=0
09:26:05 T:140080701515648 NOTICE: m_displayName : HDA Intel
09:26:05 T:140080701515648 NOTICE: m_displayNameExtra: HDMI
09:26:05 T:140080701515648 NOTICE: m_deviceType : AE_DEVTYPE_HDMI
09:26:05 T:140080701515648 NOTICE: m_channels : FL,FR,BL,BR,FC,LFE,SL,SR
09:26:05 T:140080701515648 NOTICE: m_sampleRates : 32000,44100,48000,88200,96000,176400,192000
09:26:05 T:140080701515648 NOTICE: m_dataFormats : AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S16LE
09:26:05 T:140080701515648 NOTICE: load settings...
09:26:05 T:140080701515648 NOTICE: special://profile/ is mapped to: special://masterprofile/
09:26:05 T:140080701515648 NOTICE: loading special://masterprofile/guisettings.xml
09:26:05 T:140080701515648 NOTICE: Getting hardware information now...
09:26:05 T:140080701515648 NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
09:26:05 T:140080701515648 NOTICE: Loaded playercorefactory configuration
09:26:05 T:140080701515648 NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
09:26:05 T:140080701515648 NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
09:26:05 T:140080701515648 NOTICE: No settings file to load (special://xbmc/system/advancedsettings.xml)
09:26:05 T:140080701515648 NOTICE: No settings file to load (special://masterprofile/advancedsettings.xml)
09:26:05 T:140080701515648 NOTICE: Default DVD Player: dvdplayer
09:26:05 T:140080701515648 NOTICE: Default Video Player: dvdplayer
09:26:05 T:140080701515648 NOTICE: Default Audio Player: paplayer
09:26:05 T:140080701515648 NOTICE: Disabled debug logging due to GUI setting. Level 0.
09:26:05 T:140080701515648 NOTICE: Log level changed to 0
09:26:05 T:140080701515648 NOTICE: Loading media sources from special://masterprofile/sources.xml
09:26:05 T:140080430921472 NOTICE: Thread CSoftAE start, auto delete: false
09:26:05 T:140080701515648 ERROR: SetPriority: error Permission denied
09:26:05 T:140080701515648 NOTICE: Running database version Addons15
09:26:06 T:140080418084608 NOTICE: Thread XBMC Peripherals start, auto delete: false
09:26:06 T:140080701515648 NOTICE: Setup SDL
09:26:06 T:140080701515648 NOTICE: Checking resolution 15
09:26:06 T:140080701515648 NOTICE: Using visual 0x22
09:26:06 T:140080701515648 NOTICE: GL_VENDOR = Tungsten Graphics, Inc
09:26:06 T:140080701515648 NOTICE: GL_RENDERER = Mesa DRI Mobile Intel® GM45 Express Chipset
09:26:06 T:140080701515648 NOTICE: GL_VERSION = 2.1 Mesa 8.0.4
09:26:06 T:140080701515648 NOTICE: GL_SHADING_LANGUAGE_VERSION = 1.20
09:26:06 T:140080701515648 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_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_NV_vertex_program 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_ATI_envmap_bumpmap GL_EXT_stencil_two_side GL_EXT_texture_cube_map GL_NV_depth_clamp GL_NV_vertex_program1_1 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_MESA_ycbcr_texture GL_ARB_depth_clamp GL_ARB_fragment_program_shadow GL_ARB_half_float_pixel 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_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_gpu_program_parameters GL_EXT_texture_array GL_EXT_texture_integer GL_EXT_texture_sRGB_decode GL_OES_EGL_image GL_MESA_texture_array GL_ARB_copy_buffer GL_ARB_depth_buffer_float GL_ARB_half_float_vertex GL_ARB_map_buffer_range GL_ARB_texture_rg GL_ARB_texture_swizzle GL_ARB_vertex_array_bgra GL_EXT_separate_shader_objects GL_EXT_texture_swizzle GL_EXT_vertex_array_bgra GL_NV_conditional_render GL_ARB_ES2_compatibility GL_ARB_draw_elements_base_vertex GL_ARB_explicit_attrib_location GL_ARB_fragment_coord_conventions GL_ARB_provoking_vertex GL_ARB_sampler_objects GL_ARB_seamless_cube_map GL_ARB_shader_texture_lod GL_EXT_provoking_vertex GL_EXT_texture_snorm GL_MESA_texture_signed_rgba GL_ARB_robustness
09:26:06 T:140080701515648 NOTICE: Running database version Addons15
09:26:06 T:140080701515648 NOTICE: Running database version ViewModes4
09:26:06 T:140080701515648 NOTICE: Running database version Textures13
09:26:06 T:140080701515648 NOTICE: Running database version MyMusic32
09:26:06 T:140080701515648 NOTICE: Running database version MyVideos75
09:26:06 T:140080701515648 NOTICE: Running database version TV22
09:26:06 T:140080701515648 NOTICE: Running database version Epg7
09:26:06 T:140080701515648 NOTICE: start dvd mediatype detection
09:26:06 T:140080701515648 NOTICE: initializing playlistplayer
09:26:06 T:140080701515648 NOTICE: DONE initializing playlistplayer
09:26:06 T:140080701789952 NOTICE: Thread CDetectDVDMedia start, auto delete: false
09:26:07 T:140080198711040 NOTICE: Thread XBPyThread start, auto delete: false
09:26:07 T:140080701515648 NOTICE: initialize done
09:26:07 T:140080207103744 NOTICE: Thread XBPyThread start, auto delete: false
09:26:07 T:140080701515648 NOTICE: Running the application...
09:26:07 T:140080190318336 NOTICE: Thread XBPyThread start, auto delete: false
09:26:07 T:140080207103744 NOTICE: Previous line repeats 1 times.
09:26:07 T:140080207103744 NOTICE: -->Python Interpreter Initialized<--
09:26:07 T:140080198711040 NOTICE: -->Python Interpreter Initialized<--
09:26:07 T:140080181925632 NOTICE: -->Python Interpreter Initialized<--
09:26:07 T:140080190318336 NOTICE: -->Python Interpreter Initialized<--
09:26:07 T:140080190318336 NOTICE: StorageServer Module loaded RUN
09:26:07 T:140080190318336 NOTICE: StorageClient-2.5.0 Starting server
09:26:07 T:140080190318336 NOTICE: StorageServer-2.5.0 Storage Server starting /home/joel/.xbmc/userdata/addon_data/script.common.plugin.cache/commoncache.db
09:26:07 T:140079687268096 NOTICE: Thread Jobworker start, auto delete: true
09:26:07 T:140080701515648 NOTICE: ES: Starting event server
09:26:07 T:140080701515648 ERROR: JSONRPC Server: Failed to connect to sdpd
09:26:07 T:140079670482688 NOTICE: Thread CTCPServer start, auto delete: false
09:26:07 T:140079678875392 NOTICE: Thread CEventServer start, auto delete: false
09:26:07 T:140079678875392 NOTICE: ES: Starting UDP Event server on 0.0.0.0:9777
09:26:07 T:140079678875392 NOTICE: UDP: Listening on port 9777
09:26:07 T:140080701515648 NOTICE: starting zeroconf publishing
09:26:07 T:140079653697280 NOTICE: Thread Jobworker start, auto delete: true
09:26:08 T:140080198711040 NOTICE: Artwork Downloader: ## Service - Run at startup: False
09:26:08 T:140080198711040 NOTICE: Artwork Downloader: ## Service - Delayed startup: minutes
09:26:08 T:140080198711040 NOTICE: Artwork Downloader: ## Service - Run as service: False
09:26:08 T:140080198711040 NOTICE: Artwork Downloader: ## Service - Time: :00
09:26:08 T:140080198711040 NOTICE: Thread XBPyThread start, auto delete: false
09:26:08 T:140080160683776 NOTICE: Thread CRssReader start, auto delete: false
09:26:08 T:140080198711040 NOTICE: -->Python Interpreter Initialized<--
09:26:16 T:140080160683776 NOTICE: Thread CRssReader start, auto delete: false
09:26:22 T:140080701515648 NOTICE: Previous line repeats 1 times.
09:26:22 T:140080701515648 NOTICE: Log level changed to 2
09:26:22 T:140080701515648 NOTICE: Enabled debug logging due to GUI setting. Level 2.
09:26:22 T:140080701515648 DEBUG: ------ Window Init () ------
09:26:22 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:23 T:140080701515648 DEBUG: Previous line repeats 1 times.
09:26:23 T:140080701515648 DEBUG: Keyboard: scancode: 09, sym: 001b, unicode: 001b, modifier: 1000
09:26:23 T:140080701515648 DEBUG: OnKey: escape (f01b) pressed, action is PreviousMenu
09:26:23 T:140080701515648 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
09:26:23 T:140080701515648 DEBUG: ------ Window Deinit (SettingsCategory.xml) ------
09:26:23 T:140080701515648 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
09:26:23 T:140080701515648 DEBUG: ------ Window Init (Settings.xml) ------
09:26:23 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:24 T:140080701515648 DEBUG: Previous line repeats 1 times.
09:26:24 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:24 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:24 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:24 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:24 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:25 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:25 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:25 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:25 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:25 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:25 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:25 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:25 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:25 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:25 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:25 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:25 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:26 T:140080701515648 DEBUG: Previous line repeats 1 times.
09:26:26 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:26 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:26 T:140080701515648 DEBUG: Keyboard: scancode: 09, sym: 001b, unicode: 001b, modifier: 1000
09:26:26 T:140080701515648 DEBUG: OnKey: escape (f01b) pressed, action is PreviousMenu
09:26:26 T:140080701515648 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
09:26:26 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:27 T:140080701515648 DEBUG: ------ Window Deinit (Settings.xml) ------
09:26:27 T:140080701515648 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
09:26:27 T:140080701515648 DEBUG: ------ Window Init (Home.xml) ------
09:26:27 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:27 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:27 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:28 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:28 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:28 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:28 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:28 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:28 T:140080701515648 DEBUG: Keyboard: scancode: 71, sym: 0114, unicode: 0000, modifier: 1000
09:26:28 T:140080701515648 DEBUG: OnKey: left (f082) pressed, action is Left
09:26:28 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating Skin.SetBool(submode)
09:26:28 T:140080701515648 DEBUG: ExecuteXBMCAction : To Skin.SetBool(submode)
09:26:28 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating ActivateWindow($VAR[Sub_GoTo])
09:26:28 T:140080701515648 DEBUG: ExecuteXBMCAction : To ActivateWindow(5004)
09:26:28 T:140080701515648 DEBUG: Activating window ID: 15004
09:26:28 T:140080701515648 DEBUG: ------ Window Init (CustomSubMusic.xml) ------
09:26:28 T:140080701515648 INFO: Loading skin file: CustomSubMusic.xml, load type: KEEP_IN_MEMORY
09:26:28 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating SetFocus(9100)
09:26:28 T:140080701515648 DEBUG: ExecuteXBMCAction : To SetFocus(9100)
09:26:28 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:29 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:29 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:29 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:29 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:29 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:29 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:29 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:29 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:29 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:29 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:29 T:140080701515648 DEBUG: Keyboard: scancode: 6f, sym: 0111, unicode: 0000, modifier: 1000
09:26:29 T:140080701515648 DEBUG: OnKey: up (f080) pressed, action is Up
09:26:30 T:140080701515648 DEBUG: Keyboard: scancode: 24, sym: 000d, unicode: 000d, modifier: 1000
09:26:30 T:140080701515648 DEBUG: OnKey: return (f00d) pressed, action is Select
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating Close
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : To Close
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating ActivateWindow(musiclibrary,playlists,return)
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : To ActivateWindow(musiclibrary,playlists,return)
09:26:30 T:140080701515648 DEBUG: Activating window ID: 10502
09:26:30 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:30 T:140080701515648 DEBUG: ------ Window Deinit (Home.xml) ------
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating Close
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : To Close
09:26:30 T:140080701515648 DEBUG: ------ Window Deinit (CustomSubMusic.xml) ------
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : Translating Skin.Reset(submode)
09:26:30 T:140080701515648 DEBUG: ExecuteXBMCAction : To Skin.Reset(submode)
09:26:30 T:140080701515648 DEBUG: ------ Window Init (MyMusicNav.xml) ------
09:26:30 T:140080701515648 INFO: Loading skin file: MyMusicNav.xml, load type: KEEP_IN_MEMORY
09:26:30 T:140080701515648 DEBUG: CGUIMediaWindow::GetDirectory (special://musicplaylists/)
09:26:30 T:140080701515648 DEBUG: ParentPath = []
09:26:30 T:140080701515648 DEBUG: CMultiPathDirectory::GetDirectory(multipath://special%3a%2f%2fprofile%2fplaylists%2fmusic/special%3a%2f%2fprofile%2fplaylists%2fmixed/)
09:26:30 T:140080701515648 DEBUG: Getting Directory (special://profile/playlists/music)
09:26:30 T:140080701515648 DEBUG: Getting Directory (special://profile/playlists/mixed)
09:26:30 T:140080701515648 DEBUG: CMultiPathDirectory::MergeItems, items = 4
09:26:30 T:140080701515648 DEBUG: Testing path: [000] special://profile/playlists/mixed/Podcasts.xsp
09:26:30 T:140080701515648 DEBUG: Testing path: [001] special://profile/playlists/music/Podcasts in the Last Week.xsp
09:26:30 T:140080701515648 DEBUG: Testing path: [002] special://profile/playlists/music/Podcasts that Need Deleted.xsp
09:26:30 T:140080701515648 DEBUG: CMultiPathDirectory::MergeItems, items = 4, took 0 ms
09:26:30 T:140080198711040 NOTICE: Thread Background Loader start, auto delete: false
09:26:30 T:140080198711040 DEBUG: Thread Background Loader 140080198711040 terminating
09:26:30 T:140079653697280 DEBUG: GetImageHash - unable to stat url
09:26:31 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:31 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:31 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:31 T:140079687268096 DEBUG: GetImageHash - unable to stat url
09:26:31 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:31 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:31 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:31 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:31 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:31 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:31 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:32 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:32 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:32 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:32 T:140080701515648 DEBUG: Keyboard: scancode: 24, sym: 000d, unicode: 000d, modifier: 1000
09:26:32 T:140080701515648 DEBUG: OnKey: return (f00d) pressed, action is Select
09:26:32 T:140080701515648 DEBUG: CGUIMediaWindow::GetDirectory (special://profile/playlists/music/Unplayed Podcasts.xsp)
09:26:32 T:140080701515648 DEBUG: ParentPath = [special://musicplaylists/]
09:26:32 T:140080701515648 DEBUG: GetSongsByWhere query = SELECT songview.* FROM songview WHERE ((songview.idSong IN (SELECT idSong FROM song_genre, genre WHERE song_genre.idGenre = genre.idGenre AND genre.strGenre LIKE '%Podcast%'))) AND ((CAST(songview.iTimesPlayed as DECIMAL(5,1)) = 0)) AND ((songview.strAlbum NOT LIKE '%Intelligence Squared%'))
09:26:32 T:140080701515648 DEBUG: GetSongsByWhere() - took 61 ms
09:26:32 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:32 T:140080198711040 NOTICE: Thread Background Loader start, auto delete: false
09:26:32 T:140079653697280 DEBUG: GetImageHash - unable to stat url
09:26:32 T:140080198711040 DEBUG: Thread Background Loader 140080198711040 terminating
09:26:33 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:33 T:140080701515648 DEBUG: Keyboard: scancode: 74, sym: 0112, unicode: 0000, modifier: 1000
09:26:33 T:140080701515648 DEBUG: OnKey: down (f081) pressed, action is Down
09:26:33 T:140079687268096 DEBUG: GetImageHash - unable to stat url
09:26:33 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:34 T:140080701515648 DEBUG: Previous line repeats 2 times.
09:26:34 T:140080701515648 DEBUG: Keyboard: scancode: 24, sym: 000d, unicode: 000d, modifier: 1000
09:26:34 T:140080701515648 DEBUG: OnKey: return (f00d) pressed, action is Select
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
09:26:34 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers(musicdb://4/9649.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d)
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/mms/udp
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
09:26:34 T:140080701515648 DEBUG: SECTION:LoadDLL(libmad.so.0)
09:26:34 T:140080701515648 DEBUG: Loading: libmad.so.0
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: adding audiodefaultplayer (3)
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: for video=0, audio=1
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: PAPlayer (3)
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: added 2 players
09:26:34 T:140080701515648 DEBUG: CFileCache::Open - opening <4/9649.mp3> using cache
09:26:34 T:140080701515648 ERROR: Open - failed to open source <musicdb://4/9649.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d>
09:26:34 T:140080701515648 ERROR: MP3Codec: Unable to open file musicdb://4/9649.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d
09:26:34 T:140080701515648 ERROR: CAudioDecoder: Unable to Init Codec while loading file musicdb://4/9649.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d
09:26:34 T:140080701515648 WARNING: PAPlayer::QueueNextFileEx - Failed to create the decoder
09:26:34 T:140080701515648 ERROR: Playlist Player: skipping unplayable item: 0, path [musicdb://4/9649.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d]
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers(musicdb://4/12116.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d)
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/mms/udp
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
09:26:34 T:140080701515648 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: adding audiodefaultplayer (3)
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: for video=0, audio=1
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: PAPlayer (3)
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
09:26:34 T:140080701515648 DEBUG: CPlayerCoreFactory::GetPlayers: added 2 players
09:26:34 T:140080701515648 DEBUG: CFileCache::Open - opening <4/12116.mp3> using cache
09:26:34 T:140080198711040 NOTICE: Thread CFileCache start, auto delete: false
09:26:34 T:140080198711040 DEBUG: Process, request seek on source to 8563042
09:26:34 T:140080701515648 DEBUG: Seek - waiting for position 8628450.
09:26:34 T:140080198711040 DEBUG: Process, request seek on source to 0
09:26:34 T:140080701515648 INFO: AudioDecoder: File is queued
09:26:34 T:140080701515648 INFO: CSoftAE::MakeStream - AE_FMT_S32NE, 44100, FC
09:26:34 T:140080430921472 DEBUG: CSoftAE::Run - Sink restart flagged
09:26:34 T:140080430921472 INFO: CSoftAE::InternalOpenSink - keeping old sink with : AE_FMT_FLOAT, FL,FR, 44100hz
09:26:34 T:140080430921472 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 2.1
09:26:34 T:140080430921472 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 4096
09:26:34 T:140080430921472 DEBUG: AERemap: Downmix normalization is disabled
09:26:34 T:140080430921472 DEBUG: CSoftAEStream::CSoftAEStream - Converting from AE_FMT_S32NE to AE_FMT_FLOAT
09:26:34 T:140080701515648 DEBUG: AudioDecoder::GetReplayGain - Final Replaygain applied: 1.000000, Track/Album Gain 89.000000, Peak 0.000000
09:26:34 T:140080701515648 INFO: PAPlayer::PrepareStream - Ready
09:26:34 T:140079396288256 NOTICE: Thread PAPlayer start, auto delete: false
09:26:34 T:140079396288256 DEBUG: PAPlayer::Process - Playback started
09:26:34 T:140080701515648 DEBUG: CFileCache::Open - opening <4/12301.mp3> using cache
09:26:34 T:140079387895552 NOTICE: Thread CFileCache start, auto delete: false
09:26:34 T:140079387895552 DEBUG: Process, request seek on source to 9350458
09:26:34 T:140080701515648 DEBUG: Seek - waiting for position 9415866.
09:26:34 T:140079387895552 DEBUG: Process, request seek on source to 0
09:26:34 T:140080430921472 DEBUG: CSoftAE::Run - Sink restart flagged
09:26:34 T:140080430921472 INFO: CSoftAE::InternalOpenSink - keeping old sink with : AE_FMT_FLOAT, FL,FR, 44100hz
09:26:34 T:140080430921472 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 2.1
09:26:34 T:140080430921472 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 4096
09:26:34 T:140080701515648 INFO: AudioDecoder: File is queued
09:26:34 T:140080701515648 INFO: CSoftAE::MakeStream - AE_FMT_S32NE, 44100, FC
09:26:34 T:140080430921472 DEBUG: CSoftAE::Run - Sink restart flagged
09:26:34 T:140080430921472 INFO: CSoftAE::InternalOpenSink - keeping old sink with : AE_FMT_FLOAT, FL,FR, 44100hz
09:26:34 T:140080430921472 DEBUG: CSoftAE::InternalOpenSink - Using speaker layout: 2.1
09:26:34 T:140080430921472 DEBUG: CSoftAE::InternalOpenSink - Internal Buffer Size: 4096
09:26:34 T:140080430921472 DEBUG: AERemap: Downmix normalization is disabled
09:26:34 T:140080430921472 DEBUG: CSoftAEStream::CSoftAEStream - Converting from AE_FMT_S32NE to AE_FMT_FLOAT
09:26:34 T:140080701515648 DEBUG: AudioDecoder::GetReplayGain - Final Replaygain applied: 1.000000, Track/Album Gain 89.000000, Peak 0.000000
09:26:35 T:140080701515648 INFO: PAPlayer::PrepareStream - Ready
09:26:35 T:140080701515648 DEBUG: CGUIInfoManager::SetCurrentSong(musicdb://4/12301.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d)
09:26:35 T:140080701515648 DEBUG: Loading additional tag info for file /home/joel/gPodder/Downloads/WNYC_s Brian Lehrer Show/bl040813apod.mp3
09:26:35 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
09:26:35 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
09:26:35 T:140080701515648 DEBUG: CGUIInfoManager::SetCurrentSong(musicdb://4/12301.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d)
09:26:35 T:140080701515648 DEBUG: Loading additional tag info for file /home/joel/gPodder/Downloads/WNYC_s Brian Lehrer Show/bl040813apod.mp3
09:26:35 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
09:26:35 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
09:26:35 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:36 T:140080701515648 DEBUG: SECTION:UnloadDelayed(DLL: libcrystalhd.so.3)
09:26:36 T:140080701515648 DEBUG: Unloading: libcrystalhd.so.3
09:26:36 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:37 T:140080701515648 DEBUG: Previous line repeats 1 times.
09:26:37 T:140080701515648 INFO: LIRC Initialize: using: /dev/lircd
09:26:37 T:140080701515648 DEBUG: Failed to connect to LIRC. Retry in 40s.
09:26:37 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:39 T:140080701515648 DEBUG: Previous line repeats 3 times.
09:26:39 T:140080701515648 DEBUG: CWinEventsSDL::CWinEventsSDL - XKb symbols pc_us_inet(evdev)
09:26:39 T:140080701515648 DEBUG: CWinEventsSDL::CWinEventsSDL - m_bEvdev = 1
09:26:39 T:140080701515648 DEBUG: Keyboard: scancode: ae, sym: 00b2, unicode: 0000, modifier: 1000
09:26:39 T:140080701515648 DEBUG: OnKey: stop (f0bc) pressed, action is Stop
09:26:39 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
09:26:39 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
09:26:39 T:140080198711040 DEBUG: Thread CFileCache 140080198711040 terminating
09:26:39 T:140080701515648 DEBUG: CSoftAEStream::~CSoftAEStream - Destructed
09:26:39 T:140079387895552 DEBUG: Thread CFileCache 140079387895552 terminating
09:26:39 T:140080701515648 DEBUG: CSoftAEStream::~CSoftAEStream - Destructed
09:26:39 T:140079396288256 DEBUG: Thread PAPlayer 140079396288256 terminating
09:26:39 T:140079687268096 DEBUG: DoWork - Saving file state for audio item musicdb://4/12301.mp3?xsp=%7b%22limit%22%3a10%2c%22order%22%3a%7b%22direction%22%3a%22ascending%22%2c%22method%22%3a%22random%22%7d%2c%22rules%22%3a%7b%22and%22%3a%5b%7b%22field%22%3a%22genre%22%2c%22operator%22%3a%22contains%22%2c%22value%22%3a%5b%22Podcast%22%5d%7d%2c%7b%22field%22%3a%22playcount%22%2c%22operator%22%3a%22is%22%2c%22value%22%3a%5b%220%22%5d%7d%2c%7b%22field%22%3a%22album%22%2c%22operator%22%3a%22doesnotcontain%22%2c%22value%22%3a%5b%22Intelligence%20Squared%22%5d%7d%5d%7d%2c%22type%22%3a%22songs%22%7d
09:26:40 T:140080207103744 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "AudioLibrary.GetAlbums", "params": {"properties": ["title", "description", "albumlabel", "theme", "mood", "style", "type", "artist", "genre", "year", "thumbnail", "fanart", "rating", "playcount"], "limits": {"end": 20}, "sort": {"order": "descending", "method": "playcount" }}}
09:26:40 T:140080207103744 DEBUG: JSONRPC: Calling audiolibrary.getalbums
09:26:40 T:140080207103744 DEBUG: GetAlbumsByWhere query: SELECT albumview.* FROM albumview WHERE albumview.strAlbum <> ''
09:26:40 T:140080207103744 DEBUG: GetAlbumsByWhere - query took 20 ms
09:26:40 T:140080207103744 DEBUG: JSONRPC: Incoming request: {"jsonrpc": "2.0", "id": 1, "method": "AudioLibrary.GetAlbums", "params": {"properties": ["title", "description", "albumlabel", "theme", "mood", "style", "type", "artist", "genre", "year", "thumbnail", "fanart", "rating", "playcount"], "limits": {"end": 20}, "sort": {"order": "descending", "method": "dateadded" }}}
09:26:40 T:140080207103744 DEBUG: JSONRPC: Calling audiolibrary.getalbums
09:26:40 T:140080207103744 DEBUG: GetAlbumsByWhere query: SELECT albumview.* FROM albumview WHERE albumview.strAlbum <> ''
09:26:40 T:140080207103744 DEBUG: GetAlbumsByWhere - query took 20 ms
09:26:40 T:140080207103744 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 34
09:26:40 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:41 T:140080701515648 DEBUG: Previous line repeats 1 times.
09:26:41 T:140080701515648 DEBUG: Keyboard: scancode: 25, sym: 0132, unicode: 0000, modifier: 1000
09:26:41 T:140080701515648 DEBUG: OnKey: leftctrl (f0d0) pressed, action is
09:26:41 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:41 T:140080701515648 DEBUG: Keyboard: scancode: 18, sym: 0071, unicode: 0011, modifier: 1040
09:26:41 T:140080701515648 DEBUG: OnKey: ctrl-q (1f051) pressed, action is
09:26:42 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:42 T:140080701515648 DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-x86_64-linux.so)
09:26:42 T:140080701515648 DEBUG: Unloading: ImageLib-x86_64-linux.so
09:26:42 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:42 T:140080701515648 DEBUG: ------ Window Init (Pointer.xml) ------
09:26:43 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:44 T:140080701515648 DEBUG: Previous line repeats 2 times.
09:26:44 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnQuit from xbmc
09:26:44 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 8, from xbmc, message OnQuit
09:26:44 T:140079687268096 DEBUG: Thread Jobworker 140079687268096 terminating (autodelete)
09:26:44 T:140079653697280 DEBUG: Thread Jobworker 140079653697280 terminating (autodelete)
09:26:44 T:140080701515648 NOTICE: Storing total System Uptime
09:26:44 T:140080701515648 NOTICE: Saving settings
09:26:44 T:140080701515648 NOTICE: stop all
09:26:44 T:140080701515648 INFO: stopping PVRManager
09:26:44 T:140080701515648 DEBUG: NetworkMessage - Signaling network services to stop
09:26:44 T:140080701515648 NOTICE: ES: Stopping event server
09:26:44 T:140080701515648 DEBUG: NetworkMessage - Waiting for network services to stop
09:26:44 T:140080701515648 NOTICE: stopping zeroconf publishing
09:26:44 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:45 T:140079678875392 NOTICE: ES: UDP Event server stopped
09:26:45 T:140079670482688 DEBUG: Thread CTCPServer 140079670482688 terminating
09:26:45 T:140080701515648 NOTICE: stop dvd detect media
09:26:45 T:140079678875392 DEBUG: Thread CEventServer 140079678875392 terminating
09:26:45 T:140080701789952 DEBUG: Thread CDetectDVDMedia 140080701789952 terminating
09:26:45 T:140080418084608 DEBUG: Thread XBMC Peripherals 140080418084608 terminating
09:26:45 T:140080701515648 NOTICE: stop sap announcement listener
09:26:45 T:140080701515648 NOTICE: clean cached files!
09:26:45 T:140080701515648 NOTICE: unload skin
09:26:45 T:140080701515648 INFO: Unloading old skin ...
09:26:45 T:140080701515648 DEBUG: ------ Window Deinit () ------
09:26:45 T:140080701515648 DEBUG: ------ Window Deinit (Pointer.xml) ------
09:26:45 T:140080701515648 DEBUG: ------ Window Deinit (MyMusicNav.xml) ------
09:26:45 T:140080701515648 DEBUG: Cleanup - Closed bundle
09:26:45 T:140080701515648 DEBUG: ADDON: Stopping service addons.
09:26:45 T:140080701515648 INFO: Stopping script with id: 1
09:26:45 T:140080207103744 DEBUG: NEWADDON PythonCallbackHandler construction with PyThreadState 0x7f66e4000920
09:26:50 T:140080701515648 ERROR: XBPyThread::stop - script /home/joel/.xbmc/addons/service.skin.widgets/default.py didn't stop in 5 seconds - let's kill it
09:26:50 T:140080701515648 INFO: Stopping script with id: 3
09:26:50 T:140080190318336 NOTICE: StorageServer-2.5.0 Closed down
09:26:50 T:140080190318336 INFO: Scriptresult: Success
09:26:50 T:140080701515648 DEBUG: XBPyThread::stop - script termination took 403ms
09:26:50 T:140080701515648 NOTICE: stop python
09:26:50 T:140080701515648 DEBUG: waiting for python thread 1 (/home/joel/.xbmc/addons/service.skin.widgets/default.py) to stop
09:26:50 T:140080190318336 DEBUG: Thread XBPyThread 140080190318336 terminating
09:26:50 T:140080207103744 DEBUG: Skin Widgets: script version 0.0.25 stopped
09:26:50 T:140080207103744 INFO: Scriptresult: Success
09:26:50 T:140080207103744 WARNING: The python script "/home/joel/.xbmc/addons/service.skin.widgets/default.py" has left several classes in memory that we couldn't clean up. The classes include: Monitor,Player,Window
09:26:50 T:140080207103744 DEBUG: Thread XBPyThread 140080207103744 terminating
09:26:50 T:140080701515648 DEBUG: python thread 1 (/home/joel/.xbmc/addons/service.skin.widgets/default.py) destructed
09:26:50 T:140080701515648 DEBUG: waiting for python thread 3 (/home/joel/.xbmc/addons/script.common.plugin.cache/default.py) to stop
09:26:50 T:140080701515648 DEBUG: python thread 3 (/home/joel/.xbmc/addons/script.common.plugin.cache/default.py) destructed
09:26:51 T:140080181925632 DEBUG: script.tv.show.next.aired: ### xbmc is closing, stop script
09:26:51 T:140080181925632 INFO: Scriptresult: Success
09:26:51 T:140080701515648 DEBUG: XBPyThread::stop - script termination took 641ms
09:26:51 T:140080701515648 DEBUG: waiting for python thread 4 (/home/joel/.xbmc/addons/script.tv.show.next.aired/default.py) to stop
09:26:51 T:140080701515648 DEBUG: python thread 4 (/home/joel/.xbmc/addons/script.tv.show.next.aired/default.py) destructed
09:26:51 T:140080181925632 DEBUG: Thread XBPyThread 140080181925632 terminating
09:26:51 T:140080430921472 DEBUG: Thread CSoftAE 140080430921472 terminating
09:26:51 T:140080701515648 NOTICE: stopped
09:26:51 T:140080701515648 NOTICE: destroy
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x342c800 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33bb8c0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x34fcf10 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x341fc10 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33ec790 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x34050d0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x34f4620 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x34404a0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33f2ae0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33a5ce0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x34337f0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33e8230 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33bb1b0 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 INFO: ADDON: cpluff: 'An unreleased information object was encountered at address 0x33bad70 with reference count 1 when destroying the associated plug-in context. Not releasing the object.'
09:26:51 T:140080701515648 NOTICE: closing down remote control service
09:26:51 T:140080701515648 NOTICE: unload sections
09:26:51 T:140080701515648 INFO: lastfm destroyed
09:26:51 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:51 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:51 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:51 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:51 T:140080701515648 DEBUG: object 0 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 1 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 2 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 3 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 4 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 5 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 6 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 7 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 8 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 9 --> 0 instances
09:26:51 T:140080701515648 NOTICE: destroy
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10013 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10014 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10015 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10016 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10017 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10018 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10019 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10021 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10107 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10115 from the window manager when it didn't exist
09:26:51 T:140080701515648 WARNING: Attempted to remove window 10104 from the window manager when it didn't exist
09:26:51 T:140080701515648 NOTICE: closing down remote control service
09:26:51 T:140080701515648 NOTICE: unload sections
09:26:51 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:51 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:51 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:51 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:51 T:140080701515648 DEBUG: object 0 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 1 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 2 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 3 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 4 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 5 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 6 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 7 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 8 --> 0 instances
09:26:51 T:140080701515648 DEBUG: object 9 --> 0 instances
09:26:51 T:140080701515648 NOTICE: application stopped...
09:26:51 T:140080701515648 DEBUG: PVRManager - destroyed
09:26:51 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:51 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:51 T:140080701515648 DEBUG: CAnnouncementManager - Announcement: OnClear from xbmc
09:26:51 T:140080701515648 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnClear
09:26:51 T:140080701515648 DEBUG: SECTION:UnloadDll(libcurl-gnutls.so.4)
09:26:51 T:140080701515648 DEBUG: Unloading: libcurl-gnutls.so.4
09:26:51 T:140080701515648 DEBUG: SECTION:UnloadAll(DLL: special://xbmcbin/system/libcpluff-x86_64-linux.so)
09:26:51 T:140080701515648 DEBUG: Unloading: libcpluff-x86_64-linux.so
09:26:51 T:140080701515648 DEBUG: SECTION:UnloadAll(DLL: libmad.so.0)
09:26:51 T:140080701515648 DEBUG: Unloading: libmad.so.0Further info, it's not consistent, I just closed XBMC and did the steps again, and it worked....makes it much harder to triage so if there is additional steps you want me to test, just say
