Jump to content

Kodi suddenly can't find some video files


naf623

Recommended Posts

Kodi suddenly can't find some of the video files in my library. Kodi tells me "This file is no longer available. Would you like to remove it from the library?".  This happens with some files and not others, and seems to be intermittent with some. The files play find if I navigate directly to them through "Videos -> Files", they also play on my PCs through the web interface, and the paths to the files are correct in the server. Nothing seems to show in the logfiles, though:

################################################################################
# ... output of cat /storage/.kodi/temp/kodi.log
# OpenELEC release: RPi2.arm-6.0.3
# 
################################################################################
01:00:05   5.524869 T:1967865856  NOTICE: special://profile/ is mapped to: special://masterprofile/
01:00:05   5.524989 T:1967865856  NOTICE: -----------------------------------------------------------------------
01:00:05   5.525030 T:1967865856  NOTICE: Starting Kodi (15.2 Git:02e7013). Platform: Linux ARM 32-bit
01:00:05   5.525063 T:1967865856  NOTICE: Using Release Kodi x32 build (version for Raspberry Pi)
01:00:05   5.525100 T:1967865856  NOTICE: Kodi compiled Mar  1 2016 by GCC 4.9.3 for Linux ARM 32-bit version 4.1.18 (262418)
01:00:05   5.525318 T:1967865856  NOTICE: Running on OpenELEC (official) - Version: 6.0.3, kernel: Linux ARM 32-bit version 4.1.18
01:00:05   5.525349 T:1967865856  NOTICE: FFmpeg version: 2.6.4
01:00:05   5.525378 T:1967865856  NOTICE: WARNING: unsupported ffmpeg version detected
01:00:05   5.525408 T:1967865856  NOTICE: Host CPU: ARMv7 Processor rev 4 (v7l), 4 cores available
01:00:05   5.525435 T:1967865856  NOTICE: ARM Features: Neon enabled
01:00:05   5.525470 T:1967865856  NOTICE: special://xbmc/ is mapped to: /usr/share/kodi
01:00:05   5.525503 T:1967865856  NOTICE: special://xbmcbin/ is mapped to: /usr/lib/kodi
01:00:05   5.525532 T:1967865856  NOTICE: special://masterprofile/ is mapped to: /storage/.kodi/userdata
01:00:05   5.525561 T:1967865856  NOTICE: special://home/ is mapped to: /storage/.kodi
01:00:05   5.525590 T:1967865856  NOTICE: special://temp/ is mapped to: /storage/.kodi/temp
01:00:05   5.525676 T:1967865856  NOTICE: The executable running is: /usr/lib/kodi/kodi.bin
01:00:05   5.525732 T:1967865856  NOTICE: Local hostname: bedroompi
01:00:05   5.525763 T:1967865856  NOTICE: Log File is located: /storage/.kodi/temp/kodi.log
01:00:05   5.529748 T:1967865856  NOTICE: -----------------------------------------------------------------------
01:00:05   5.651638 T:1967865856   ERROR: DBus: Error org.freedesktop.DBus.Error.ServiceUnknown - The name org.freedesktop.UPower was not provided by any .service files
01:00:05   5.658974 T:1967865856  NOTICE: load settings...
01:00:05   5.724083 T:1967850560  NOTICE: Thread FDEventMonitor start, auto delete: false
09:33:19   5.751877 T:1967865856  NOTICE: Found 1 Lists of Devices
09:33:19   5.751971 T:1967865856  NOTICE: Enumerated PI devices:
09:33:19   5.752001 T:1967865856  NOTICE:     Device 1
09:33:19   5.752396 T:1967865856  NOTICE:         m_deviceName      : HDMI
09:33:19   5.752433 T:1967865856  NOTICE:         m_displayName     : HDMI
09:33:19   5.752463 T:1967865856  NOTICE:         m_displayNameExtra:
09:33:19   5.752492 T:1967865856  NOTICE:         m_deviceType      : AE_DEVTYPE_HDMI
09:33:19   5.752521 T:1967865856  NOTICE:         m_channels        : FL,FR
09:33:19   5.752551 T:1967865856  NOTICE:         m_sampleRates     : 8000,11025,16000,22050,24000,32000,44100,48000,88200,96000,176400,192000
09:33:19   5.752583 T:1967865856  NOTICE:         m_dataFormats     : AE_FMT_FLOAT,AE_FMT_S32NE,AE_FMT_S16NE,AE_FMT_S32LE,AE_FMT_S16LE,AE_FMT_FLOATP,AE_FMT_S32NEP,AE_FMT_S16NEP,AE_FMT_AC3,AE_FMT_DTS,AE_FMT_EAC3
09:33:19   5.752635 T:1967865856  NOTICE:     Device 2
09:33:19   5.752699 T:1967865856  NOTICE:         m_deviceName      : Analogue
09:33:19   5.752729 T:1967865856  NOTICE:         m_displayName     : Analogue
09:33:19   5.752759 T:1967865856  NOTICE:         m_displayNameExtra:
09:33:19   5.752788 T:1967865856  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
09:33:19   5.752816 T:1967865856  NOTICE:         m_channels        : FL,FR
09:33:19   5.752843 T:1967865856  NOTICE:         m_sampleRates     : 48000
09:33:19   5.752873 T:1967865856  NOTICE:         m_dataFormats     : AE_FMT_FLOAT,AE_FMT_S32LE,AE_FMT_S16LE,AE_FMT_FLOATP,AE_FMT_S32NEP,AE_FMT_S16NEP
09:33:19   5.752902 T:1967865856  NOTICE:     Device 3
09:33:19   5.752955 T:1967865856  NOTICE:         m_deviceName      : Both
09:33:19   5.752985 T:1967865856  NOTICE:         m_displayName     : HDMI and Analogue
09:33:19   5.753013 T:1967865856  NOTICE:         m_displayNameExtra:
09:33:19   5.753041 T:1967865856  NOTICE:         m_deviceType      : AE_DEVTYPE_PCM
09:33:19   5.753088 T:1967865856  NOTICE:         m_channels        : FL,FR
09:33:19   5.753117 T:1967865856  NOTICE:         m_sampleRates     : 48000
09:33:19   5.753147 T:1967865856  NOTICE:         m_dataFormats     : AE_FMT_FLOAT,AE_FMT_S32LE,AE_FMT_S16LE,AE_FMT_FLOATP,AE_FMT_S32NEP,AE_FMT_S16NEP
09:33:19   5.774755 T:1967865856  NOTICE: Loaded settings file from special://xbmc/system/advancedsettings.xml
09:33:19   5.774998 T:1967865856  NOTICE: Contents of special://xbmc/system/advancedsettings.xml are...
                                            <?xml version="1.0" encoding="UTF-8" ?>
                                            <advancedsettings>
                                              <showexitbutton>false</showexitbutton>
                                              <fanartres>720</fanartres>
                                              <imageres>540</imageres>
                                              <video>
                                                <busydialogdelayms>750</busydialogdelayms>
                                              </video>
                                              <samba>
                                                <clienttimeout>30</clienttimeout>
                                              </samba>
                                              <network>
                                                <readbufferfactor>4.0</readbufferfactor>
                                              </network>
                                            </advancedsettings>
09:33:19   5.776314 T:1967865856  NOTICE: No settings file to load (special://masterprofile/advancedsettings.xml)
09:33:19   5.776350 T:1967865856  NOTICE: Default DVD Player: dvdplayer
09:33:19   5.776379 T:1967865856  NOTICE: Default Video Player: dvdplayer
09:33:19   5.776407 T:1967865856  NOTICE: Default Audio Player: paplayer
09:33:19   5.776443 T:1967865856  NOTICE: Disabled debug logging due to GUI setting. Level 0.
09:33:19   5.776472 T:1967865856  NOTICE: Log level changed to "LOG_LEVEL_NORMAL"
09:33:19   5.776626 T:1967865856  NOTICE: CMediaSourceSettings: loading media sources from special://masterprofile/sources.xml
09:33:19   5.778628 T:1967865856  NOTICE: Loading player core factory settings from special://xbmc/system/playercorefactory.xml.
09:33:19   5.779982 T:1967865856  NOTICE: Loaded playercorefactory configuration
09:33:19   5.780287 T:1967865856  NOTICE: Loading player core factory settings from special://masterprofile/playercorefactory.xml.
09:33:19   5.780413 T:1967865856  NOTICE: special://masterprofile/playercorefactory.xml does not exist. Skipping.
09:33:19   5.822921 T:1957688384  NOTICE: Thread ActiveAE start, auto delete: false
09:33:19   5.823166 T:1947202624  NOTICE: Thread AESink start, auto delete: false
09:33:19   5.829269 T:1886385216  NOTICE: Thread CRBPWorker start, auto delete: false
09:33:19   5.928246 T:1967865856  NOTICE: Running database version Addons19
09:33:19   6.161426 T:1967865856  NOTICE: ADDONS: Using repository repository.xbmc.org
09:33:19   6.161514 T:1967865856  NOTICE: ADDONS: Using repository repository.emby.kodi
09:33:19   6.161553 T:1967865856  NOTICE: ADDONS: Using repository repository.openelec.tv
09:33:19   6.161739 T:1875899456  NOTICE: Thread RemoteControl start, auto delete: false
09:33:19   6.199113 T:1967865856  NOTICE: Raspberry PI firmware version: Feb 19 2016 19:53:38 
                                            Copyright (c) 2012 Broadcom
                                            version 573126451d3fb80e6de5ffb7d1fa117d814417b8 (clean) (release)
09:33:19   6.199203 T:1967865856  NOTICE: ARM mem: 752MB GPU mem: 256MB MPG2:0 WVC1:0
09:33:19   6.199235 T:1967865856  NOTICE: cacheMemBufferSize: 20MB
09:33:19   6.199504 T:1967865856  NOTICE: Config:
                                            arm_freq=1200
                                            audio_pwm_mode=1
                                            audio_sdm_mod_order=2
                                            config_hdmi_boost=5
                                            core_freq=400
                                            desired_osc_freq=0x387520
                                            disable_commandline_tags=2
                                            disable_l2cache=1
                                            emmc_pll_core=1
                                            force_eeprom_read=1
                                            force_pwm_open=1
                                            framebuffer_ignore_alpha=1
                                            framebuffer_swap=1
                                            gpu_freq=300
                                            hdmi_channel_map=8
                                            hdmi_force_cec_address=65535
                                            hdmi_ignore_cec_init=1
                                            init_uart_clock=0x2dc6c00
                                            lcd_framerate=60
                                            over_voltage_avs=0x1b774
                                            overscan_bottom=48
                                            overscan_left=48
                                            overscan_right=48
                                            overscan_top=48
                                            pause_burst_frames=1
                                            program_serial_random=1
                                            sdram_freq=450
                                            temp_limit=85
09:33:19   6.199635 T:1967865856  NOTICE: Config:
                                            device_tree=-
09:33:19   6.199690 T:1967865856  NOTICE: InitWindowSystem: Using EGL Implementation: raspberrypi
09:33:19   6.201610 T:1967865856  NOTICE: Found resolution 640 x 480 for display 0 with 640 x 480 @ 60.000000 Hz
09:33:19   6.201660 T:1967865856  NOTICE: Found resolution 640 x 480 for display 0 with 640 x 480 @ 59.940063 Hz
09:33:19   6.201697 T:1967865856  NOTICE: Found resolution 720 x 480 for display 0 with 720 x 480 @ 60.000000 Hz
09:33:19   6.201736 T:1967865856  NOTICE: Found resolution 720 x 480 for display 0 with 720 x 480 @ 59.940063 Hz
09:33:19   6.201770 T:1967865856  NOTICE: Found resolution 1280 x 720 for display 0 with 1280 x 720 @ 60.000000 Hz
09:33:19   6.201805 T:1967865856  NOTICE: Found resolution 1280 x 720 for display 0 with 1280 x 720 @ 59.940063 Hz
09:33:19   6.201839 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 60.000000 Hz
09:33:19   6.201874 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 59.940063 Hz
09:33:19   6.201908 T:1967865856  NOTICE: Found resolution 720 x 576 for display 0 with 720 x 576 @ 50.000000 Hz
09:33:19   6.201942 T:1967865856  NOTICE: Found resolution 1280 x 720 for display 0 with 1280 x 720 @ 50.000000 Hz
09:33:19   6.201976 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 50.000000 Hz
09:33:19   6.202010 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 24.000000 Hz
09:33:19   6.202047 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 23.976025 Hz
09:33:19   6.202082 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 25.000000 Hz
09:33:19   6.202116 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 30.000000 Hz
09:33:19   6.202151 T:1967865856  NOTICE: Found resolution 1920 x 1080 for display 0 with 1920 x 1080 @ 29.970032 Hz
09:33:19   6.202185 T:1967865856  NOTICE: Found resolution 640 x 480 for display 0 with 640 x 480 @ 72.000000 Hz
09:33:19   6.202220 T:1967865856  NOTICE: Found resolution 640 x 480 for display 0 with 640 x 480 @ 71.928070 Hz
09:33:19   6.202270 T:1967865856  NOTICE: Found resolution 640 x 480 for display 0 with 640 x 480 @ 75.000000 Hz
09:33:19   6.202305 T:1967865856  NOTICE: Found resolution 800 x 600 for display 0 with 800 x 600 @ 60.000000 Hz
09:33:19   6.202340 T:1967865856  NOTICE: Found resolution 800 x 600 for display 0 with 800 x 600 @ 59.940063 Hz
09:33:19   6.202388 T:1967865856  NOTICE: Found resolution 800 x 600 for display 0 with 800 x 600 @ 72.000000 Hz
09:33:19   6.202424 T:1967865856  NOTICE: Found resolution 800 x 600 for display 0 with 800 x 600 @ 71.928070 Hz
09:33:19   6.202459 T:1967865856  NOTICE: Found resolution 800 x 600 for display 0 with 800 x 600 @ 75.000000 Hz
09:33:19   6.202493 T:1967865856  NOTICE: Found resolution 1024 x 768 for display 0 with 1024 x 768 @ 60.000000 Hz
09:33:19   6.202527 T:1967865856  NOTICE: Found resolution 1024 x 768 for display 0 with 1024 x 768 @ 59.940063 Hz
09:33:19   6.202561 T:1967865856  NOTICE: Found resolution 1024 x 768 for display 0 with 1024 x 768 @ 70.000000 Hz
09:33:19   6.202596 T:1967865856  NOTICE: Found resolution 1024 x 768 for display 0 with 1024 x 768 @ 75.000000 Hz
09:33:19   6.202630 T:1967865856  NOTICE: Found resolution 1152 x 864 for display 0 with 1152 x 864 @ 75.000000 Hz
09:33:19   6.202663 T:1967865856  NOTICE: Found resolution 1280 x 800 for display 0 with 1280 x 800 @ 60.000000 Hz
09:33:19   6.202700 T:1967865856  NOTICE: Found resolution 1280 x 800 for display 0 with 1280 x 800 @ 59.940063 Hz
09:33:19   6.202734 T:1967865856  NOTICE: Found resolution 1280 x 1024 for display 0 with 1280 x 1024 @ 60.000000 Hz
09:33:19   6.202769 T:1967865856  NOTICE: Found resolution 1280 x 1024 for display 0 with 1280 x 1024 @ 59.940063 Hz
09:33:19   6.202803 T:1967865856  NOTICE: Found resolution 1280 x 1024 for display 0 with 1280 x 1024 @ 75.000000 Hz
09:33:19   6.202837 T:1967865856  NOTICE: Found resolution 1440 x 900 for display 0 with 1440 x 900 @ 60.000000 Hz
09:33:19   6.202871 T:1967865856  NOTICE: Found resolution 1440 x 900 for display 0 with 1440 x 900 @ 59.940063 Hz
09:33:19   6.202905 T:1967865856  NOTICE: Found resolution 1680 x 1050 for display 0 with 1680 x 1050 @ 60.000000 Hz
09:33:19   6.202940 T:1967865856  NOTICE: Found resolution 1680 x 1050 for display 0 with 1680 x 1050 @ 59.940063 Hz
09:33:19   6.202973 T:1967865856  NOTICE: Found resolution 1366 x 768 for display 0 with 1366 x 768 @ 60.000000 Hz
09:33:19   6.203010 T:1967865856  NOTICE: Found resolution 1366 x 768 for display 0 with 1366 x 768 @ 59.940063 Hz
09:33:19   6.203044 T:1967865856  NOTICE: Found resolution 1600 x 900 for display 0 with 1600 x 900 @ 60.000000 Hz
09:33:19   6.203079 T:1967865856  NOTICE: Found resolution 1600 x 900 for display 0 with 1600 x 900 @ 59.940063 Hz
09:33:19   6.203111 T:1967865856  NOTICE: Found (1920x1080@60.000000) at 22, setting to RES_DESKTOP at 16
09:33:19   6.203457 T:1967865856  NOTICE: Checking resolution 23
09:33:19   6.307946 T:1967865856  NOTICE: GL_VENDOR = Broadcom
09:33:19   6.308039 T:1967865856  NOTICE: GL_RENDERER = VideoCore IV HW
09:33:19   6.308071 T:1967865856  NOTICE: GL_VERSION = OpenGL ES 2.0
09:33:19   6.308107 T:1967865856  NOTICE: GL_SHADING_LANGUAGE_VERSION = OpenGL ES GLSL ES 1.00
09:33:19   6.308153 T:1967865856  NOTICE: GL_EXTENSIONS = GL_OES_compressed_ETC1_RGB8_texture GL_OES_compressed_paletted_texture GL_OES_texture_npot GL_OES_depth24 GL_OES_vertex_half_float GL_OES_EGL_image GL_OES_EGL_image_external GL_EXT_discard_framebuffer GL_OES_rgb8_rgba8 GL_OES_depth32 GL_OES_mapbuffer GL_EXT_texture_format_BGRA8888 GL_APPLE_rgb_422 GL_EXT_debug_marker
09:33:20   6.891900 T:1967865856  NOTICE: Register - new cec device registered on cec->RPI: CEC Adapter (2708:1001)
09:33:20   6.892002 T:1856996416  NOTICE: Thread CECAdapter start, auto delete: false
09:33:20   6.913798 T:1831830592  NOTICE: Thread PeripBusUSBUdev start, auto delete: false
09:33:20   6.929412 T:1967865856  NOTICE: Running database version Addons19
09:33:20   6.934558 T:1967865856  NOTICE: Running database version ViewModes6
09:33:20   7.231351 T:1967865856  NOTICE: Running database version Textures13
09:33:21   8.215073 T:1801040960  NOTICE: Thread CECAdapterUpdate start, auto delete: false
09:33:21   8.319505 T:1967865856  NOTICE: Running database version MyMusic52
09:33:24  10.855926 T:1967865856  NOTICE: Running database version MyVideos93
09:33:24  10.871702 T:1967865856  NOTICE: Running database version TV29
09:33:24  10.877597 T:1967865856  NOTICE: Running database version Epg10
09:33:24  10.877830 T:1967865856  NOTICE: start dvd mediatype detection
09:33:24  10.878026 T:1877054528  NOTICE: Thread DetectDVDMedia start, auto delete: false
09:33:25  11.773585 T:1967865856 WARNING: JSONRPC: Could not parse type "PVR.Details.Channel"
09:33:25  11.773992 T:1967865856 WARNING: JSONRPC: Could not parse type "PVR.Details.ChannelGroup.Extended"
09:33:25  11.787823 T:1967865856 WARNING: JSONRPC: Could not parse type "GUI.Property.Value"
09:33:25  11.794227 T:1967865856 WARNING: JSONRPC: Could not parse type "Setting.Details.SettingList"
09:33:25  11.858808 T:1822639168  NOTICE: Thread LanguageInvoker start, auto delete: false
09:33:25  11.866336 T:1967865856  NOTICE: Previous line repeats 1 times.
09:33:25  11.866443 T:1967865856  NOTICE: initialize done
09:33:25  11.866481 T:1967865856  NOTICE: Running the application...
09:33:25  12.109365 T:1822639168  NOTICE: -->Python Interpreter Initialized<--
09:33:25  12.234696 T:1790964800  NOTICE: Previous line repeats 1 times.
09:33:25  12.234815 T:1790964800  NOTICE: Thread JobWorker start, auto delete: true
09:33:25  12.372349 T:1967865856  NOTICE: starting zeroconf publishing
09:33:25  12.372612 T:1967865856  NOTICE: Webserver: Starting...
09:33:25  12.373378 T:1967865856  NOTICE: WebServer: Started the webserver
09:33:25  12.373506 T:1967865856  NOTICE: starting upnp client
09:33:25  12.376343 T:1772090432  NOTICE: Thread JobWorker start, auto delete: true
09:33:25  12.377298 T:1967865856  NOTICE: ES: Starting event server
09:33:25  12.380070 T:1654510656  NOTICE: Thread TCPServer start, auto delete: false
09:33:25  12.386590 T:1662899264  NOTICE: Thread EventServer start, auto delete: false
09:33:25  12.386848 T:1662899264  NOTICE: ES: Starting UDP Event server on 0.0.0.0:9777
09:33:25  12.386955 T:1662899264  NOTICE: UDP: Listening on port 9777
09:33:25  12.387460 T:1591317568  NOTICE: Thread JobWorker start, auto delete: true
09:33:27  13.594405 T:1814250560  NOTICE: Previous line repeats 1 times.
09:33:27  13.594536 T:1814250560  NOTICE: ## OpenELEC Addon ## 0.6.12
09:33:27  13.609737 T:1822639168  NOTICE: EMBY.service -> Delaying emby startup by: 0 sec...
09:33:27  13.617093 T:1822639168  NOTICE: EMBY.service -> ======== START EMBY ========
09:33:27  13.618065 T:1822639168  NOTICE: EMBY.service -> Platform: Linux/RPi
09:33:27  13.618528 T:1822639168  NOTICE: EMBY.service -> KODI Version: 15.2 Git:02e7013
09:33:27  13.618917 T:1822639168  NOTICE: EMBY.service -> EMBY Version: 2.2.19
09:33:27  13.657321 T:1822639168  NOTICE: EMBY.service -> Using plugin paths: False
09:33:27  13.657893 T:1822639168  NOTICE: EMBY.service -> Log Level: 1
09:33:27  13.658635 T:1822639168  NOTICE: EMBY.videonodes -> Clearing nodes properties.
09:33:27  13.861200 T:1822639168  NOTICE: EMBY.clientinfo -> DeviceId loaded: D5235E32FEA7476698983B48469400B4
09:33:27  14.056293 T:1822639168  NOTICE: EMBY.service -> Server is online and ready.
09:33:27  14.061073 T:1709835328  NOTICE: EMBY.userclient -> ----===## Starting UserClient ##===----
09:33:27  14.408592 T:1709835328  NOTICE: EMBY.downloadutils -> Requests session started on: http://10.20.42.10:8096
09:33:27  14.497676 T:1709835328  NOTICE: EMBY.userclient -> Current user: naf
09:33:27  14.498173 T:1709835328  NOTICE: EMBY.userclient -> Current userId: d3739544fe084d7a81fd1f1704b39d5f
09:33:28  15.085961 T:1822639168  NOTICE: EMBY.kodimonitor -> Kodi monitor started.
09:33:28  15.111738 T:1537209408  NOTICE: EMBY.librarysync -> ---===### Starting LibrarySync ###===---
09:33:28  15.148644 T:1537209408  NOTICE: EMBY.librarysync -> current: 2.2.19 minimum: 1.1.63
09:33:28  15.149365 T:1582928960  NOTICE: EMBY.websocket_client -> websocket url: ws://10.20.42.10:8096?api_key=a66e46fa1b224251b3199415834e0c71&deviceId=D5235E32FEA7476698983B48469400B4
09:33:28  15.154268 T:1582928960  NOTICE: EMBY.websocket_client -> ----===## Starting WebSocketClient ##===----
09:33:28  15.154840 T:1537209408  NOTICE: EMBY.librarysync -> Database version: 2.2.19
09:33:28  15.155666 T:1537209408  NOTICE: EMBY.librarysync -> SyncDatabase (started)
09:33:28  15.183552 T:1537209408  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
09:33:28  15.239616 T:1582928960  NOTICE: EMBY.downloadutils -> SessionId: 6b3657101073d80868047e9808a90aa5
09:33:28  15.246461 T:1537209408  NOTICE: EMBY.librarysync -> Sorted views: [u'Comedy Shows', u'Factual & Reality', u'Animated Movies', u'Cartoons', u'Christmas Movies', u'Family Light Entertainment', u'Family Movies', u'Family TV Series', u'Light Entertainment', u'Movies', u'TV Series', u'TV to Sort']
09:33:28  15.246981 T:1537209408  NOTICE: EMBY.videonodes -> Clearing nodes properties.
09:33:30  16.654541 T:1537209408  NOTICE: EMBY.librarysync -> Removing views: []
09:33:30  16.655252 T:1537209408  NOTICE: EMBY.librarysync -> Commit successful.
09:33:30  16.731890 T:1537209408  NOTICE: EMBY.librarysync -> Last sync run: 2016-09-14 08:27:41
09:33:30  16.786163 T:1537209408  NOTICE: EMBY.librarysync -> RetentionDateTime: 1900-01-01 00:00:00
09:33:30  17.472977 T:1537209408  NOTICE: EMBY.librarysync -> Fast sync changes: {u'FoldersAddedTo': [], u'UserDataChanged': [{u'ItemId': u'a22b850b547014638d3f0ae7ab014fc8', u'IsFavorite': False, u'Played': True, u'PlayedPercentage': 58.707637401225597, u'LastPlayedDate': u'2016-09-14T08:29:26.8750000Z', u'PlaybackPositionTicks': 21943065570L, u'Key': u'74608021002', u'PlayCount': 5}], u'ItemsRemoved': [], u'ItemsUpdated': [u'a8abda1fc85e36779d6091791f0f6d4c'], u'FoldersRemovedFrom': [], u'ItemsAdded': []}
09:33:30  17.473412 T:1537209408  NOTICE: EMBY.librarysync -> Queue userdata: [u'a22b850b547014638d3f0ae7ab014fc8']
09:33:30  17.473730 T:1537209408  NOTICE: EMBY.librarysync -> Queue update: [u'a8abda1fc85e36779d6091791f0f6d4c']
09:33:30  17.474119 T:1537209408  NOTICE: EMBY.librarysync -> SyncDatabase (finished in: 0:00:02) True
09:33:31  17.535172 T:1537209408  NOTICE: EMBY.librarysync -> incSyncIndicator=0 totalUpdates=2
09:33:31  17.572111 T:1537209408  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
09:33:31  17.595137 T:1537209408  NOTICE: Previous line repeats 1 times.
09:33:31  17.595291 T:1537209408  NOTICE: EMBY.itemtypes -> Processing update: {u'Series': [u'a8abda1fc85e36779d6091791f0f6d4c']}
09:33:31  17.625065 T:1537209408  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
09:33:31  17.678312 T:1537209408  NOTICE: Previous line repeats 1 times.
09:33:31  17.678474 T:1537209408  NOTICE: EMBY.itemtypes -> showid: 453 pathid: 455
09:33:31  18.267538 T:1537209408  NOTICE: EMBY.itemtypes -> UPDATE tvshow itemid: a8abda1fc85e36779d6091791f0f6d4c - Title: Top Gear
09:33:34  20.754341 T:1537209408  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
09:33:34  20.766502 T:1537209408  NOTICE: Previous line repeats 1 times.
09:33:34  20.766605 T:1537209408  NOTICE: EMBY.itemtypes -> Processing userdata: {u'Episode': [u'a22b850b547014638d3f0ae7ab014fc8']}
09:33:34  20.797283 T:1537209408  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
09:33:34  20.838564 T:1537209408  NOTICE: Previous line repeats 1 times.
09:33:34  20.838667 T:1537209408  NOTICE: EMBY.itemtypes -> Update playstate for episode: Alfa 4C vs. Quadski fileid: 26317
09:33:34  20.845104 T:1537209408  NOTICE: EMBY.librarysync -> Updating emby database.
09:33:35  22.148920 T:1537209408  NOTICE: EMBY.librarysync -> New sync time: server time -2 min: 2016-09-14T08:31:35Z
09:33:36  23.526070 T:1537209408  NOTICE: EMBY.librarysync -> Commit successful.
09:33:36  23.526505 T:1537209408  NOTICE: EMBY.librarysync -> Updating video library.
09:33:37  23.683870 T:1557763136  NOTICE: VideoInfoScanner: Starting scan ..
09:33:37  23.728704 T:1822639168  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanStarted Data: null
09:33:37  23.800840 T:1557763136  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
09:33:37  24.009327 T:1822639168  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanFinished Data: null
09:33:41  27.549019 T:1566151744  NOTICE: Thread BackgroundLoader start, auto delete: false
09:35:32 138.552216 T:1967865856  NOTICE: Previous line repeats 4 times.
09:35:32 138.552429 T:1967865856  NOTICE: NFS is idle. Closing the remaining connections.

After the initial sync, I tried once to open an episode which failed previously, and it failed. But none of that shows in the log.

Link to comment
Share on other sites

Angelblue05

Check the path to the episode, is it correct? Otherwise, you can try to enable Kodi debug, it should show what's happening when you playback the file.

Link to comment
Share on other sites

Yeah, I checked the paths. I even did a full repair of the library to try to update any patrhs which may have been out of date or something, but nothing changed.

All I get is:

10:09:49  43.798027 T:1865385024   DEBUG: PushCecKeypress - received key  b duration 0 (rep:0 size:0)
10:09:49  43.798119 T:1865385024   DEBUG: PushCecKeypress - added key  b
10:09:49  43.831333 T:1968119808   DEBUG: OnKey: 11 (0x0b) pressed, action is Select
10:09:49  43.852398 T:1968119808   DEBUG: SECTION:LoadDLL(libnfs.so.8)
10:09:49  43.853905 T:1968119808   DEBUG: Loading: libnfs.so.8
10:09:49  43.915371 T:1968119808   DEBUG: NFS: Context for 10.20.42.10/mnt/tv not open - get a new context.
10:09:49  44.004650 T:1968119808   DEBUG: NFS: Connected to server 10.20.42.10 and export /mnt/tv
10:09:49  44.004765 T:1968119808   DEBUG: NFS: chunks: r/w 1048576/1048576
10:09:49  44.010197 T:1968119808   DEBUG: OnClick called on 'videodb://tvshows/titles/399/9/23249?season=9&tvshowid=399' but file doesn't exist
10:09:49  44.010571 T:1968119808   DEBUG: ------ Window Init (DialogYesNo.xml) ------
10:09:49  44.010616 T:1968119808    INFO: Loading skin file: DialogYesNo.xml, load type: KEEP_IN_MEMORY

It just thinks the file doesn't exist.

Link to comment
Share on other sites

Angelblue05

Can you repeat the test, still with Kodi debug, but playback an episode that does work? Just to compare, thanks. If I gather correctly, the path looks like nfs://10.20.42.**/mnt/tv/...?

 

 

Sent from my iPhone using Tapatalk

Link to comment
Share on other sites

The equivalent section of log (from pressing "select") seems to be:

10:38:15  53.512947 T:1865053248   DEBUG: PushCecKeypress - received key  b duration 0 (rep:0 size:0)
10:38:15  53.513042 T:1865053248   DEBUG: PushCecKeypress - added key  b
10:38:15  53.535030 T:1967345664   DEBUG: OnKey: 11 (0x0b) pressed, action is Select
10:38:15  53.555580 T:1967345664   DEBUG: NFS: Context for 10.20.42.10/mnt/tv not open - get a new context.
10:38:15  53.634323 T:1967345664   DEBUG: NFS: Connected to server 10.20.42.10 and export /mnt/tv
10:38:15  53.634430 T:1967345664   DEBUG: NFS: chunks: r/w 1048576/1048576
10:38:15  53.636234 T:1865053248   DEBUG: PushCecKeypress - received key  b duration 124 (rep:0 size:0)
10:38:15  53.636276 T:1865053248   DEBUG: PushCecKeypress - ignored key  b
10:38:15  53.641216 T:1967345664   DEBUG: OnPlayMedia nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:15  53.641594 T:1967345664   DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc
10:38:15  53.641697 T:1967345664   DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd
10:38:15  53.658768 T:1967345664   DEBUG: Loading settings for nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:15  53.683662 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers(nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4)
10:38:15  53.683773 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules
10:38:15  53.683826 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules
10:38:15  53.683861 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/mms/udp
10:38:15  53.683960 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout
10:38:15  53.684044 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp
10:38:15  53.684109 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp
10:38:15  53.684177 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams
10:38:15  53.684238 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd
10:38:15  53.684277 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage
10:38:15  53.684330 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf
10:38:15  53.684395 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv
10:38:15  53.684456 T:1967345664   DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio
10:38:15  53.684517 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players
10:38:15  53.684616 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1)
10:38:15  53.684650 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0
10:38:15  53.684689 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1
10:38:15  53.684719 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1)
10:38:15  53.684753 T:1967345664   DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players
10:38:15  53.688889 T:1967345664  NOTICE: DVDPlayer: Opening: nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:15  53.689014 T:1967345664 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
10:38:15  53.689117 T:1967345664   DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec
10:38:15  53.689156 T:1967345664   DEBUG: CMMALRenderer::UnInitMMAL pool((nil))
10:38:15  53.689194 T:1967345664   DEBUG: CMMALRenderer::PreInit
10:38:15  53.689381 T:1608881216  NOTICE: Thread DVDPlayer start, auto delete: false
10:38:15  53.689568 T:1608881216  NOTICE: Creating InputStream
10:38:15  53.696804 T:1608881216   DEBUG: CNFSFile::Open - opened mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:15  53.703594 T:1608881216   DEBUG: ScanForExternalSubtitles: Searching for subtitles...
10:38:15  53.714298 T:1608881216   DEBUG: ScanForExternalSubtitles: END (total time: 11 ms)
10:38:15  53.714436 T:1608881216  NOTICE: Creating Demuxer
10:38:15  53.762825 T:1608881216   DEBUG: Open - probing detected format [mov,mp4,m4a,3gp,3g2,mj2]
10:38:15  53.763111 T:1608881216   DEBUG: ffmpeg[5FE59440]: [mov,mp4,m4a,3gp,3g2,mj2] overread end of atom 'colr' by 1 bytes
10:38:15  54.002899 T:1608881216   DEBUG: Open - avformat_find_stream_info starting
10:38:15  54.013683 T:1608881216   DEBUG: Open - av_find_stream_info finished
10:38:15  54.013821 T:1608881216    INFO: ffmpeg[5FE59440]: Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4':
10:38:15  54.013866 T:1608881216    INFO: ffmpeg[5FE59440]:   Metadata:
10:38:15  54.013935 T:1608881216    INFO: ffmpeg[5FE59440]:     major_brand     : mp42
10:38:15  54.013985 T:1608881216    INFO: ffmpeg[5FE59440]:     minor_version   : 0
10:38:15  54.014030 T:1608881216    INFO: ffmpeg[5FE59440]:     compatible_brands: mp42isomavc1
10:38:15  54.014084 T:1608881216    INFO: ffmpeg[5FE59440]:     creation_time   : 2014-11-28 03:21:07
10:38:15  54.014133 T:1608881216    INFO: ffmpeg[5FE59440]:     encoder         : HandBrake 0.9.9 2013052900
10:38:15  54.014202 T:1608881216    INFO: ffmpeg[5FE59440]:   Duration: 00:24:17.21, start: 0.000000, bitrate: 774 kb/s
10:38:15  54.014488 T:1608881216    INFO: ffmpeg[5FE59440]:     Stream #0:0(und): Video: h264 (Main) (avc1 / 0x31637661), yuv420p(tv, smpte170m/smpte170m/bt709), 624x480 [SAR 1:1 DAR 13:10], 609 kb/s, 29.97 fps, 29.97 tbr, 90k tbn, 180k tbc (default)
10:38:15  54.014530 T:1608881216    INFO: ffmpeg[5FE59440]:     Metadata:
10:38:15  54.014580 T:1608881216    INFO: ffmpeg[5FE59440]:       creation_time   : 2014-11-28 03:21:07
10:38:15  54.014633 T:1608881216    INFO: ffmpeg[5FE59440]:       encoder         : JVT/AVC Coding
10:38:15  54.014759 T:1608881216    INFO: ffmpeg[5FE59440]:     Stream #0:1(und): Audio: aac (LC) (mp4a / 0x6134706D), 44100 Hz, stereo, fltp, 159 kb/s (default)
10:38:15  54.014797 T:1608881216    INFO: ffmpeg[5FE59440]:     Metadata:
10:38:15  54.014843 T:1608881216    INFO: ffmpeg[5FE59440]:       creation_time   : 2014-11-28 03:21:07
10:38:15  54.014896 T:1608881216   DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0
10:38:15  54.014931 T:1608881216   DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1
10:38:15  54.015106 T:1608881216  NOTICE: Opening stream: 0 source: 256
10:38:15  54.015209 T:1608881216   DEBUG: CMMALRenderer::init_vout configured:0 format:0->18
10:38:15  54.021255 T:1608881216  NOTICE: Creating video codec with codec id: 28
10:38:15  54.021309 T:1608881216   DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:no MediaCodec:no OpenMax:no libstagefright:no VDPAU:no VAAPI:no iMXVPU:no MMAL:yes
10:38:15  54.021378 T:1608881216   DEBUG: FactoryCodec - Video: mmal-xxxx - Opening
10:38:15  54.030872 T:1608881216   DEBUG: FactoryCodec - Video: mmal-mvc - Opened
10:38:15  54.030972 T:1608881216  NOTICE: Creating video thread
10:38:15  54.031063 T:1617269824  NOTICE: Thread DVDPlayerVideo start, auto delete: false
10:38:15  54.031120 T:1608881216  NOTICE: Opening stream: 1 source: 256
10:38:15  54.031178 T:1617269824  NOTICE: running thread: video_thread
10:38:15  54.031216 T:1608881216  NOTICE: Finding audio codec for: 86018
10:38:15  54.031269 T:1608881216   DEBUG: FactoryCodec - Audio: passthrough - Opening
10:38:15  54.031330 T:1608881216   DEBUG: FactoryCodec - Audio: passthrough - Failed
10:38:15  54.031368 T:1608881216   DEBUG: FactoryCodec - Audio: FFmpeg - Opening
10:38:15  54.031929 T:1634047040  NOTICE: Thread RefClock start, auto delete: false
10:38:15  54.031979 T:1634047040   DEBUG: CVideoReferenceClock: setting up RPi
10:38:15  54.032017 T:1634047040   DEBUG: CVideoReferenceClock: fps: 59.94
10:38:15  54.032078 T:1634047040   DEBUG: CVideoReferenceClock: Detected refreshrate: 59.940 hertz
10:38:15  54.035866 T:1608881216   DEBUG: FactoryCodec - Audio: FFmpeg - Opened
10:38:15  54.035946 T:1608881216  NOTICE: Creating audio thread
10:38:15  54.036129 T:1617269824   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
10:38:15  54.036179 T:1568248896  NOTICE: Thread DVDPlayerAudio start, auto delete: false
10:38:15  54.036213 T:1568248896  NOTICE: running thread: CDVDPlayerAudio::Process()
10:38:15  54.036251 T:1568248896   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
10:38:15  54.036343 T:1608881216   DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:15  54.037189 T:1608881216   DEBUG: OnPlayBackStarted: play state was 1, starting 1
10:38:15  54.037270 T:1967345664   DEBUG: PlayFile: OpenFile succeed, play state 2
10:38:15  54.037323 T:1967345664   DEBUG: OnPlayBackStarted: play state was 2, starting 0
10:38:15  54.038780 T:1608881216   DEBUG: CDVDPlayer::SetCaching - caching state 3
10:38:15  54.039062 T:1617269824   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(0.000000, 1)
10:38:15  54.039124 T:1617269824    INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
10:38:15  54.039181 T:1608881216   DEBUG: CDVDPlayer::CheckContinuity - wrapback :2, prev:66733.333333, curr:33366.666667, diff:-33366.666667
10:38:15  54.039608 T:1568248896   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(23219.954649, 1)
10:38:15  54.039818 T:1568248896  NOTICE: Creating audio stream (codec id: 86018, channels: 2, sample rate: 44100, no pass-through)
10:38:15  54.039978 T:1568248896   DEBUG: CDVDPlayerAudio:: synctype set to 2: resample
10:38:15  54.040051 T:1568248896  NOTICE: CDVDPlayerAudio::OutputPacket duplicate 4 packets of duration 23
10:38:15  54.051746 T:1967345664   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.image_decode input port 320 output port 321 m_handle 0x3cf38c0
10:38:15  54.052490 T:1967345664   DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.image_decode) - port(320), nBufferCountMin(2), nBufferCountActual(2), nBufferSize(81920), nBufferAlignmen(16)
10:38:15  54.057640 T:1967345664   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.egl_render input port 220 output port 221 m_handle 0x3b7d878
10:38:15  54.058224 T:1967345664   DEBUG: COMXCoreComponent::UseEGLImage component(OMX.broadcom.egl_render) - port(221), nBufferCountMin(1), nBufferCountActual(1), nBufferSize(15360) nBufferAlignmen(16)
10:38:15  54.071228 T:1617269824  NOTICE:  fps: 29.970030, pwidth: 624, pheight: 480, dwidth: 624, dheight: 480
10:38:15  54.071327 T:1617269824   DEBUG: OutputPicture - change configuration. 624x480. framerate: 29.97. format: MMAL
10:38:15  54.071373 T:1617269824   DEBUG: CMMALRenderer::Configure - 624x480->624x480@29.97 flags:12 format:18 ext:0 orient:0
10:38:15  54.071445 T:1617269824  NOTICE: Display resolution USER : 1920x1080 (1920x1080) @ 59.94 - Full Screen (23)
10:38:15  54.071514 T:1617269824   DEBUG: CMMALRenderer::init_vout configured:0 format:18->18
10:38:15  54.071571 T:1617269824   DEBUG: CXBMCRenderManager::Configure - 3
10:38:15  54.071621 T:1617269824   DEBUG: CVideoReferenceClock: Clock speed 100.000006%
10:38:15  54.071732 T:1608881216   DEBUG: CDVDPlayer::HandleMessages - player started 2
10:38:15  54.077431 T:1947202624    INFO: CActiveAESink::OpenSink - initialize sink
10:38:15  54.078815 T:1967345664   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.image_decode handle 0x3cf38c0
10:38:15  54.079639 T:1967345664   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.egl_render handle 0x3b7d878
10:38:15  54.096016 T:1967345664   DEBUG: CMMALRenderer::SetVideoRect 0,0,624,480 -> 260,26,1661,1056 (o:0 v:0 d:0 i:0)
10:38:15  54.096268 T:1967345664   DEBUG: CMMALRenderer::SetVideoRect 0,0,624,480 -> 260,26,1401,1030 t:100000
10:38:15  54.096806 T:1967345664   DEBUG: CGUIInfoManager::SetCurrentMovie(nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4)
10:38:15  54.115845 T:1967345664   DEBUG: GetMovieId (nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4), query = select idMovie from movie where idFile=9357
10:38:15  54.116631 T:1967345664   DEBUG: GetEpisodeId (nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4), query = select idEpisode from episode where idFile=9357
10:38:15  54.126068 T:1967345664   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
10:38:15  54.126270 T:1967345664   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
10:38:15  54.127193 T:1967345664   DEBUG: Activating window ID: 12005
10:38:15  54.132305 T:1967345664   DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
10:38:15  54.134792 T:1967345664   DEBUG: ------ Window Init (VideoFullScreen.xml) ------
10:38:15  54.174690 T:1947202624   DEBUG: CAESinkPi:Drain delay:97ms now:0ms
10:38:15  54.174797 T:1947202624   DEBUG: CAESinkPi:Deinitialize
10:38:15  54.175049 T:1947202624   DEBUG: CAESinkPi:SetAudioProps hdmi_stream_channels 0 hdmi_channel_map 00000000
10:38:15  54.181492 T:1947202624   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.audio_render handle 0x742013d8
10:38:15  54.181725 T:1947202624   DEBUG: CActiveAESink::OpenSink - trying to open device PI:HDMI
10:38:15  54.181980 T:1947202624   DEBUG: CAESinkPi:SetAudioProps hdmi_stream_channels 0 hdmi_channel_map 00000008
10:38:15  54.182026 T:1947202624   DEBUG: CAESinkPi:Initialize Format:30 Channels:2 Samplerate:44100 framesize:8 bufsize:17640 bytes/s=352800.00 dest=PI:HDMI
10:38:15  54.182896 T:1947202624   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_render input port 100 output port 100 m_handle 0x742013d8
10:38:15  54.184017 T:1947202624   DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.audio_render) - port(100), nBufferCountMin(1), nBufferCountActual(2), nBufferSize(17648), nBufferAlignmen(16)
10:38:15  54.184315 T:1947202624   DEBUG: CActiveAESink::OpenSink - SinkPi Initialized:
10:38:15  54.184349 T:1947202624   DEBUG:   Output Device : HDMI
10:38:15  54.184380 T:1947202624   DEBUG:   Sample Rate   : 44100
10:38:15  54.184410 T:1947202624   DEBUG:   Sample Format : AE_FMT_FLOATP
10:38:15  54.184441 T:1947202624   DEBUG:   Channel Count : 2
10:38:15  54.184471 T:1947202624   DEBUG:   Channel Layout: FL,FR
10:38:15  54.184502 T:1947202624   DEBUG:   Frames        : 2205
10:38:15  54.184532 T:1947202624   DEBUG:   Frame Samples : 4410
10:38:15  54.184559 T:1947202624   DEBUG:   Frame Size    : 8
10:38:15  54.188484 T:1957688384   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
10:38:15  54.190544 T:1608881216   DEBUG: Previous line repeats 1 times.
10:38:15  54.190697 T:1608881216   DEBUG: CDVDPlayer::HandleMessages - player started 1
10:38:15  54.190765 T:1608881216   DEBUG: CDVDPlayer::SetCaching - caching state 0
10:38:15  54.191303 T:1568248896  NOTICE: CDVDPlayerAudio::OutputPacket duplicate 4 packets of duration 23
10:38:15  54.191624 T:1568248896  NOTICE: CDVDPlayerAudio::OutputPacket duplicate 2 packets of duration 23
10:38:16  54.229580 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: Player.OnPlay Data: {"item":{"id":7934,"type":"episode"},"player":{"playerid":1,"speed":1}}
10:38:16  54.340126 T:1568248896   DEBUG: CDVDPlayerAudio::HandleSyncError - average error 11261.989117 below threshold of 50000.000000
10:38:16  54.340237 T:1568248896   DEBUG: CDVDPlayerAudio::HandleSyncError rr:1.00069 error:11.262ms
10:38:16  54.348324 T:1822131264  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
10:38:16  54.428970 T:1822131264  NOTICE: EMBY.player -> ONPLAYBACK_STARTED: nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4 itemid: 991d2a2bc8a9424ce0bf39dd882364c4
10:38:16  54.467915 T:1822131264  NOTICE: EMBY.player -> ADDING_FILE: {'nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4': {'refresh_id': '519d00811176ad194786b44b457e3b7f', 'AudioStreamIndex': 1, 'SubtitleStreamIndex': '', 'currentPosition': 0, 'item_id': '991d2a2bc8a9424ce0bf39dd882364c4', 'currentfile': 'nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4', 'runtime': 14572150000L, 'Type': 'Episode', 'playmethod': 'DirectPlay'}}
10:38:16  54.469559 T:1576637504  NOTICE: EMBY.websocket_client -> Message: {"MessageType":"PlaybackStart","Data":{"SupportedCommands":["MoveUp","MoveDown","MoveLeft","MoveRight","Select","Back","ToggleContextMenu","ToggleFullscreen","ToggleOsdMenu","GoHome","PageUp","NextLetter","GoToSearch","GoToSettings","PageDown","PreviousLetter","TakeScreenshot","VolumeUp","VolumeDown","ToggleMute","SendString","DisplayMessage","SetAudioStreamIndex","SetSubtitleStreamIndex","Mute","Unmute","SetVolume","Play","Playstate","PlayNext"],"QueueableMediaTypes":["Video"],"PlayableMediaTypes":["Audio","Video"],"Id":"6b3657101073d80868047e9808a90aa5","UserId":"d3739544fe084d7a81fd1f1704b39d5f","UserName":"naf","AdditionalUsers":[],"ApplicationVersion":"2.2.19","Client":"Kodi","LastActivityDate":"2016-09-14T09:38:16.2423850Z","DeviceName":"BedroomPi","NowPlayingItem":{"Name":"Pilot","Id":"991d2a2bc8a9424ce0bf39dd882364c4","Type":"Episode","MediaType":"Video","RunTimeTicks":14572150000,"PrimaryImageTag":"a64a6b292f766126fe0091d98869c846","PrimaryImageItemId":"991d2a2bc8a9424ce0bf39dd882364c4","LogoImageTag":"a8b8997b174999d8ba6f8260af2b2081","LogoItemId":"519d00811176ad194786b44b457e3b7f","ThumbImageTag":"dbaf0dded37218f1f6b763f4cab17c06","ThumbItemId":"519d00811176ad194786b44b457e3b7f","BackdropImageTag":"fb6cc3bfd97e03205279286005989c76","BackdropItemId":"519d00811176ad194786b44b457e3b7f","PremiereDate":"1989-09-18T23:00:00.0000000Z","ProductionYear":1989,"IndexNumber":1,"ParentIndexNumber":1,"SeriesName":"Doogie Howser, M.D.","Artists":[],"MediaStreams":[{"Codec":"h264","CodecTag":"avc1","Language":"und","IsInterlaced":false,"BitRate":609411,"BitDepth":8,"RefFrames":4,"IsDefault":true,"IsForced":false,"Height":480,"Width":624,"AverageFrameRate":29.97,"RealFrameRate":29.97003,"Profile":"Main","Type":"Video","AspectRatio":"4:3","Index":0,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"PixelFormat":"yuv420p","Level":40,"IsAnamorphic":false},{"Codec":"aac","CodecTag":"mp4a","Language":"und","DisplayTitle":"Und AAC stereo Default","IsInterlaced":false,"ChannelLayout":"stereo","BitRate":159991,"Channels":2,"SampleRate":44100,"IsDefault":true,"IsForced":false,"Profile":"LC","Type":"Audio","Index":1,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Level":0}],"ChapterImagesItemId":"991d2a2bc8a9424ce0bf39dd882364c4","Chapters":[{"StartPositionTicks":0,"Name":"Chapter 1"},{"StartPositionTicks":3000000000,"Name":"Chapter 2"},{"StartPositionTicks":6000000000,"Name":"Chapter 3"},{"StartPositionTicks":9000000000,"Name":"Chapter 4"},{"StartPositionTicks":12000000000,"Name":"Chapter 5"}]},"DeviceId":"D5235E32FEA7476698983B48469400B4","SupportsRemoteControl":true,"PlayState":{"PositionTicks":2000000,"CanSeek":true,"IsPaused":false,"IsMuted":false,"VolumeLevel":100,"AudioStreamIndex":1,"MediaSourceId":"991d2a2bc8a9424ce0bf39dd882364c4","PlayMethod":"DirectPlay","RepeatMode":"RepeatNone"}}}
10:38:16  55.019562 T:1576637504  NOTICE: EMBY.websocket_client -> Message: {"MessageType":"UserDataChanged","Data":{"UserId":"d3739544fe084d7a81fd1f1704b39d5f","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":3,"IsFavorite":false,"LastPlayedDate":"2016-09-14T09:38:16.2424550Z","Played":false,"Key":"72203001001","ItemId":"991d2a2bc8a9424ce0bf39dd882364c4"},{"PlayedPercentage":0,"UnplayedItemCount":26,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":false,"Key":"72203001","ItemId":"49d3384c33a41f195a524d78c97eb8ca"}]}}
10:38:16  55.020153 T:1576637504  NOTICE: EMBY.librarysync -> Queue userdata: [u'991d2a2bc8a9424ce0bf39dd882364c4', u'49d3384c33a41f195a524d78c97eb8ca']
10:38:17  55.388767 T:1568248896   DEBUG: CDVDPlayerAudio::HandleSyncError rr:0.99996 error:-3.748ms
10:38:17  55.733547 T:1967345664   DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
10:38:17  55.735878 T:1729094720  NOTICE: EMBY.librarysync -> incSyncIndicator=0 totalUpdates=2
10:38:17  55.767967 T:1729094720  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
10:38:17  55.783596 T:1729094720  NOTICE: Previous line repeats 1 times.
10:38:17  55.783695 T:1729094720  NOTICE: EMBY.itemtypes -> Processing userdata: {u'Season': [u'49d3384c33a41f195a524d78c97eb8ca'], u'Episode': [u'991d2a2bc8a9424ce0bf39dd882364c4']}
10:38:17  55.815105 T:1729094720  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
10:38:17  55.905712 T:1729094720  NOTICE: Previous line repeats 3 times.
10:38:17  55.905811 T:1729094720  NOTICE: EMBY.itemtypes -> Update playstate for episode: Pilot fileid: 9357
10:38:17  55.922440 T:1729094720  NOTICE: EMBY.librarysync -> Updating emby database.
10:38:17  55.964417 T:1729094720  NOTICE: EMBY.librarysync -> New sync time: server time -2 min: 2016-09-14T09:36:17Z
10:38:17  56.017208 T:1729094720  NOTICE: EMBY.librarysync -> Commit successful.
10:38:17  56.017616 T:1729094720  NOTICE: EMBY.librarysync -> Updating video library.
10:38:17  56.133949 T:1967345664   DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
10:38:17  56.150272 T:1593414720  NOTICE: VideoInfoScanner: Starting scan ..
10:38:17  56.150433 T:1593414720   DEBUG: CAnnouncementManager - Announcement: OnScanStarted from xbmc
10:38:17  56.150551 T:1593414720   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanStarted
10:38:17  56.185078 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanStarted Data: null
10:38:17  56.186001 T:1593414720  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
10:38:17  56.186085 T:1593414720   DEBUG: CAnnouncementManager - Announcement: OnScanFinished from xbmc
10:38:17  56.186195 T:1593414720   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanFinished
10:38:18  56.236835 T:1967345664   DEBUG: ------ Window Deinit (DialogExtendedProgressBar.xml) ------
10:38:18  56.286469 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanFinished Data: null
10:38:19  57.389561 T:1568248896   DEBUG: CDVDPlayerAudio::HandleSyncError rr:1.00007 error:0.717ms
10:38:20  58.370129 T:1617269824   DEBUG: CPullupCorrection: detected pattern of length 1: 33366.67, frameduration: 33366.666667
10:38:21  59.389275 T:1568248896   DEBUG: CDVDPlayerAudio::HandleSyncError rr:1.00015 error:3.689ms
10:38:23  61.389297 T:1568248896   DEBUG: CDVDPlayerAudio::HandleSyncError rr:1.00014 error:3.188ms
10:38:23  61.619965 T:1865053248   DEBUG: PushCecKeypress - received key e0 duration 1000 (rep:0 size:0)
10:38:23  61.620079 T:1865053248   DEBUG: PushCecKeypress - added key e0
10:38:23  61.639763 T:1967345664   DEBUG: OnKey: guide (0xe0) pressed, action is Stop
10:38:23  61.639885 T:1967345664  NOTICE: CDVDPlayer::CloseFile()
10:38:23  61.639923 T:1967345664  NOTICE: DVDPlayer: waiting for threads to exit
10:38:23  61.644520 T:1608881216  NOTICE: CDVDPlayer::OnExit()
10:38:23  61.644558 T:1608881216  NOTICE: Closing stream player 1
10:38:23  61.644592 T:1608881216  NOTICE: Waiting for audio thread to exit
10:38:23  61.688927 T:1568248896  NOTICE: thread end: CDVDPlayerAudio::OnExit()
10:38:23  61.688995 T:1608881216  NOTICE: Closing audio device
10:38:23  61.689041 T:1568248896   DEBUG: Thread DVDPlayerAudio 1568248896 terminating
10:38:23  61.740299 T:1608881216  NOTICE: Deleting audio codec
10:38:23  61.740479 T:1608881216   DEBUG: CVideoReferenceClock: Clock speed 100.000000%
10:38:23  61.740524 T:1608881216  NOTICE: Closing stream player 2
10:38:23  61.740566 T:1608881216  NOTICE: waiting for video thread to exit
10:38:23  61.740639 T:1957688384   DEBUG: CActiveAE::DiscardStream - audio stream deleted
10:38:23  61.740711 T:1957688384   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
10:38:23  61.741093 T:1947202624   DEBUG: Previous line repeats 1 times.
10:38:23  61.741123 T:1947202624    INFO: CActiveAESink::OpenSink - initialize sink
10:38:23  61.789776 T:1617269824  NOTICE: thread end: video_thread
10:38:23  61.790695 T:1608881216  NOTICE: deleting video codec
10:38:23  61.790768 T:1617269824   DEBUG: Thread DVDPlayerVideo 1617269824 terminating
10:38:23  61.794201 T:1608881216   DEBUG: CNFSFile::Close closing file mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:23  61.794342 T:1608881216   DEBUG: OnPlayBackStopped: play state was 2, starting 0
10:38:23  61.794415 T:1608881216   DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
10:38:23  61.794514 T:1608881216   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
10:38:23  61.794628 T:1608881216   DEBUG: Thread DVDPlayer 1608881216 terminating
10:38:23  61.794720 T:1967345664  NOTICE: DVDPlayer: finished waiting
10:38:23  61.794792 T:1967345664   DEBUG: CMMALRenderer::UnInitMMAL pool(0x6b667ba0)
10:38:23  61.809063 T:1967345664   DEBUG: CGUIWindowManager::PreviousWindow: Deactivate
10:38:23  61.809124 T:1967345664   DEBUG: ------ Window Deinit (VideoFullScreen.xml) ------
10:38:23  61.824863 T:1967345664   DEBUG: CGUIWindowManager::PreviousWindow: Activate new
10:38:23  61.838364 T:1947202624   DEBUG: CAESinkPi:Drain delay:97ms now:0ms
10:38:23  61.838482 T:1947202624   DEBUG: CAESinkPi:Deinitialize
10:38:23  61.838737 T:1947202624   DEBUG: CAESinkPi:SetAudioProps hdmi_stream_channels 0 hdmi_channel_map 00000000
10:38:23  61.840916 T:1947202624   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.audio_render handle 0x742013d8
10:38:23  61.841129 T:1947202624   DEBUG: CActiveAESink::OpenSink - trying to open device PI:HDMI
10:38:23  61.841331 T:1967345664   DEBUG: ------ Window Init (MyVideoNav.xml) ------
10:38:23  61.841385 T:1947202624   DEBUG: CAESinkPi:SetAudioProps hdmi_stream_channels 0 hdmi_channel_map 00000008
10:38:23  61.841442 T:1947202624   DEBUG: CAESinkPi:Initialize Format:15 Channels:2 Samplerate:44100 framesize:8 bufsize:17640 bytes/s=352800.00 dest=PI:HDMI
10:38:23  61.842331 T:1947202624   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_render input port 100 output port 100 m_handle 0x742251a8
10:38:23  61.843498 T:1947202624   DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.audio_render) - port(100), nBufferCountMin(1), nBufferCountActual(2), nBufferSize(17648), nBufferAlignmen(16)
10:38:23  61.843784 T:1947202624   DEBUG: CActiveAESink::OpenSink - SinkPi Initialized:
10:38:23  61.843819 T:1947202624   DEBUG:   Output Device : HDMI
10:38:23  61.843849 T:1947202624   DEBUG:   Sample Rate   : 44100
10:38:23  61.843880 T:1947202624   DEBUG:   Sample Format : AE_FMT_FLOAT
10:38:23  61.843910 T:1947202624   DEBUG:   Channel Count : 2
10:38:23  61.843948 T:1967345664   DEBUG: CGUIMediaWindow::GetDirectory (videodb://tvshows/titles/104/-1/?tvshowid=104)
10:38:23  61.844006 T:1947202624   DEBUG:   Channel Layout: FL,FR
10:38:23  61.844036 T:1947202624   DEBUG:   Frames        : 2205
10:38:23  61.844070 T:1947202624   DEBUG:   Frame Samples : 4410
10:38:23  61.844101 T:1947202624   DEBUG:   Frame Size    : 8
10:38:23  61.844135 T:1967345664   DEBUG:   ParentPath = [videodb://tvshows/titles/104/-1/?tvshowid=104]
10:38:23  61.848072 T:1957688384   DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
10:38:23  61.869007 T:1967345664   DEBUG: RunQuery took 6 ms for 97 items query: select * from episode_view  WHERE episode_view.idShow = 104
10:38:23  61.905842 T:1967345664   DEBUG: RunQuery took 10 ms for 0 items query: select * from movie_view join movielinktvshow on movielinktvshow.idMovie=movie_view.idMovie WHERE movielinktvshow.idShow = 104
10:38:23  61.916035 T:1967345664   DEBUG: WindowVideoNav::GetDirectory
10:38:23  62.180931 T:1642435648  NOTICE: Thread BackgroundLoader start, auto delete: false
10:38:24  62.249134 T:1822131264  NOTICE: EMBY.player -> Clear playlist properties.
10:38:24  62.249851 T:1822131264  NOTICE: EMBY.player -> Played_information: {'nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4': {'refresh_id': '519d00811176ad194786b44b457e3b7f', 'AudioStreamIndex': 1, 'SubtitleStreamIndex': '', 'currentPosition': 7.0270004272460938, 'item_id': '991d2a2bc8a9424ce0bf39dd882364c4', 'currentfile': 'nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4', 'runtime': 14572150000L, 'Type': 'Episode', 'playmethod': 'DirectPlay'}}
10:38:24  62.264698 T:1967345664   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.image_decode input port 320 output port 321 m_handle 0x3d1a778
10:38:24  62.265270 T:1967345664   DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.image_decode) - port(320), nBufferCountMin(2), nBufferCountActual(2), nBufferSize(125120), nBufferAlignmen(16)
10:38:24  62.267471 T:1967345664   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.resize input port 60 output port 61 m_handle 0x3d3b400
10:38:24  62.268497 T:1967345664   DEBUG: COMXCoreComponent::Initialize OMX.broadcom.egl_render input port 220 output port 221 m_handle 0x3d5c2c8
10:38:24  62.269001 T:1967345664   DEBUG: COMXCoreComponent::UseEGLImage component(OMX.broadcom.egl_render) - port(221), nBufferCountMin(1), nBufferCountActual(1), nBufferSize(15360) nBufferAlignmen(16)
10:38:24  62.284035 T:1642435648   DEBUG: Thread BackgroundLoader 1642435648 terminating
10:38:24  62.426628 T:1967345664   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.image_decode handle 0x3d1a778
10:38:24  62.427692 T:1967345664   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.resize handle 0x3d3b400
10:38:24  62.428928 T:1967345664   DEBUG: COMXCoreComponent::Deinitialize : OMX.broadcom.egl_render handle 0x3d5c2c8
10:38:24  62.542622 T:1967345664  NOTICE: CDVDPlayer::CloseFile()
10:38:24  62.542809 T:1967345664  NOTICE: DVDPlayer: waiting for threads to exit
10:38:24  62.542877 T:1967345664  NOTICE: DVDPlayer: finished waiting
10:38:24  62.543003 T:1967345664   DEBUG: CMMALRenderer::UnInitMMAL pool((nil))
10:38:24  62.543072 T:1967345664  NOTICE: CDVDPlayer::CloseFile()
10:38:24  62.543129 T:1967345664  NOTICE: DVDPlayer: waiting for threads to exit
10:38:24  62.543190 T:1967345664  NOTICE: DVDPlayer: finished waiting
10:38:24  62.543274 T:1822131264  NOTICE: EMBY.player -> Percent complete: 0.0048222125268 Mark played at: 0.9
10:38:24  62.543400 T:1967345664   DEBUG: CMMALRenderer::UnInitMMAL pool((nil))
10:38:24  62.556915 T:1634047040   DEBUG: CVideoReferenceClock: cleaning up RPi
10:38:24  62.557072 T:1634047040   DEBUG: Thread RefClock 1634047040 terminating
10:38:24  62.564743 T:1792230464   DEBUG: DoWork - Saving file state for video item nfs://10.20.42.10/mnt/tv/Family TV Series/Doogie Howser, M.D/Season 1/Doogie Howser, M.D. S01E01 - Pilot.mp4
10:38:24  62.637890 T:1792230464   DEBUG: CAnnouncementManager - Announcement: OnUpdate from xbmc
10:38:24  62.638142 T:1792230464   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnUpdate
10:38:24  62.657871 T:1576637504  NOTICE: EMBY.websocket_client -> Message: {"MessageType":"PlaybackStopped","Data":{"SupportedCommands":["MoveUp","MoveDown","MoveLeft","MoveRight","Select","Back","ToggleContextMenu","ToggleFullscreen","ToggleOsdMenu","GoHome","PageUp","NextLetter","GoToSearch","GoToSettings","PageDown","PreviousLetter","TakeScreenshot","VolumeUp","VolumeDown","ToggleMute","SendString","DisplayMessage","SetAudioStreamIndex","SetSubtitleStreamIndex","Mute","Unmute","SetVolume","Play","Playstate","PlayNext"],"QueueableMediaTypes":["Video"],"PlayableMediaTypes":["Audio","Video"],"Id":"6b3657101073d80868047e9808a90aa5","UserId":"d3739544fe084d7a81fd1f1704b39d5f","UserName":"naf","AdditionalUsers":[],"ApplicationVersion":"2.2.19","Client":"Kodi","LastActivityDate":"2016-09-14T09:38:24.4105270Z","DeviceName":"BedroomPi","DeviceId":"D5235E32FEA7476698983B48469400B4","SupportsRemoteControl":true,"PlayState":{"CanSeek":false,"IsPaused":false,"IsMuted":false,"RepeatMode":"RepeatNone"}}}
10:38:24  62.697075 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: Player.OnStop Data: {"end":false,"item":{"id":7934,"type":"episode"}}
10:38:24  62.716747 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnUpdate Data: {"item":{"id":7934,"type":"episode"}}
10:38:24  63.203709 T:1576637504  NOTICE: EMBY.websocket_client -> Message: {"MessageType":"UserDataChanged","Data":{"UserId":"d3739544fe084d7a81fd1f1704b39d5f","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":3,"IsFavorite":false,"LastPlayedDate":"2016-09-14T09:38:16.2424550Z","Played":false,"Key":"72203001001","ItemId":"991d2a2bc8a9424ce0bf39dd882364c4"},{"PlayedPercentage":0,"UnplayedItemCount":26,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":false,"Key":"72203001","ItemId":"49d3384c33a41f195a524d78c97eb8ca"}]}}
10:38:24  63.204258 T:1576637504  NOTICE: EMBY.librarysync -> Queue userdata: [u'991d2a2bc8a9424ce0bf39dd882364c4', u'49d3384c33a41f195a524d78c97eb8ca']
10:38:25  63.684902 T:1967345664   DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
10:38:25  63.708523 T:1729094720  NOTICE: EMBY.librarysync -> incSyncIndicator=0 totalUpdates=2
10:38:25  63.743610 T:1729094720  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
10:38:25  63.768913 T:1729094720  NOTICE: Previous line repeats 1 times.
10:38:25  63.769047 T:1729094720  NOTICE: EMBY.itemtypes -> Processing userdata: {u'Season': [u'49d3384c33a41f195a524d78c97eb8ca'], u'Episode': [u'991d2a2bc8a9424ce0bf39dd882364c4']}
10:38:25  63.805622 T:1729094720  NOTICE: EMBY.artwork -> Using Image Cache Thread Count: 25
10:38:25  63.897114 T:1729094720  NOTICE: Previous line repeats 3 times.
10:38:25  63.897209 T:1729094720  NOTICE: EMBY.itemtypes -> Update playstate for episode: Pilot fileid: 9357
10:38:25  63.913216 T:1729094720  NOTICE: EMBY.librarysync -> Updating emby database.
10:38:25  63.956966 T:1729094720  NOTICE: EMBY.librarysync -> New sync time: server time -2 min: 2016-09-14T09:36:25Z
10:38:25  64.020515 T:1729094720  NOTICE: EMBY.librarysync -> Commit successful.
10:38:25  64.021194 T:1729094720  NOTICE: EMBY.librarysync -> Updating video library.
10:38:25  64.158401 T:1967345664   DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------
10:38:25  64.174751 T:1774208064  NOTICE: VideoInfoScanner: Starting scan ..
10:38:25  64.174889 T:1774208064   DEBUG: CAnnouncementManager - Announcement: OnScanStarted from xbmc
10:38:25  64.174995 T:1774208064   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanStarted
10:38:26  64.221809 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanStarted Data: null
10:38:55  94.046272 T:1593414720   DEBUG: Thread JobWorker 1593414720 terminating (autodelete)
10:38:55  94.046448 T:1428300864   DEBUG: Thread JobWorker 1428300864 terminating (autodelete)
10:38:55  94.046616 T:1792230464   DEBUG: Thread JobWorker 1792230464 terminating (autodelete)
10:39:09 107.273445 T:1774208064  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:43
10:39:09 107.273590 T:1774208064   DEBUG: CAnnouncementManager - Announcement: OnScanFinished from xbmc
10:39:09 107.273705 T:1774208064   DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanFinished
10:39:09 107.285683 T:1967345664   DEBUG: CGUIMediaWindow::GetDirectory (videodb://tvshows/titles/104/-1/?tvshowid=104)
10:39:09 107.285843 T:1967345664   DEBUG:   ParentPath = [videodb://tvshows/titles/104/-1/?tvshowid=104]
10:39:09 107.311043 T:1774208064   DEBUG: RunQuery took 6 ms for 97 items query: select * from episode_view  WHERE episode_view.idShow = 104
10:39:09 107.332199 T:1822131264  NOTICE: EMBY.kodimonitor -> Method: VideoLibrary.OnScanFinished Data: null
10:39:09 107.349312 T:1774208064   DEBUG: RunQuery took 11 ms for 0 items query: select * from movie_view join movielinktvshow on movielinktvshow.idMovie=movie_view.idMovie WHERE movielinktvshow.idShow = 104
10:39:09 107.382225 T:1967345664   DEBUG: WindowVideoNav::GetDirectory

That probably includes the "stop" command too...

 

Yes, thats the path structure.

Link to comment
Share on other sites

Angelblue05

You said you did a repair sync, did you try a reset instead? If the path is correct, I don't really see how this is an emby for kodi issue, especially since you are using native playback mode. Do you need permission to access your files or is it accessible by everyone? I understand you navigated to the file via videos > files. You didn't add any sources to Kodi, right? And the path when you navigated to your content was 100% matching what the Emby add-on added to the Kodi database? Hmm

 

 

Sent from my iPhone using Tapatalk

Link to comment
Share on other sites

I didn't; that would have taken even longer. It already takes around 24 hours. So I hoped there might be another solution; but I'll set it going.

 

I only added sources after it stopped working, and all of them are set to be excluded from scans anyway. Why, though? Are added sources a problem for the add on? I do like to add my "unsorted media" folders so I can watch stuff thats mixed and not scanned into the library yet. I hadn't added those this time yet, though.

 

I can't check what the Kodi database has as its path as my remote doesn't seem to send 'c' over CEC; but the emby server lists the correct path. Some of the file paths to ones which don't work might have changed since the add-on first added them to the local database; but other files which don't work have definitely not moved. The repair ought to have sorted that though, right?

  • Like 1
Link to comment
Share on other sites

Angelblue05

Sources can definitely break the add-on's built structure in the Kodi database, especially if they are reflecting the same content as found in Emby. If it's separate content, then it should be fine.

 

Yes a repair should technically force update your content and correct the path, unless the structure was compromised by adding the source. Actually a reset is faster than repair because we don't validate the existance of the entries in the Kodi database. Do you only have one Kodi device? At this time, I'm not sure what the problem could be. Your logs don't show anything weird other than not being able to locate certain files.

 

Is there anything in common with the files that can't be found? Are they all episodes? From the same show? Episodes that are not playing, are they all from the same season?

 

 

Sent from my iPhone using Tapatalk

Edited by Angelblue05
Link to comment
Share on other sites

I don't let Kodi scan anything, its just a convenient way to navigate directly to the file as opposed to indirectly through the media library.

 

My other devices all access via. the web interface. I do have Kodi on my tablet, but I don't use it and don't even think I have the Emby add on installed on it. If I'd known it would be quicker, I'd have done it right away. Good to know.

 

Not that I know of. All of my media are mp4s, pretty sure they're all h.264, all on the same physical disk, in the same parent folder...

Link to comment
Share on other sites

Angelblue05

@@naf623

 

I think the only way you will resolve your issue is by doing a reset of your local database. You can always rebuild the database on a faster device as long as you use the same Kodi version to build it. You can then copy over the userdata profile folders (addon_data, database, thumbnails) over to your main Kodi device.

  • Like 1
Link to comment
Share on other sites

Yeah, the reset seems to have worked. Took ages to rebuild - kept getting "Library Sync Thread Has Exited" the first few times I tried.

 

Thats useful to know for future. Its running on a Pi3 these days, so a bit faster than it used to be. Its just the sheer size of my media library thats the issue. 7TB of TV, 2TB of movies. I skipped my music library for now just for the sake of getting it done.

  • Like 1
Link to comment
Share on other sites

Angelblue05

Yikes. Do you happen to have the errors from the logs when you got library sync exited?

 

 

Sent from my iPhone using Tapatalk

Link to comment
Share on other sites

Sorry, no. I didn't have convenient access to it at the time.

 

I turned on the fix in the add-on settings, and it was working fine. Left it running overnight and it hadn't even finished doing the movies yet. So I turned the setting off and rebooted. It started syncing from scratch again, but was done later that day.

Link to comment
Share on other sites

Guest
This topic is now closed to further replies.
×
×
  • Create New...