rendered paste body18:47:53 T:3030153104 M:3366924288 ERROR: Failed to create common scripts symlink.
18:47:53 T:3030153104 M:3366670336 NOTICE: -----------------------------------------------------------------------
18:47:53 T:3030153104 M:3366670336 NOTICE: Starting XBMC, Platform: GNU/Linux. Built on Dec 24 2009 (SVN:26018)
18:47:53 T:3030153104 M:3366670336 NOTICE: special://xbmc/ is mapped to: /usr/share/xbmc
18:47:53 T:3030153104 M:3366670336 NOTICE: special://masterprofile/ is mapped to: /home/chris/.xbmc/userdata
18:47:53 T:3030153104 M:3366670336 NOTICE: special://home/ is mapped to: /home/chris/.xbmc
18:47:53 T:3030153104 M:3366670336 NOTICE: special://temp/ is mapped to: /home/chris/.xbmc/temp
18:47:53 T:3030153104 M:3366670336 NOTICE: The executable running is: /usr/lib/xbmc/xbmc.bin
18:47:53 T:3030153104 M:3366670336 NOTICE: Log File is located: /home/chris/.xbmc/temp/xbmc.log
18:47:53 T:3030153104 M:3366670336 NOTICE: -----------------------------------------------------------------------
18:47:53 T:3030153104 M:3365675008 NOTICE: Setup SDL
18:47:54 T:3030153104 M:3364663296 NOTICE: load settings...
18:47:54 T:3030153104 M:3364663296 NOTICE: special://profile/ is mapped to: special://masterprofile/
18:47:54 T:3030153104 M:3364663296 NOTICE: loading special://masterprofile/guisettings.xml
18:47:54 T:3030153104 M:3364655104 NOTICE: Getting hardware information now...
18:47:54 T:3030153104 M:3364655104 NOTICE: Checking resolution 11
18:47:54 T:3030153104 M:3364687872 NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
18:47:54 T:3030153104 M:3364589568 NOTICE: Loaded playercorefactory configuration
18:47:54 T:3030153104 M:3364589568 NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
18:47:54 T:3030153104 M:3364589568 NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
18:47:54 T:3030153104 M:3364589568 NOTICE: No advancedsettings.xml to load (special://masterprofile/advancedsettings.xml)
18:47:54 T:3030153104 M:3364589568 NOTICE: Default DVD Player: dvdplayer
18:47:54 T:3030153104 M:3364589568 NOTICE: Default Video Player: dvdplayer
18:47:54 T:3030153104 M:3364589568 NOTICE: Default Audio Player: paplayer
18:47:54 T:3030153104 M:3364589568 NOTICE: Enabled debug logging due to GUI setting (2)
18:47:54 T:3030153104 M:3364589568 NOTICE: special://masterprofile/sources.xml
18:47:54 T:3030153104 M:3364601856 INFO: XRANDR: /usr/share/xbmc/xbmc-xrandr --output default --mode 0x146
18:47:54 T:3030153104 M:3360264192 NOTICE: Using fbConfig[0]
18:47:54 T:3030153104 M:3359756288 INFO: GL: Maximum texture width: 8192
18:47:54 T:3030153104 M:3359756288 DEBUG: Loading: /usr/share/xbmc/system/ImageLib-i486-linux.so
18:47:54 T:3030153104 M:3359096832 DEBUG: GLX_EXTENSIONS: GLX_EXT_visual_info GLX_EXT_visual_rating GLX_SGIX_fbconfig GLX_SGIX_pbuffer GLX_SGI_video_sync GLX_SGI_swap_control GLX_EXT_texture_from_pixmap GLX_ARB_create_context GLX_ARB_create_context_profile GLX_ARB_multisample GLX_NV_float_buffer GLX_ARB_fbconfig_float GLX_EXT_framebuffer_sRGB GLX_ARB_get_proc_address
18:47:54 T:3030153104 M:3359096832 NOTICE: GL_VENDOR = NVIDIA Corporation
18:47:54 T:3030153104 M:3359096832 NOTICE: GL_RENDERER = GeForce 8200/PCI/SSE2/3DNOW!
18:47:54 T:3030153104 M:3359096832 NOTICE: GL_VERSION = 3.2.0 NVIDIA 190.53
18:47:54 T:3030153104 M:3359096832 NOTICE: GL_EXTENSIONS = GL_ARB_color_buffer_float GL_ARB_compatibility GL_ARB_copy_buffer GL_ARB_depth_buffer_float GL_ARB_depth_clamp GL_ARB_depth_texture GL_ARB_draw_buffers GL_ARB_draw_elements_base_vertex GL_ARB_draw_instanced GL_ARB_fragment_coord_conventions GL_ARB_fragment_program GL_ARB_fragment_program_shadow GL_ARB_fragment_shader GL_ARB_framebuffer_object GL_ARB_framebuffer_sRGB GL_ARB_geometry_shader4 GL_ARB_half_float_pixel GL_ARB_half_float_vertex GL_ARB_imaging GL_ARB_map_buffer_range GL_ARB_multisample GL_ARB_multitexture GL_ARB_occlusion_query GL_ARB_pixel_buffer_object GL_ARB_point_parameters GL_ARB_point_sprite GL_ARB_provoking_vertex GL_ARB_seamless_cube_map GL_ARB_shader_objects GL_ARB_shading_language_100 GL_ARB_shadow GL_ARB_sync GL_ARB_texture_border_clamp GL_ARB_texture_buffer_object GL_ARB_texture_compression GL_ARB_texture_compression_rgtc GL_ARB_texture_cube_map GL_ARB_texture_env_add GL_ARB_texture_env_combine GL_ARB_texture_env_crossbar GL_ARB_texture_env_dot3 GL_ARB_texture_float GL_ARB_texture_mirrored_repeat GL_ARB_texture_multisample GL_ARB_texture_non_power_of_two GL_ARB_texture_rectangle GL_ARB_texture_rg GL_ARB_transpose_matrix GL_ARB_uniform_buffer_object GL_ARB_vertex_array_bgra GL_ARB_vertex_array_object GL_ARB_vertex_buffer_object GL_ARB_vertex_program GL_ARB_vertex_shader GL_ARB_window_pos GL_ATI_draw_buffers GL_ATI_texture_float GL_ATI_texture_mirror_once GL_S3_s3tc GL_EXT_texture_env_add GL_EXT_abgr GL_EXT_bgra GL_EXT_bindable_uniform GL_EXT_blend_color GL_EXT_blend_equation_separate GL_EXT_blend_func_separate GL_EXT_blend_minmax GL_EXT_blend_subtract GL_EXT_compiled_vertex_array GL_EXT_Cg_shader GL_EXT_depth_bounds_test GL_EXT_direct_state_access GL_EXT_draw_buffers2 GL_EXT_draw_instanced GL_EXT_draw_range_elements GL_EXT_fog_coord GL_EXT_framebuffer_blit GL_EXT_framebuffer_multisample GL_EXTX_framebuffer_mixed_formats GL_EXT_framebuffer_object GL_EXT_framebuffer_sRGB GL_EXT_geometry_shader4 GL_EXT_gpu_program_parameters GL_EXT_gpu_shader4 GL_EXT_multi_draw_arrays GL_EXT_packed_depth_stencil GL_EXT_packed_float GL_EXT_packed_pixels GL_EXT_pixel_buffer_object GL_EXT_point_parameters GL_EXT_provoking_vertex GL_EXT_rescale_normal GL_EXT_secondary_color GL_EXT_separate_shader_objects GL_EXT_separate_specular_color GL_EXT_shadow_funcs GL_EXT_stencil_two_side GL_EXT_stencil_wrap GL_EXT_texture3D GL_EXT_texture_array GL_EXT_texture_buffer_object GL_EXT_texture_compression_latc GL_EXT_texture_compression_rgtc GL_EXT_texture_compression_s3tc GL_EXT_texture_cube_map GL_EXT_texture_edge_clamp GL_EXT_texture_env_combine GL_EXT_texture_env_dot3 GL_EXT_texture_filter_anisotropic GL_EXT_texture_integer GL_EXT_texture_lod GL_EXT_texture_lod_bias GL_EXT_texture_mirror_clamp GL_EXT_texture_object GL_EXT_texture_shared_exponent GL_EXT_texture_sRGB GL_EXT_texture_swizzle GL_EXT_timer_query GL_EXT_transform_feedback2 GL_EXT_vertex_array GL_EXT_vertex_array_bgra GL_IBM_rasterpos_clip GL_IBM_texture_mirrored_repeat GL_KTX_buffer_region GL_NV_blend_square GL_NV_conditional_render GL_NV_copy_depth_to_color GL_NV_copy_image GL_NV_depth_buffer_float GL_NV_depth_clamp GL_NV_explicit_multisample GL_NV_fence GL_NV_float_buffer GL_NV_fog_distance GL_NV_fragment_program GL_NV_fragment_program_option GL_NV_fragment_program2 GL_NV_framebuffer_multisample_coverage GL_NV_geometry_shader4 GL_NV_gpu_program4 GL_NV_half_float GL_NV_light_max_exponent GL_NV_multisample_coverage GL_NV_multisample_filter_hint GL_NV_occlusion_query GL_NV_packed_depth_stencil GL_NV_parameter_buffer_object GL_NV_parameter_buffer_object2 GL_NV_pixel_data_range GL_NV_point_sprite GL_NV_primitive_restart GL_NV_register_combiners GL_NV_register_combiners2 GL_NV_shader_buffer_load GL_NV_texgen_reflection GL_NV_texture_barrier GL_NV_texture_compression_vtc GL_NV_texture_env_combine4 GL_NV_texture_expand_normal GL_NV_texture_rectangle GL_NV_texture_shader GL_NV_texture_shader2 GL_NV_texture_shader3 GL_NV_transform_feedback GL_NV_transform_feedback2 GL_NV_vertex_array_range GL_NV_vertex_array_range2 GL_NV_vertex_buffer_unified_memory GL_NV_vertex_program GL_NV_vertex_program1_1 GL_NV_vertex_program2 GL_NV_vertex_program2_option GL_NV_vertex_program3 GL_NVX_conditional_render GL_SGIS_generate_mipmap GL_SGIS_texture_lod GL_SGIX_depth_texture GL_SGIX_shadow GL_SUN_slice_accum
18:47:54 T:3030153104 M:3359096832 INFO: GL: Maximum texture width: 8192
18:47:54 T:3030153104 M:3359096832 INFO: load language info file: special://xbmc/language/English/langinfo.xml
18:47:54 T:3030153104 M:3356958720 INFO: load language file:special://xbmc/language/English/strings.xml
18:47:54 T:3030153104 M:3357110272 INFO: load keymapping
18:47:54 T:3030153104 M:3357134848 INFO: Loading special://xbmc/system/keymaps/gamepad.xml
18:47:54 T:3030153104 M:3357134848 INFO: Loading special://xbmc/system/keymaps/joystick.AppleRemote.xml
18:47:54 T:3030153104 M:3357134848 INFO: Loading special://xbmc/system/keymaps/joystick.Harmony.xml
18:47:54 T:3030153104 M:3357134848 INFO: Loading special://xbmc/system/keymaps/joystick.Logitech.RumblePad.2.xml
18:47:54 T:3030153104 M:3357134848 INFO: Loading special://xbmc/system/keymaps/joystick.Microsoft.Xbox.Controller.S.xml
18:47:54 T:3030153104 M:3357007872 INFO: Loading special://xbmc/system/keymaps/joystick.Sony.PLAYSTATION(R)3.Controller.xml
18:47:54 T:3030153104 M:3357007872 INFO: Loading special://xbmc/system/keymaps/joystick.WiiRemote.xml
18:47:54 T:3030153104 M:3357159424 INFO: Loading special://xbmc/system/keymaps/keyboard.xml
18:47:54 T:3030153104 M:3357159424 INFO: Loading special://xbmc/system/keymaps/remote.xml
18:47:54 T:3030153104 M:3357159424 INFO: Loading special://xbmc/system/Lircmap.xml
18:47:54 T:3030153104 M:3357159424 DEBUG: CButtonTranslator::Load - no userdata Lircmap.xml found, skipping
18:47:54 T:3030153104 M:3357159424 INFO: Checking skin version of: PM3.HD
18:47:54 T:3030153104 M:3357159424 INFO: Skin version is: 2.11 (2.110000)
18:47:54 T:3030153104 M:3357159424 INFO: GUI format 1920x1009 Windowed
18:47:54 T:3030153104 M:3357159424 DEBUG: Selected DeviceKit.Disks as storage provider
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DaemonVersion 7
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: Querying available devices
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks with interface org.freedesktop.DeviceKit.Disks and method EnumerateDevices
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded (/org/freedesktop/DeviceKit/Disks/devices/sda3)
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda3 with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda3 with interface org.freedesktop.DBus.Properties and method GetAll
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded - DeviceUDI /org/freedesktop/DeviceKit/Disks/devices/sda3: HasFileSystem ext4 IsMounted true IsRemovable false IsPartition true
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded (/org/freedesktop/DeviceKit/Disks/devices/sr0)
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sr0 with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded - DeviceUDI /org/freedesktop/DeviceKit/Disks/devices/sr0: HasFileSystem IsMounted false IsRemovable false IsPartition false
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded (/org/freedesktop/DeviceKit/Disks/devices/sda)
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded - DeviceUDI /org/freedesktop/DeviceKit/Disks/devices/sda: HasFileSystem IsMounted false IsRemovable false IsPartition false
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded (/org/freedesktop/DeviceKit/Disks/devices/sda5)
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda5 with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda5 with interface org.freedesktop.DBus.Properties and method GetAll
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded - DeviceUDI /org/freedesktop/DeviceKit/Disks/devices/sda5: HasFileSystem swap IsMounted false IsRemovable false IsPartition true
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded (/org/freedesktop/DeviceKit/Disks/devices/sda1)
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda1 with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda1 with interface org.freedesktop.DBus.Properties and method GetAll
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded - DeviceUDI /org/freedesktop/DeviceKit/Disks/devices/sda1: HasFileSystem ext4 IsMounted true IsRemovable false IsPartition true
18:47:54 T:3030153104 M:3357159424 NOTICE: DeviceKit.Disks: Added /media/hd
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded (/org/freedesktop/DeviceKit/Disks/devices/sda2)
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda2 with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda2 with interface org.freedesktop.DBus.Properties and method GetAll
18:47:54 T:3030153104 M:3357159424 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks/devices/sda with interface org.freedesktop.DBus.Properties and method Get
18:47:54 T:3030153104 M:3357159424 DEBUG: DeviceKit.Disks: DeviceAdded - DeviceUDI /org/freedesktop/DeviceKit/Disks/devices/sda2: HasFileSystem IsMounted false IsRemovable false IsPartition true
18:47:54 T:3030153104 M:3357159424 INFO: creating subdirectories
18:47:54 T:3030153104 M:3357159424 INFO: userdata folder: special://masterprofile/
18:47:54 T:3030153104 M:3357159424 INFO: recording folder:
18:47:54 T:3030153104 M:3357159424 INFO: screenshots folder:
18:47:54 T:3030153104 M:3357065216 INFO: thumbnails folder: special://masterprofile/Thumbnails
18:47:54 T:3030153104 M:3357065216 NOTICE: start dvd mediatype detection
18:47:54 T:3027942256 M:3357065216 DEBUG: thread start, auto delete: 0
18:47:54 T:3027942256 M:3357065216 DEBUG: Compiled with libcdio Version 0.78
18:47:54 T:3030153104 M:3357065216 NOTICE: initializing playlistplayer
18:47:54 T:3030153104 M:3357065216 NOTICE: DONE initializing playlistplayer
18:47:54 T:3027942256 M:3357065216 DEBUG: Drive closed media present, remounting...
18:47:54 T:3027942256 M:3357065216 INFO: Detecting DVD-ROM media filesystem...
18:47:54 T:3027942256 M:3357065216 INFO: CD Analysis Report
18:47:54 T:3027942256 M:3357065216 INFO: __________________________________
18:47:54 T:3027942256 M:3357065216 INFO: CD-ROM with ISO 9660 filesystem
18:47:54 T:3027942256 M:3357065216 INFO: ISO 9660: 1151849 blocks, label `'
18:47:54 T:3027942256 M:3357065216 INFO: Tracks overall:1; Audio tracks:0; Data tracks:1
18:47:54 T:3030153104 M:3357032448 DEBUG: DPMS: supported power-saving modes: SUSPEND OFF STANDBY
18:47:54 T:3030153104 M:3357032448 NOTICE: load default skin:[PM3.HD]
18:47:54 T:3030153104 M:3357032448 INFO: load skin from:special://xbmc/skin/PM3.HD
18:47:54 T:3030153104 M:3357032448 INFO: delete old skin...
18:47:54 T:3030153104 M:3357032448 DEBUG: ------ Window Deinit (Pointer.xml) ------
18:47:54 T:3030153104 M:3357032448 DEBUG: ------ Window Deinit (DialogMuteBug.xml) ------
18:47:54 T:3030153104 M:3357032448 INFO: Default 4:3 resolution directory is special://xbmc/skin/PM3.HD/720p
18:47:54 T:3030153104 M:3357032448 INFO: Default 16:9 resolution directory is special://xbmc/skin/PM3.HD/720p
18:47:54 T:3030153104 M:3357032448 INFO: Skin version is: 2.11
18:47:54 T:3030153104 M:3356905472 INFO: Loading skin includes from /usr/share/xbmc/skin/PM3.HD/720p/includes.xml
18:47:54 T:3030153104 M:3355660288 INFO: load fonts for skin...
18:47:54 T:3027942256 M:3355660288 INFO: Using protocol iso9660://
18:47:54 T:3027942256 M:3355660288 INFO: Disc label:
18:47:54 T:3027942256 M:3355660288 DEBUG: SetNewDVDShareUrl: looking for disc thumb:[iso9660://folder.jpg]
18:47:54 T:3027942256 M:3355660288 DEBUG: SetNewDVDShareUrl: looking for disc thumb:[iso9660://Folder.jpg]
18:47:54 T:3027942256 M:3355660288 DEBUG: SetNewDVDShareUrl: looking for disc thumb:[iso9660://folder.JPG]
18:47:54 T:3027942256 M:3355660288 DEBUG: SetNewDVDShareUrl: looking for disc thumb:[iso9660://Folder.JPG]
18:47:54 T:3030153104 M:3355811840 INFO: Loading fonts from special://xbmc/skin/PM3.HD/720p/Font.xml
18:47:55 T:3030153104 M:3353956352 INFO: load new skin...
18:47:55 T:3030153104 M:3353956352 INFO: Skin version is: 2.11 (2.110000)
18:47:55 T:3030153104 M:3353956352 INFO: Loading skin file: Home.xml
18:47:55 T:3030153104 M:3353853952 DEBUG: Load Home.xml: 95.25ms
18:47:55 T:3030153104 M:3353853952 INFO: Loading user windows, path special://xbmc/skin/PM3.HD/720p
18:47:55 T:3030153104 M:3353853952 INFO: Loading skin file: special://xbmc/skin/PM3.HD/720p/custom_SkinSetting_1111.xml
18:47:55 T:3030153104 M:3353878528 INFO: Loading skin file: special://xbmc/skin/PM3.HD/720p/custom_Credits_1112.xml
18:47:55 T:3030153104 M:3353878528 INFO: Loading user windows, path special://xbmc/skin/PM3.HD/720p
18:47:55 T:3030153104 M:3353878528 INFO: Loading skin file: special://xbmc/skin/PM3.HD/720p/custom_SkinSetting_1111.xml
18:47:55 T:3030153104 M:3353878528 INFO: Loading skin file: special://xbmc/skin/PM3.HD/720p/custom_Credits_1112.xml
18:47:55 T:3030153104 M:3353878528 INFO: Loading user windows, path special://xbmc/skin/PM3.HD/720p
18:47:55 T:3030153104 M:3353878528 INFO: Loading skin file: special://xbmc/skin/PM3.HD/720p/custom_SkinSetting_1111.xml
18:47:55 T:3030153104 M:3353878528 INFO: Loading skin file: special://xbmc/skin/PM3.HD/720p/custom_Credits_1112.xml
18:47:55 T:3030153104 M:3353878528 DEBUG: Load Skin XML: 123.03ms
18:47:55 T:3030153104 M:3353878528 INFO: initialize new skin...
18:47:55 T:3030153104 M:3353878528 INFO: Loading skin file: Pointer.xml
18:47:55 T:3030153104 M:3353878528 DEBUG: Load Pointer.xml: 9.03ms
18:47:55 T:3030153104 M:3353800704 DEBUG: Alloc resources: 136.74ms (9.15 ms skin load)
18:47:55 T:3030153104 M:3353800704 INFO: Loading skin file: DialogVolumeBar.xml
18:47:55 T:3030153104 M:3353800704 DEBUG: Load DialogVolumeBar.xml: 1.94ms
18:47:55 T:3030153104 M:3353800704 DEBUG: Alloc resources: 38.50ms (2.07 ms skin load)
18:47:55 T:3030153104 M:3353800704 INFO: Loading skin file: DialogSeekBar.xml
18:47:55 T:3030153104 M:3353800704 DEBUG: Load DialogSeekBar.xml: 4.84ms
18:47:55 T:3030153104 M:3353800704 DEBUG: Alloc resources: 22.98ms (5.03 ms skin load)
18:47:55 T:3030153104 M:3353800704 INFO: Loading skin file: DialogKaiToast.xml
18:47:55 T:3030153104 M:3353800704 DEBUG: Load DialogKaiToast.xml: 0.95ms
18:47:55 T:3030153104 M:3353800704 DEBUG: Alloc resources: 1.04ms (1.04 ms skin load)
18:47:55 T:3030153104 M:3353800704 INFO: Loading skin file: DialogMuteBug.xml
18:47:55 T:3030153104 M:3353800704 DEBUG: Load DialogMuteBug.xml: 0.78ms
18:47:55 T:3030153104 M:3353800704 DEBUG: Alloc resources: 0.86ms (0.86 ms skin load)
18:47:55 T:3030153104 M:3353800704 INFO: skin loaded...
18:47:55 T:3030153104 M:3353698304 DEBUG: Loading: libcurl.so.4
18:47:55 T:3030153104 M:3353624576 DEBUG: Activating window ID: 12999
18:47:55 T:3030153104 M:3353624576 DEBUG: Checking if window ID 12999 is locked.
18:47:55 T:3030153104 M:3353624576 DEBUG: ------ Window Init (Startup.xml) ------
18:47:55 T:3030153104 M:3353624576 INFO: Loading skin file: Startup.xml
18:47:55 T:3030153104 M:3353624576 DEBUG: Load Startup.xml: 0.80ms
18:47:55 T:3030153104 M:3353624576 DEBUG: Alloc resources: 0.88ms (0.87 ms skin load)
18:47:55 T:3030153104 M:3353624576 INFO: removing tempfiles
18:47:55 T:3030153104 M:3353624576 DEBUG: DBus: Creating message to org.freedesktop.ConsoleKit on /org/freedesktop/ConsoleKit/Manager with interface org.freedesktop.ConsoleKit.Manager and method CanStop
18:47:55 T:3030153104 M:3353481216 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Disks on /org/freedesktop/DeviceKit/Disks with interface org.freedesktop.DeviceKit.Disks and method EnumerateDevices
18:47:55 T:3030153104 M:3353481216 DEBUG: DBus: Creating message to org.freedesktop.ConsoleKit on /org/freedesktop/ConsoleKit/Manager with interface org.freedesktop.ConsoleKit.Manager and method CanStop
18:47:55 T:3030153104 M:3353481216 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Power on /org/freedesktop/DeviceKit/Power with interface org.freedesktop.DBus.Properties and method Get
18:47:55 T:3030153104 M:3353632768 DEBUG: DBus: Creating message to org.freedesktop.DeviceKit.Power on /org/freedesktop/DeviceKit/Power with interface org.freedesktop.DBus.Properties and method Get
18:47:55 T:3030153104 M:3353632768 DEBUG: DBus: Creating message to org.freedesktop.ConsoleKit on /org/freedesktop/ConsoleKit/Manager with interface org.freedesktop.ConsoleKit.Manager and method CanRestart
18:47:55 T:3030153104 M:3353632768 NOTICE: initialize done
18:47:55 T:3030153104 M:3353632768 NOTICE: Running the application...
18:47:55 T:3030153104 M:3353632768 DEBUG: ExecuteXBMCAction : Translating ReplaceWindow(Home)
18:47:55 T:3030153104 M:3353632768 DEBUG: ExecuteXBMCAction : To ReplaceWindow(Home)
18:47:55 T:3030153104 M:3353632768 DEBUG: Activating window ID: 10000
18:47:55 T:3030153104 M:3353632768 DEBUG: Checking if window ID 10000 is locked.
18:47:55 T:3030153104 M:3353632768 DEBUG: ------ Window Deinit (Startup.xml) ------
18:47:55 T:3030153104 M:3353632768 DEBUG: ------ Window Init (Home.xml) ------
18:47:55 T:3030153104 M:3353300992 DEBUG: Alloc resources: 15.22ms (0.00 ms skin load)
18:47:55 T:3030153104 M:3353300992 DEBUG: Process - no user autoexec.py (/home/chris/.xbmc/scripts/autoexec.py) found, skipping
18:47:55 T:3030153104 M:3353300992 DEBUG: Process - no system autoexec.py (/usr/share/xbmc/scripts/autoexec.py) found, skipping
18:47:55 T:3030153104 M:3353300992 DEBUG: NetworkMessage - Starting network services
18:47:55 T:3030153104 M:3353300992 NOTICE: ES: Starting event server
18:47:55 T:3018578800 M:3353300992 DEBUG: thread start, auto delete: 0
18:47:55 T:3018578800 M:3353300992 NOTICE: ES: Starting UDP Event server on 127.0.0.1:9777
18:47:55 T:3030153104 M:3353300992 NOTICE: DS: Starting dbus server
18:47:55 T:3018578800 M:3353300992 NOTICE: UDP: Listening on port 9777
18:47:55 T:3010186096 M:3353452544 DEBUG: thread start, auto delete: 0
18:47:55 T:3010186096 M:3353452544 NOTICE: DS: Starting DBUS server in Run Application aka thread
18:47:55 T:3030153104 M:3353452544 NOTICE: starting zeroconf publishing
18:47:55 T:3018578800 M:3353325568 DEBUG: CZeroconfAvahi::clientCallback: client is up and running
18:47:55 T:3030153104 M:3353325568 DEBUG: CZeroconfAvahi::doPublishService identifier: servers.eventserver type: _xbmc-events._udp name:XBMC Event Server port:9777
18:47:55 T:3030153104 M:3353325568 DEBUG: CZeroconfAvahi::addService() named: XBMC Event Server type: _xbmc-events._udp port:9777
18:47:55 T:3030153104 M:3353329664 DEBUG: CLastfmScrobbler: Clearing session.
18:47:55 T:3030153104 M:3353329664 DEBUG: CLibrefmScrobbler: Clearing session.
18:47:55 T:2993400688 M:3353329664 DEBUG: thread start, auto delete: 1
18:47:55 T:2993400688 M:3344756736 DEBUG: DoWork - took 118 ms to load special://skin/backgrounds/videos.jpg
18:47:56 T:3027872624 M:3342000128 DEBUG: thread start, auto delete: 0
18:47:56 T:2993400688 M:3343142912 INFO: WEATHER: Downloading weather
18:47:56 T:2993400688 M:3343142912 DEBUG: FileCurl::Open(0xb26b9100) http://xoap.weather.com/weather/local/USNY0996?cc=*&unit=m&dayf=4&prod=xoap&link=xoap&par=1004124588&key=079f24145f208494
18:47:56 T:2993400688 M:3343294464 INFO: easy_aquire - Created session to http://xoap.weather.com
18:47:56 T:3027872624 M:3341643776 DEBUG: FileCurl::Open(0xb4799120) http://feeds.feedburner.com/xbmc
18:47:56 T:3027872624 M:3341643776 INFO: easy_aquire - Created session to http://feeds.feedburner.com
18:47:56 T:2993400688 M:3342913536 DEBUG: FileCurl::Close(0xb26b9100) http://xoap.weather.com/weather/local/USNY0996?cc=*&unit=m&dayf=4&prod=xoap&link=xoap&par=1004124588&key=079f24145f208494
18:47:56 T:2993400688 M:3342913536 INFO: WEATHER: Weather download successful
18:47:56 T:3027872624 M:3338997760 DEBUG: FileCurl::Close(0xb4799120) http://feeds.feedburner.com/xbmc
18:47:56 T:3027872624 M:3338997760 DEBUG: Got rss feed: http://feeds.feedburner.com/xbmc
18:47:56 T:3027872624 M:3338997760 DEBUG: RSS feed encoding: ISO-8859-1
18:47:56 T:3027872624 M:3338997760 DEBUG: Parsed rss feed: http://feeds.feedburner.com/xbmc
18:47:56 T:3001793392 M:3342692352 DEBUG: CZeroconfAvahi::groupCallback: Service successfully established
18:47:57 T:3027872624 M:3342692352 DEBUG: Thread 3027872624 terminating
18:47:59 T:3030153104 M:3342573568 DEBUG: SDLKeyboard: scancode: 51, sym: 92, unicode: 92, modifier: 0
18:47:59 T:3030153104 M:3342573568 DEBUG: OnKey: 61676 pressed, action is 199
18:47:59 T:3030153104 M:3342573568 ERROR: GLX: Same window as before, refreshing context
18:47:59 T:3030153104 M:3342573568 INFO: GL: Maximum texture width: 8192
18:48:01 T:3030153104 M:3343192064 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:48:01 T:3030153104 M:3343192064 DEBUG: OnKey: 61478 pressed, action is 3
18:48:01 T:2972621680 M:3342098432 DEBUG: thread start, auto delete: 1
18:48:01 T:2972621680 M:3342098432 INFO: easy_aquire - Created session to http://www.google.com
18:48:01 T:2993400688 M:3339431936 DEBUG: DoWork - took 186 ms to load special://skin/backgrounds/settings.jpg
18:48:01 T:2972621680 M:3339558912 DEBUG: FileCurl::Close(0xb12e80a0) http://www.google.com/
18:48:01 T:3030153104 M:3339702272 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:48:01 T:3030153104 M:3339702272 DEBUG: OnKey: 61453 pressed, action is 7
18:48:01 T:3030153104 M:3339702272 DEBUG: ExecuteXBMCAction : Translating ActivateWindow(Settings)
18:48:01 T:3030153104 M:3339702272 DEBUG: ExecuteXBMCAction : To ActivateWindow(Settings)
18:48:01 T:3030153104 M:3339702272 DEBUG: Activating window ID: 10004
18:48:01 T:3030153104 M:3339702272 DEBUG: Checking if window ID 10004 is locked.
18:48:01 T:3030153104 M:3339702272 DEBUG: ------ Window Deinit (Home.xml) ------
18:48:02 T:3030153104 M:3339702272 DEBUG: ------ Window Init (Settings.xml) ------
18:48:02 T:3030153104 M:3339702272 INFO: Loading skin file: Settings.xml
18:48:02 T:3030153104 M:3339550720 DEBUG: Load Settings.xml: 61.36ms
18:48:02 T:3030153104 M:3339321344 DEBUG: Alloc resources: 158.57ms (61.64 ms skin load)
18:48:03 T:3030153104 M:3338555392 DEBUG: SDLKeyboard: scancode: 116, sym: 274, unicode: 0, modifier: 0
18:48:03 T:3030153104 M:3338555392 DEBUG: OnKey: 61480 pressed, action is 4
18:48:04 T:3030153104 M:3338555392 DEBUG: SDLKeyboard: scancode: 114, sym: 275, unicode: 0, modifier: 0
18:48:04 T:3030153104 M:3338555392 DEBUG: OnKey: 61479 pressed, action is 2
18:48:04 T:3030153104 M:3338555392 DEBUG: SDLKeyboard: scancode: 114, sym: 275, unicode: 0, modifier: 0
18:48:04 T:3030153104 M:3338555392 DEBUG: OnKey: 61479 pressed, action is 2
18:48:04 T:3030153104 M:3338555392 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:48:04 T:3030153104 M:3338555392 DEBUG: OnKey: 61453 pressed, action is 7
18:48:04 T:3030153104 M:3338555392 DEBUG: ExecuteXBMCAction : Translating ActivateWindow(SystemSettings)
18:48:04 T:3030153104 M:3338555392 DEBUG: ExecuteXBMCAction : To ActivateWindow(SystemSettings)
18:48:04 T:3030153104 M:3338555392 DEBUG: Activating window ID: 10016
18:48:04 T:3030153104 M:3338555392 DEBUG: Checking if window ID 10016 is locked.
18:48:04 T:3030153104 M:3338555392 DEBUG: ------ Window Deinit (Settings.xml) ------
18:48:04 T:3030153104 M:3338440704 DEBUG: ------ Window Init (SettingsCategory.xml) ------
18:48:04 T:3030153104 M:3338440704 INFO: Loading skin file: SettingsCategory.xml
18:48:04 T:3030153104 M:3338416128 DEBUG: Load SettingsCategory.xml: 4.95ms
18:48:04 T:3030153104 M:3338440704 DEBUG: Alloc resources: 33.73ms (5.12 ms skin load)
18:48:05 T:3030153104 M:3342012416 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:48:05 T:3030153104 M:3342012416 DEBUG: OnKey: 61478 pressed, action is 3
18:48:05 T:3030153104 M:3343790080 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:48:05 T:3030153104 M:3343790080 DEBUG: OnKey: 61478 pressed, action is 3
18:48:06 T:3030153104 M:3342139392 DEBUG: SDLKeyboard: scancode: 114, sym: 275, unicode: 0, modifier: 0
18:48:06 T:3030153104 M:3342139392 DEBUG: OnKey: 61479 pressed, action is 2
18:48:06 T:3030153104 M:3343663104 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:48:06 T:3030153104 M:3343663104 DEBUG: OnKey: 61453 pressed, action is 7
18:48:06 T:3030153104 M:3343663104 NOTICE: Disabled debug logging due to GUI setting. Level 0.
18:48:13 T:3030153104 M:3338588160 NOTICE: DVDPlayer: Opening: dvd://1
18:48:13 T:3030153104 M:3338588160 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:48:13 T:2954189680 M:3338461184 NOTICE: Creating InputStream
18:48:14 T:2954189680 M:3338899456 NOTICE: DVDPlayer: playing a dvd with menu's
18:48:14 T:2954189680 M:3338899456 NOTICE: Creating Demuxer
18:48:14 T:2954189680 M:3335266304 NOTICE: Opening audio stream: 0 source: 512
18:48:14 T:2954189680 M:3335266304 NOTICE: Opening Subtitle stream: 0 source: 512
18:48:14 T:2954189680 M:3335266304 WARNING: Process - Could not detect frame rate for: /dev/cdrom. Using default of 25.000 fps for conversion of any commercial break frame markers to times.
18:48:14 T:2954189680 M:3335315456 WARNING: CDVDMessageQueue(audio)::Put MSGQ_NOT_INITIALIZED
18:48:14 T:2954189680 M:3335315456 WARNING: CDVDMessageQueue(video)::Put MSGQ_NOT_INITIALIZED
18:48:14 T:2954189680 M:3335315456 WARNING: CDVDMessageQueue(teletext)::Put MSGQ_NOT_INITIALIZED
18:48:14 T:2954189680 M:3335299072 NOTICE: Opening Subtitle stream: 1 source: 256
18:48:14 T:2954189680 M:3334905856 NOTICE: Opening video stream: 0 source: 256
18:48:14 T:2954189680 M:3334905856 NOTICE: Creating video codec with codec id: 2
18:48:14 T:2954189680 M:3334803456 NOTICE: Creating video thread
18:48:14 T:2954189680 M:3334803456 NOTICE: Opening audio stream: 2 source: 256
18:48:14 T:2954189680 M:3334803456 NOTICE: Finding audio codec for: 86020
18:48:14 T:2954189680 M:3334803456 NOTICE: Creating audio thread
18:48:14 T:2937510768 M:3334803456 NOTICE: running thread: CDVDPlayerAudio::Process()
18:48:14 T:2937510768 M:3334434816 NOTICE: Creating audio device with codec id: 86020, channels: 2, sample rate: 48000, pass-through
18:48:14 T:2962582384 M:3333750784 NOTICE: running thread: video_thread
18:48:14 T:2962582384 M:3332100096 NOTICE: fps: 25.000000, pwidth: 720, pheight: 480, dwidth: 656, dheight: 480
18:48:14 T:2962582384 M:3332100096 NOTICE: Display resolution DESKTOP : 1920x1080 @ 50.00 - Full Screen (12)
18:48:15 T:3030153104 M:3327717376 NOTICE: Using GL_TEXTURE_2D
18:48:15 T:3030153104 M:3327238144 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:48:15 T:3030153104 M:3326324736 NOTICE: GL: NPOT texture support detected
18:48:22 T:2954189680 M:3318001664 WARNING: CDVDMessageQueue(teletext)::Put MSGQ_NOT_INITIALIZED
18:48:22 T:2954189680 M:3328720896 NOTICE: Opening audio stream: 1 source: 256
18:48:38 T:2954189680 M:3325624320 ERROR: Error getting next block: Error reading from DVD.
18:48:38 T:2954189680 M:3325624320 NOTICE: CDVDPlayer::OnExit()
18:48:38 T:2954189680 M:3325624320 NOTICE: DVDPlayer: eof, waiting for queues to empty
18:48:38 T:2954189680 M:3325624320 NOTICE: DVDPlayer: closing audio stream
18:48:38 T:2954189680 M:3325624320 NOTICE: Closing audio stream
18:48:38 T:2954189680 M:3325624320 NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
18:48:52 T:2937510768 M:3329781760 WARNING: CDVDMessageQueue(audio)::Get - retrieved last data packet of queue
18:48:52 T:2954189680 M:3329273856 NOTICE: Waiting for audio thread to exit
18:48:52 T:2937510768 M:3329273856 NOTICE: thread end: CDVDPlayerAudio::OnExit()
18:48:52 T:2954189680 M:3329273856 NOTICE: Closing audio device
18:48:52 T:2954189680 M:3329273856 NOTICE: Deleting audio codec
18:48:52 T:2954189680 M:3329273856 NOTICE: DVDPlayer: closing video stream
18:48:52 T:2954189680 M:3329273856 NOTICE: Closing video stream
18:48:52 T:2954189680 M:3329273856 NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
18:48:52 T:2962582384 M:3329273856 WARNING: CDVDMessageQueue(video)::Get - retrieved last data packet of queue
18:48:52 T:2954189680 M:3329273856 NOTICE: waiting for video thread to exit
18:48:52 T:2962582384 M:3329273856 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
18:48:52 T:2962582384 M:3329273856 NOTICE: thread end: video_thread
18:48:52 T:2954189680 M:3329273856 NOTICE: deleting video codec
18:48:52 T:2954189680 M:3329273856 NOTICE: DVDPlayer: closing video stream
18:48:52 T:2954189680 M:3329273856 NOTICE: Closing subtitle stream
18:48:52 T:2954189680 M:3329273856 NOTICE: CDVDPlayer::OnExit() deleting demuxer
18:48:52 T:2954189680 M:3329273856 NOTICE: CDVDPlayer::OnExit() deleting input stream
18:48:52 T:3030153104 M:3326496768 NOTICE: CDVDPlayer::CloseFile()
18:48:52 T:3030153104 M:3326496768 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:48:52 T:3030153104 M:3326496768 NOTICE: DVDPlayer: waiting for threads to exit
18:48:52 T:3030153104 M:3326496768 NOTICE: DVDPlayer: finished waiting
18:49:29 T:3030153104 M:3331182592 ERROR: PulseAudio: Waited for the Context but it failed
18:49:29 T:3030153104 M:3331182592 ERROR: PulseAudio: Failed to create context
18:49:29 T:3030153104 M:3331182592 ERROR: PulseAudio: Waited for the Context but it failed
18:49:29 T:3030153104 M:3331182592 ERROR: PulseAudio: Failed to create context
18:49:30 T:3030153104 M:3330920448 NOTICE: Enabled debug logging due to GUI setting. Level 2.
18:49:33 T:3030153104 M:3330039808 DEBUG: SDLKeyboard: scancode: 9, sym: 27, unicode: 27, modifier: 0
18:49:33 T:3030153104 M:3330039808 DEBUG: OnKey: 61467 pressed, action is 10
18:49:33 T:3030153104 M:3330039808 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
18:49:33 T:3030153104 M:3330039808 DEBUG: ------ Window Deinit (SettingsCategory.xml) ------
18:49:33 T:3030153104 M:3330039808 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
18:49:33 T:3030153104 M:3330039808 DEBUG: ------ Window Init (Settings.xml) ------
18:49:33 T:3030153104 M:3330039808 INFO: Loading skin file: Settings.xml
18:49:33 T:3030153104 M:3330039808 DEBUG: Load Settings.xml: 7.08ms
18:49:33 T:3030153104 M:3330039808 DEBUG: Alloc resources: 8.91ms (7.51 ms skin load)
18:49:35 T:3030153104 M:3326103552 DEBUG: SDLKeyboard: scancode: 9, sym: 27, unicode: 27, modifier: 0
18:49:35 T:3030153104 M:3326103552 DEBUG: OnKey: 61467 pressed, action is 10
18:49:35 T:3030153104 M:3326103552 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
18:49:35 T:3030153104 M:3326103552 DEBUG: ------ Window Deinit (Settings.xml) ------
18:49:35 T:3030153104 M:3326103552 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
18:49:35 T:3030153104 M:3326103552 DEBUG: ------ Window Init (Home.xml) ------
18:49:35 T:3030153104 M:3326103552 INFO: Loading skin file: Home.xml
18:49:35 T:3030153104 M:3326103552 DEBUG: Load Home.xml: 8.42ms
18:49:35 T:3030153104 M:3326103552 DEBUG: Alloc resources: 9.57ms (8.72 ms skin load)
18:49:35 T:2962582384 M:3326103552 DEBUG: Loading: /usr/share/xbmc/system/ImageLib-i486-linux.so
18:49:35 T:2962582384 M:3327504384 DEBUG: DoWork - took 115 ms to load special://skin/backgrounds/settings.jpg
18:49:36 T:3030153104 M:3326615552 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:49:36 T:3030153104 M:3326615552 DEBUG: OnKey: 61478 pressed, action is 3
18:49:36 T:2962582384 M:3324530688 DEBUG: DoWork - took 132 ms to load special://skin/backgrounds/scripts.jpg
18:49:36 T:3030153104 M:3324657664 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:49:36 T:3030153104 M:3324657664 DEBUG: OnKey: 61478 pressed, action is 3
18:49:37 T:3030153104 M:3321659392 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:49:37 T:3030153104 M:3321659392 DEBUG: OnKey: 61478 pressed, action is 3
18:49:37 T:2993400688 M:3321659392 DEBUG: thread start, auto delete: 1
18:49:37 T:2962582384 M:3322421248 DEBUG: DoWork - took 162 ms to load special://skin/backgrounds/weather.jpg
18:49:37 T:2993400688 M:3321962496 DEBUG: DoWork - took 121 ms to load special://skin/backgrounds/pictures.jpg
18:49:37 T:3030153104 M:3321962496 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:49:37 T:3030153104 M:3321962496 DEBUG: OnKey: 61478 pressed, action is 3
18:49:37 T:2962582384 M:3319726080 DEBUG: DoWork - took 129 ms to load special://skin/backgrounds/music.jpg
18:49:37 T:3030153104 M:3319791616 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:49:37 T:3030153104 M:3319791616 DEBUG: OnKey: 61478 pressed, action is 3
18:49:37 T:2993400688 M:3317727232 DEBUG: DoWork - took 103 ms to load special://skin/backgrounds/videos.jpg
18:49:37 T:3030153104 M:3317727232 DEBUG: SDLKeyboard: scancode: 111, sym: 273, unicode: 0, modifier: 0
18:49:37 T:3030153104 M:3317727232 DEBUG: OnKey: 61478 pressed, action is 3
18:49:38 T:2962582384 M:3318235136 DEBUG: FileCurl::Close(0xb09550a0) http://www.google.com/
18:49:38 T:3030153104 M:3318235136 DEBUG: SDLKeyboard: scancode: 116, sym: 274, unicode: 0, modifier: 0
18:49:38 T:3030153104 M:3318235136 DEBUG: OnKey: 61480 pressed, action is 4
18:49:39 T:3030153104 M:3319513088 DEBUG: SDLKeyboard: scancode: 114, sym: 275, unicode: 0, modifier: 0
18:49:39 T:3030153104 M:3319513088 DEBUG: OnKey: 61479 pressed, action is 2
18:49:39 T:3030153104 M:3319140352 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:49:39 T:3030153104 M:3319140352 DEBUG: OnKey: 61453 pressed, action is 7
18:49:39 T:3030153104 M:3319140352 DEBUG: ExecuteXBMCAction : Translating XBMC.PlayDVD()
18:49:39 T:3030153104 M:3319140352 DEBUG: ExecuteXBMCAction : To XBMC.PlayDVD()
18:49:39 T:3030153104 M:3319140352 DEBUG: new file set audiostream:0
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers(dvd://1)
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/rtmp/mms/udp
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: dvd
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: adding player: videodefaultdvdplayer (1) for rule: dvd
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdfile
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers: matched 1 rules with players
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
18:49:39 T:3030153104 M:3319140352 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
18:49:39 T:3030153104 M:3319140352 NOTICE: DVDPlayer: Opening: dvd://1
18:49:39 T:2972621680 M:3319140352 DEBUG: thread start, auto delete: 1
18:49:39 T:3030153104 M:3319140352 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:49:39 T:2781707120 M:3319140352 DEBUG: thread start, auto delete: 0
18:49:39 T:2781707120 M:3319140352 NOTICE: Creating InputStream
18:49:39 T:2781707120 M:3319140352 DEBUG: Loading: /usr/share/xbmc/system/players/dvdplayer/libdvdnav-i486-linux.so
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdnav: Using dvdnav version 4.1.3
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Using libdvdcss version 1.2.10 for DVD access
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdnav: vm: DVD Title: WAGES_OF_FEAR
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdnav: Unable to find map file '/home/chris/.dvdnav/WAGES_OF_FEAR.map'
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdnav: DVD disk reports itself with Region mask 0x00fe0000. Regions:
18:49:39 T:2781707120 M:3319140352 INFO: msg: 1
18:49:39 T:2781707120 M:3319140352 INFO: msg:
18:49:39 T:2781707120 M:3319140352 INFO: msg:
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Attempting to retrieve all CSS keys
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: This can take a _long_ time, please be patient
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VIDEO_TS.VOB at 0x00000144
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_01_0.VOB at 0x00000197
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_01_1.VOB at 0x00006965
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_02_0.VOB at 0x00006986
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_02_1.VOB at 0x000069bf
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_03_0.VOB at 0x00006dfb
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_03_1.VOB at 0x00006e34
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_04_0.VOB at 0x003d6de6
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Get key for /VIDEO_TS/VTS_04_1.VOB at 0x003d6e1f
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Found 4 VTS's
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: Elapsed time 0
18:49:39 T:2781707120 M:3319140352 DEBUG: Open - Setting region mask 01
18:49:39 T:2781707120 M:3319140352 INFO: msg: libdvdread: potential layer change. 1 zero sectors detected starting at 4!
18:49:39 T:2781707120 M:3319140352 NOTICE: DVDPlayer: playing a dvd with menu's
18:49:39 T:2781707120 M:3319140352 NOTICE: Creating Demuxer
18:49:39 T:2781707120 M:3319140352 DEBUG: Loading: /usr/share/xbmc/system/players/dvdplayer/avformat-52-i486-linux.so
18:49:39 T:2781707120 M:3318632448 DEBUG: DVDNAV_HOP_CHANNEL
18:49:39 T:2781707120 M:3318632448 INFO: ffmpeg[A5CD7B70]: Input #0, mpeg, from '/dev/cdrom':
18:49:39 T:2781707120 M:3318632448 INFO: ffmpeg[A5CD7B70]: Duration: N/A, bitrate: N/A
18:49:39 T:2781707120 M:3318632448 NOTICE: Opening audio stream: 0 source: 512
18:49:39 T:2781707120 M:3318632448 NOTICE: Opening Subtitle stream: 0 source: 512
18:49:39 T:2781707120 M:3318632448 WARNING: Process - Could not detect frame rate for: /dev/cdrom. Using default of 25.000 fps for conversion of any commercial break frame markers to times.
18:49:39 T:2781707120 M:3318632448 DEBUG: ReadEditDecisionLists - checking for any edit decision lists (EDL) on local drive or remote share for: /dev/cdrom
18:49:39 T:2781707120 M:3318632448 WARNING: CDVDMessageQueue(audio)::Put MSGQ_NOT_INITIALIZED
18:49:39 T:2781707120 M:3318632448 WARNING: CDVDMessageQueue(video)::Put MSGQ_NOT_INITIALIZED
18:49:39 T:2781707120 M:3318632448 WARNING: CDVDMessageQueue(teletext)::Put MSGQ_NOT_INITIALIZED
18:49:39 T:2781707120 M:3318632448 DEBUG: - DVDNAV_VTS_CHANGE (HOLDING)
18:49:39 T:2781707120 M:3318632448 DEBUG: DVDNAV_VTS_CHANGE
18:49:39 T:2781707120 M:3318632448 INFO: GetVideoAspectRatio - Aspect wanted: 0, Scale permissions: 3
18:49:39 T:3030153104 M:3318632448 DEBUG: OnPlayBackStarted - Playback has started
18:49:39 T:3030153104 M:3318632448 DEBUG: CGUIInfoManager::SetCurrentMovie(dvd://1)
18:49:39 T:3030153104 M:3318632448 DEBUG: GetMovieId (dvd://1), query = select idMovie from movie where idFile=1
18:49:39 T:3030153104 M:3318632448 DEBUG: GetEpisodeId (dvd://1), query = select idEpisode from episode where idFile=1
18:49:39 T:3030153104 M:3318632448 DEBUG: GetMusicVideoId (dvd://1), query = select idMVideo from musicvideo where idFile=1
18:49:39 T:2972621680 M:3318632448 DEBUG: Thread 2972621680 terminating (autodelete)
18:49:39 T:2781707120 M:3322187776 DEBUG: ProcessBlock - Cell change: Title 0, Chapter 0
18:49:39 T:2781707120 M:3322187776 DEBUG: ProcessBlock - At position 0% inside the feature
18:49:39 T:2781707120 M:3322187776 DEBUG: DVDNAV_CELL_CHANGE
18:49:39 T:2781707120 M:3322187776 DEBUG: DVDNAV_SPU_CLUT_CHANGE
18:49:39 T:2781707120 M:3322187776 DEBUG: DVDNAV_SPU_STREAM_CHANGE
18:49:39 T:2781707120 M:3322187776 DEBUG: DVDNAV_AUDIO_STREAM_CHANGE
18:49:39 T:2781707120 M:3322187776 DEBUG: DVDNAV_NAV_PACKET - DISCONTINUITY FROM:0 TO:233566 DIFF:233566
18:49:39 T:2781707120 M:3322187776 INFO: ffmpeg[A5CD7B70]: Input #0, mpeg, from '/dev/cdrom':
18:49:39 T:2781707120 M:3322187776 INFO: ffmpeg[A5CD7B70]: Duration: N/A, bitrate: N/A
18:49:39 T:2781707120 M:3322187776 NOTICE: Opening Subtitle stream: 1 source: 256
18:49:39 T:2781707120 M:3322187776 DEBUG: CDVDPlayer::ProcessSubData: Got complete SPU packet
18:49:39 T:2781707120 M:3322187776 NOTICE: Opening video stream: 0 source: 256
18:49:39 T:2781707120 M:3322187776 INFO: GetVideoAspectRatio - Aspect wanted: 0, Scale permissions: 3
18:49:39 T:2781707120 M:3322187776 NOTICE: Creating video codec with codec id: 2
18:49:39 T:2781707120 M:3322187776 DEBUG: FactoryCodec - Video: libmpeg2 - Opening
18:49:39 T:2781707120 M:3322187776 DEBUG: Loading: /usr/share/xbmc/system/players/dvdplayer/libmpeg2-i486-linux.so
18:49:39 T:2781707120 M:3322187776 DEBUG: FactoryCodec - Video: libmpeg2 - Opened
18:49:39 T:2781707120 M:3322187776 NOTICE: Creating video thread
18:49:39 T:2972621680 M:3322187776 DEBUG: thread start, auto delete: 0
18:49:39 T:2781707120 M:3322187776 NOTICE: Opening audio stream: 2 source: 256
18:49:39 T:2781707120 M:3322187776 NOTICE: Finding audio codec for: 86020
18:49:39 T:2781707120 M:3322187776 DEBUG: FactoryCodec - Audio: passthrough - Opening
18:49:39 T:2781707120 M:3322187776 DEBUG: Loading: /usr/share/xbmc/system/players/dvdplayer/liba52-i486-linux.so
18:49:39 T:2781707120 M:3322187776 DEBUG: FactoryCodec - Audio: passthrough - Opened
18:49:39 T:2781707120 M:3322187776 NOTICE: Creating audio thread
18:49:39 T:2773048176 M:3322187776 DEBUG: thread start, auto delete: 0
18:49:39 T:2773048176 M:3322187776 NOTICE: running thread: CDVDPlayerAudio::Process()
18:49:39 T:2773048176 M:3322187776 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(-0.000000, 0)
18:49:39 T:2773048176 M:3322187776 DEBUG: ParseFrame - source flags changed flags:1 sr:48000 br:192000
18:49:39 T:2773048176 M:3322187776 NOTICE: Creating audio device with codec id: 86020, channels: 2, sample rate: 48000, pass-through
18:49:39 T:2773048176 M:3322187776 DEBUG: CALSADirectSound::CALSADirectSound - Channels: 2 - SampleRate: 48000 - SampleBit: 16 - Resample false - Codec AC3 - IsMusic false - IsPassthrough true - audioDevice: hdmi
18:49:39 T:2773048176 M:3322187776 DEBUG: RemoveActiveDevice - Removing device 1
18:49:39 T:2773048176 M:3322187776 DEBUG: SetActiveDevice - SetActiveDevice from 0 to 2
18:49:39 T:2773048176 M:3322187776 DEBUG: RemoveActiveDevice - Removing device 0
18:49:39 T:2773048176 M:3322187776 DEBUG: Initialize - using alsa device hdmi:AES0=0x6,AES1=0x82,AES2=0x0,AES3=0x2
18:49:39 T:2972621680 M:3322187776 DEBUG: LinuxRendererGL: Cleaning up GL resources
18:49:39 T:2972621680 M:3322187776 NOTICE: running thread: video_thread
18:49:39 T:2972621680 M:3322187776 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(-33366.666667, 1)
18:49:39 T:2972621680 M:3322187776 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
18:49:39 T:2972621680 M:3322187776 NOTICE: fps: 25.000000, pwidth: 720, pheight: 480, dwidth: 656, dheight: 480
18:49:39 T:2972621680 M:3322187776 DEBUG: OutputPicture - change configuration. 720x480. framerate: 25.00
18:49:39 T:2972621680 M:3322187776 NOTICE: Display resolution DESKTOP : 1920x1080 @ 50.00 - Full Screen (12)
18:49:39 T:3030153104 M:3322187776 DEBUG: Activating window ID: 12005
18:49:39 T:3030153104 M:3322187776 DEBUG: Checking if window ID 12005 is locked.
18:49:39 T:3030153104 M:3322187776 DEBUG: ------ Window Deinit (Home.xml) ------
18:49:39 T:3030153104 M:3322187776 DEBUG: ------ Window Init (VideoFullScreen.xml) ------
18:49:39 T:3030153104 M:3322187776 INFO: Loading skin file: VideoFullScreen.xml
18:49:39 T:3030153104 M:3321933824 DEBUG: Load VideoFullScreen.xml: 0.77ms
18:49:39 T:3030153104 M:3321933824 DEBUG: Alloc resources: 0.85ms (0.85 ms skin load)
18:49:39 T:3030153104 M:3321933824 INFO: Loading skin file: VideoOSD.xml
18:49:39 T:3030153104 M:3321806848 DEBUG: Load VideoOSD.xml: 35.98ms
18:49:39 T:3030153104 M:3320664064 DEBUG: Alloc resources: 6.75ms (0.00 ms skin load)
18:49:39 T:3030153104 M:3320664064 INFO: Loading skin file: VideoOSDSettings.xml
18:49:39 T:3030153104 M:3320664064 DEBUG: Load VideoOSDSettings.xml: 1.55ms
18:49:39 T:3030153104 M:3318632448 DEBUG: Alloc resources: 14.02ms (0.00 ms skin load)
18:49:39 T:3030153104 M:3318632448 INFO: Loading skin file: VideoOSDSettings.xml
18:49:39 T:3030153104 M:3318632448 DEBUG: Load VideoOSDSettings.xml: 1.58ms
18:49:39 T:3030153104 M:3318632448 DEBUG: Alloc resources: 0.08ms (0.00 ms skin load)
18:49:39 T:2773048176 M:3311902720 DEBUG: CALSADirectSound::Initialize - packet size:2048, packet count:16, buffer size:8192
18:49:39 T:2773048176 M:3311902720 DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
18:49:39 T:2773048176 M:3311902720 DEBUG: CDVDPlayerAudio:: Discontinuty - was:194151.802333, should be:12.078480, error:-194139.723853
18:49:40 T:3030153104 M:3311902720 NOTICE: Using GL_TEXTURE_2D
18:49:40 T:3030153104 M:3311902720 DEBUG: GL: Requested render method: 0
18:49:40 T:3030153104 M:3311902720 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:49:40 T:3030153104 M:3311902720 DEBUG: GL: Shader compilation log:
18:49:40 T:3030153104 M:3311902720 DEBUG: GL: Shader compilation log:
18:49:40 T:3030153104 M:3311648768 NOTICE: GL: NPOT texture support detected
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 720 x 480
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 720 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 720 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 720 x 480
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 720 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 720 x 240
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:3030153104 M:3311648768 DEBUG: GL: Creating YUV NPOT texture of size 360 x 120
18:49:40 T:2972621680 M:3309998080 DEBUG: CDVDVideoCodecLibMpeg2::m_bFilm = true
18:49:41 T:3030153104 M:3312877568 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:49:41 T:3030153104 M:3312877568 DEBUG: OnKey: 61453 pressed, action is 7
18:49:41 T:2781707120 M:3312877568 DEBUG: - button select
18:49:41 T:2781707120 M:3312877568 DEBUG: DVDNAV_HOP_CHANNEL
18:49:41 T:2781707120 M:3312877568 WARNING: CDVDMessageQueue(teletext)::Put MSGQ_NOT_INITIALIZED
18:49:41 T:2781707120 M:3312877568 DEBUG: - DVDNAV_VTS_CHANGE (HOLDING)
18:49:41 T:2781707120 M:3312877568 DEBUG: DVDNAV_VTS_CHANGE
18:49:41 T:2781707120 M:3312877568 INFO: GetVideoAspectRatio - Aspect wanted: 0, Scale permissions: 3
18:49:41 T:2972621680 M:3313639424 DEBUG: (Reset)
18:49:41 T:2972621680 M:3313639424 DEBUG: CDVDPlayerVideo - CDVDMsg::VIDEO_SET_ASPECT
18:49:41 T:2781707120 M:3313639424 DEBUG: ProcessBlock - Cell change: Title 3, Chapter 1
18:49:41 T:2781707120 M:3313639424 DEBUG: ProcessBlock - At position 0% inside the feature
18:49:41 T:2781707120 M:3313639424 DEBUG: DVDNAV_CELL_CHANGE
18:49:41 T:2781707120 M:3313639424 DEBUG: DVDNAV_SPU_CLUT_CHANGE
18:49:41 T:2781707120 M:3313639424 DEBUG: DVDNAV_SPU_STREAM_CHANGE
18:49:41 T:2781707120 M:3313639424 INFO: ProcessBlock - none or invalid audio stream selected, defaulting to first
18:49:41 T:2781707120 M:3313639424 DEBUG: SetActiveAudioStream - id: 0, stream: 0
18:49:41 T:2781707120 M:3313639424 DEBUG: DVDNAV_AUDIO_STREAM_CHANGE
18:49:41 T:2781707120 M:3313639424 DEBUG: DVDNAV_AUDIO_STREAM_CHANGE
18:49:41 T:2781707120 M:3313639424 DEBUG: DVDNAV_NAV_PACKET - DISCONTINUITY FROM:13663644 TO:233566 DIFF:-13430077
18:49:41 T:2781707120 M:3313639424 INFO: ffmpeg[A5CD7B70]: Input #0, mpeg, from '/dev/cdrom':
18:49:41 T:2781707120 M:3313639424 INFO: ffmpeg[A5CD7B70]: Duration: N/A, bitrate: N/A
18:49:41 T:2781707120 M:3313639424 NOTICE: Opening audio stream: 1 source: 256
18:49:41 T:2773048176 M:3313639424 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_DELAY(33366.666667)
18:49:41 T:2972621680 M:3313639424 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(13396711.111111, 1)
18:49:41 T:2773048176 M:3313258496 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(13430077.777778, 0)
18:49:41 T:2773048176 M:3313258496 DEBUG: CDVDPlayerAudio:: Discontinuty - was:13451912.444111, should be:13430087.536258, error:-21824.907853
18:49:45 T:2972621680 M:3316064256 DEBUG: CPullupCorrection: detected pattern of length 1: 33366.67
18:49:53 T:2781707120 M:3315183616 ERROR: Error getting next block: Error reading from DVD.
18:49:53 T:2781707120 M:3315183616 NOTICE: CDVDPlayer::OnExit()
18:49:53 T:2781707120 M:3315183616 NOTICE: DVDPlayer: eof, waiting for queues to empty
18:49:53 T:2781707120 M:3315183616 NOTICE: DVDPlayer: closing audio stream
18:49:53 T:2781707120 M:3315183616 NOTICE: Closing audio stream
18:49:53 T:2781707120 M:3315183616 NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
18:49:55 T:2972621680 M:3315183616 DEBUG: CDVDVideoCodecLibMpeg2::m_bFilm = false
18:49:55 T:2972621680 M:3315183616 DEBUG: CPullupCorrection: pattern lost
18:49:56 T:2972621680 M:3315183616 DEBUG: CDVDVideoCodecLibMpeg2::m_bFilm = true
18:50:00 T:2972621680 M:3314810880 DEBUG: CPullupCorrection: detected pattern of length 2: 50053.78 33363.11
18:50:07 T:2993400688 M:3314946048 DEBUG: Thread 2993400688 terminating (autodelete)
18:50:07 T:3030153104 M:3314946048 DEBUG: SECTION:UnloadDelayed(DLL: special://xbmc/system/ImageLib-i486-linux.so)
18:50:07 T:3030153104 M:3314946048 DEBUG: Unloading: ImageLib-i486-linux.so
18:50:08 T:2962582384 M:3314946048 DEBUG: Thread 2962582384 terminating (autodelete)
18:50:08 T:3030153104 M:3314946048 INFO: CheckIdle - Closing session to http://www.google.com (easy=0x99a3758, multi=(nil))
18:50:11 T:2773048176 M:3315732480 WARNING: CDVDMessageQueue(audio)::Get - retrieved last data packet of queue
18:50:11 T:2773048176 M:3315732480 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
18:50:11 T:2781707120 M:3315732480 NOTICE: Waiting for audio thread to exit
18:50:11 T:2773048176 M:3315732480 DEBUG: CDVDPlayerAudio::Process - Abort received, exiting thread
18:50:11 T:2773048176 M:3315732480 NOTICE: thread end: CDVDPlayerAudio::OnExit()
18:50:11 T:2773048176 M:3315732480 DEBUG: Thread 2773048176 terminating
18:50:11 T:2781707120 M:3315732480 NOTICE: Closing audio device
18:50:11 T:2781707120 M:3315986432 DEBUG: SetActiveDevice - SetActiveDevice from 2 to 1
18:50:11 T:2781707120 M:3315986432 DEBUG: RemoveActiveDevice - Removing device 2
18:50:11 T:2781707120 M:3315986432 NOTICE: Deleting audio codec
18:50:11 T:2781707120 M:3321446400 NOTICE: DVDPlayer: closing video stream
18:50:11 T:2781707120 M:3321446400 NOTICE: Closing video stream
18:50:11 T:2781707120 M:3321446400 NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
18:50:11 T:2972621680 M:3321454592 WARNING: CDVDMessageQueue(video)::Get - retrieved last data packet of queue
18:50:11 T:2972621680 M:3321454592 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
18:50:11 T:2781707120 M:3321454592 NOTICE: waiting for video thread to exit
18:50:11 T:2972621680 M:3321454592 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
18:50:11 T:2972621680 M:3321454592 NOTICE: thread end: video_thread
18:50:11 T:2972621680 M:3321454592 DEBUG: Thread 2972621680 terminating
18:50:11 T:2781707120 M:3321454592 NOTICE: deleting video codec
18:50:11 T:2781707120 M:3321454592 NOTICE: DVDPlayer: closing video stream
18:50:11 T:2781707120 M:3321454592 NOTICE: Closing subtitle stream
18:50:11 T:2781707120 M:3321454592 NOTICE: CDVDPlayer::OnExit() deleting demuxer
18:50:11 T:2781707120 M:3321454592 NOTICE: CDVDPlayer::OnExit() deleting input stream
18:50:11 T:2781707120 M:3322851328 DEBUG: OnPlayBackEnded - Playback has finished
18:50:11 T:2781707120 M:3322851328 DEBUG: Thread 2781707120 terminating
18:50:11 T:3030153104 M:3322851328 DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
18:50:11 T:3030153104 M:3322851328 DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
18:50:11 T:3030153104 M:3323105280 DEBUG: CGUIWindowManager::PreviousWindow: Activate new
18:50:11 T:3030153104 M:3323105280 DEBUG: ------ Window Init (Home.xml) ------
18:50:11 T:3030153104 M:3323105280 INFO: Loading skin file: Home.xml
18:50:11 T:3030153104 M:3323105280 DEBUG: Load Home.xml: 6.59ms
18:50:11 T:3030153104 M:3323105280 DEBUG: Alloc resources: 24.15ms (6.85 ms skin load)
18:50:11 T:2972621680 M:3323105280 DEBUG: thread start, auto delete: 1
18:50:11 T:2972621680 M:3323105280 DEBUG: Loading: /usr/share/xbmc/system/ImageLib-i486-linux.so
18:50:11 T:3030153104 M:3326152704 NOTICE: CDVDPlayer::CloseFile()
18:50:11 T:3030153104 M:3326152704 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:50:11 T:3030153104 M:3326152704 NOTICE: DVDPlayer: waiting for threads to exit
18:50:11 T:3030153104 M:3326152704 NOTICE: DVDPlayer: finished waiting
18:50:11 T:3030153104 M:3326152704 DEBUG: LinuxRendererGL: Cleaning up GL resources
18:50:11 T:3030153104 M:3326152704 DEBUG: Deleted YV12 texture 0
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 1 plane 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 1 plane 2
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 1 plane 3
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 2 plane 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 2 plane 2
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 2 plane 3
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 3 plane 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 3 plane 2
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 3 plane 3
18:50:11 T:3030153104 M:3326152704 DEBUG: Deleted YV12 texture 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 1 plane 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 1 plane 2
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 1 plane 3
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 2 plane 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 2 plane 2
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 2 plane 3
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 3 plane 1
18:50:11 T:3030153104 M:3326152704 DEBUG: GL: Deleting texture field 3 plane 2
18:50:11 T:3030153104 M:3326660608 DEBUG: GL: Deleting texture field 3 plane 3
18:50:11 T:2972621680 M:3326787584 DEBUG: DoWork - took 129 ms to load special://skin/backgrounds/videos.jpg
18:50:11 T:3030153104 M:3326152704 DEBUG: SaveFileState - Saving file state for video item dvd://1
18:50:12 T:3030153104 M:3326152704 DEBUG: SECTION:UnloadDelayed(SECTION: LCODE)
18:50:23 T:3030153104 M:3328126976 DEBUG: SDLKeyboard: scancode: 114, sym: 275, unicode: 0, modifier: 0
18:50:23 T:3030153104 M:3328126976 DEBUG: OnKey: 61479 pressed, action is 2
18:50:23 T:3030153104 M:3328888832 DEBUG: SDLKeyboard: scancode: 114, sym: 275, unicode: 0, modifier: 0
18:50:23 T:3030153104 M:3328888832 DEBUG: OnKey: 61479 pressed, action is 2
18:50:23 T:3030153104 M:3328679936 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:50:23 T:3030153104 M:3328679936 DEBUG: OnKey: 61453 pressed, action is 7
18:50:23 T:3030153104 M:3328679936 DEBUG: ExecuteXBMCAction : Translating ActivateWindow(ShutdownMenu)
18:50:23 T:3030153104 M:3328679936 DEBUG: ExecuteXBMCAction : To ActivateWindow(ShutdownMenu)
18:50:23 T:3030153104 M:3328679936 DEBUG: Activating window ID: 10111
18:50:23 T:3030153104 M:3328679936 DEBUG: Checking if window ID 10111 is locked.
18:50:23 T:3030153104 M:3328679936 DEBUG: ------ Window Init (DialogButtonMenu.xml) ------
18:50:23 T:3030153104 M:3328679936 INFO: Loading skin file: DialogButtonMenu.xml
18:50:23 T:3030153104 M:3328679936 DEBUG: Load DialogButtonMenu.xml: 35.95ms
18:50:23 T:3030153104 M:3316080640 DEBUG: Alloc resources: 133.99ms (36.15 ms skin load)
18:50:25 T:3030153104 M:3314069504 DEBUG: SDLKeyboard: scancode: 113, sym: 276, unicode: 0, modifier: 0
18:50:25 T:3030153104 M:3314069504 DEBUG: OnKey: 61477 pressed, action is 1
18:50:25 T:3030153104 M:3314323456 DEBUG: SDLKeyboard: scancode: 36, sym: 13, unicode: 13, modifier: 0
18:50:25 T:3030153104 M:3314323456 DEBUG: OnKey: 61453 pressed, action is 7
18:50:25 T:3030153104 M:3314323456 DEBUG: ExecuteXBMCAction : Translating dialog.close(all,true)
18:50:25 T:3030153104 M:3314323456 DEBUG: ExecuteXBMCAction : To dialog.close(all,true)
18:50:25 T:3030153104 M:3314323456 DEBUG: ------ Window Deinit (DialogButtonMenu.xml) ------
18:50:25 T:3030153104 M:3314323456 DEBUG: ExecuteXBMCAction : Translating XBMC.Quit()
18:50:25 T:3030153104 M:3314323456 DEBUG: ExecuteXBMCAction : To XBMC.Quit()
18:50:25 T:2972621680 M:3314323456 DEBUG: Thread 2972621680 terminating (autodelete)
18:50:25 T:3030153104 M:3314323456 NOTICE: Storing total System Uptime
18:50:25 T:3030153104 M:3314323456 NOTICE: Saving settings
18:50:25 T:3030153104 M:3314323456 NOTICE: stop all
18:50:25 T:3030153104 M:3314323456 DEBUG: NetworkMessage - Signaling network services to stop
18:50:25 T:3030153104 M:3314323456 NOTICE: ES: Stopping event server
18:50:25 T:3030153104 M:3314323456 DEBUG: NetworkMessage - Waiting for network services to stop
18:50:25 T:3030153104 M:3314323456 NOTICE: stopping zeroconf publishing
18:50:25 T:3030153104 M:3314323456 DEBUG: CLastfmScrobbler: Journal with 0 entries saved to special://masterprofile/LastfmScrobbler.xml
18:50:25 T:3030153104 M:3314323456 DEBUG: CLibrefmScrobbler: Journal with 0 entries saved to special://masterprofile/LibrefmScrobbler.xml
18:50:26 T:3018578800 M:3314323456 NOTICE: ES: UDP Event server stopped
18:50:26 T:3018578800 M:3314323456 DEBUG: Thread 3018578800 terminating
18:50:26 T:3010186096 M:3314196480 NOTICE: DS: DBUS server stopped
18:50:26 T:3010186096 M:3314196480 DEBUG: Thread 3010186096 terminating
18:50:26 T:3030153104 M:3314196480 NOTICE: stop dvd detect media
18:50:26 T:3027942256 M:3314196480 DEBUG: Thread 3027942256 terminating
18:50:26 T:3030153104 M:3314196480 NOTICE: stop sap announcement listener
18:50:26 T:3030153104 M:3314196480 NOTICE: clean cached files!
18:50:26 T:3030153104 M:3314196480 NOTICE: unload skin
18:50:26 T:3030153104 M:3314196480 DEBUG: ------ Window Deinit (Home.xml) ------
18:50:26 T:3030153104 M:3314196480 DEBUG: ------ Window Deinit (Pointer.xml) ------
18:50:26 T:3030153104 M:3314196480 DEBUG: ------ Window Deinit (DialogMuteBug.xml) ------
18:50:26 T:3030153104 M:3316862976 NOTICE: stop python
18:50:26 T:3030153104 M:3316862976 NOTICE: stopped
18:50:26 T:3030153104 M:3316862976 NOTICE: destroy
18:50:26 T:3030153104 M:3316981760 NOTICE: unload sections
18:50:26 T:3030153104 M:3316981760 DEBUG: SECTION:UnloadAll(DLL: libcurl.so.4)
18:50:26 T:3030153104 M:3316981760 DEBUG: Unloading: libcurl.so.4
18:50:26 T:3030153104 M:3316981760 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/avutil-50-i486-linux.so)
18:50:26 T:3030153104 M:3316981760 DEBUG: Unloading: avutil-50-i486-linux.so
18:50:26 T:3030153104 M:3316981760 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/avcodec-52-i486-linux.so)
18:50:26 T:3030153104 M:3316981760 DEBUG: Unloading: avcodec-52-i486-linux.so
18:50:26 T:3030153104 M:3316981760 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/swscale-0.6.1-i486-linux.so)
18:50:26 T:3030153104 M:3316981760 DEBUG: Unloading: swscale-0.6.1-i486-linux.so
18:50:26 T:3030153104 M:3317235712 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/libdvdnav-i486-linux.so)
18:50:26 T:3030153104 M:3317235712 DEBUG: Unloading: libdvdnav-i486-linux.so
18:50:26 T:3030153104 M:3317235712 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/avformat-52-i486-linux.so)
18:50:26 T:3030153104 M:3317235712 DEBUG: Unloading: avformat-52-i486-linux.so
18:50:26 T:3030153104 M:3320918016 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/libmpeg2-i486-linux.so)
18:50:26 T:3030153104 M:3320918016 DEBUG: Unloading: libmpeg2-i486-linux.so
18:50:26 T:3030153104 M:3320918016 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/players/dvdplayer/liba52-i486-linux.so)
18:50:26 T:3030153104 M:3320918016 DEBUG: Unloading: liba52-i486-linux.so
18:50:26 T:3030153104 M:3320918016 DEBUG: SECTION:UnloadAll(DLL: special://xbmc/system/ImageLib-i486-linux.so)
18:50:26 T:3030153104 M:3320918016 DEBUG: Unloading: ImageLib-i486-linux.so
18:50:26 T:3030153104 M:3320918016 DEBUG: CLastfmScrobbler: Journal with 0 entries saved to special://masterprofile/LastfmScrobbler.xml
18:50:26 T:3030153104 M:3320918016 DEBUG: CLibrefmScrobbler: Journal with 0 entries saved to special://masterprofile/LibrefmScrobbler.xml
18:50:26 T:3030153104 M:3320918016 INFO: lastfm destroyed
18:50:26 T:3030153104 M:3320918016 DEBUG: object 0 --> 0 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 1 --> 2 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 2 --> 16 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 3 --> 0 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 4 --> 18 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 5 --> 0 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 6 --> 0 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 7 --> 0 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 8 --> 0 instances
18:50:26 T:3030153104 M:3320918016 DEBUG: object 9 --> 0 instances
18:50:26 T:3030153104 M:3334885376 DEBUG: LinuxRendererGL: Cleaning up GL resources