Angelblue05 4130 Posted May 24, 2015 Share Posted May 24, 2015 (edited) @@scalda I'm checking your log again. From the looks of it, when you started playback, there was still updating happening which could explain the delay you've been experiencing. At least looking at the logs, it seems ItemCount (I think it's votes?) was still being written to database. Is it possible for you to let your Kodi run a bit to see if things settles? Edit: Even when kodi was shutting down, itemcount was still being pulled from your server. I thought maybe they were the same item, but it seems to be different ones each time. Edited May 24, 2015 by Angelblue05 Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 Ok well I'm going to have to revert back to the earlier release as I can't have it keep polling the database everytime something is played as it's just to many data read and writes to my sd card and it slows my system down, which is a shame as it was working so well didn't have any problems till you reverted back to using the plugin location to store information for local playback Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted May 24, 2015 Share Posted May 24, 2015 I don't think it's constantly pulling data, it's more the fact that it was still writing information to your database at the moment of playback. This stops when the information is fully set. If you allow it to finish then it would most likely resolve your issue. Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 I don't think it's constantly pulling data, it's more the fact that it was still writing information to your database at the moment of playback. This stops when the information is fully set. If you allow it to finish then it would most likely resolve your issue. That would be for every file that I play I would have to pause it as soon as it started so the database can write the changes that it needs ie the path to the file as you have already stated that's what it does. The problem that no one seems to be grasping is that kodi is getting a Path substitute from the plugin folder before the media is ever played and then changing this path in the database when it goes to play the file where as before there was no path substitute and it just played straight from the file location on my server via smb and no database changes and that are made til the file is finished playing to update the play count and watched status Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 yeah no problem, you should probably do that, just head back to a pre 0.1.0 release to go back to the old way. DB polling will still happen, you may need to roll back the old old addon, the one that does nto sync the DB if you truly want to move away from DB sync issues. I don't have any database sync issues it's the file playbacks from the path substitute in the plugin folder like it was when the Addon first came out and then it was changed to the direct smb path and since then it has worked flawlessly this is what I'm trying to get across I love the Addon and it's the thing I have been waiting for, for a long time I never used the old Addon as it wasn't what I wanted and needed Link to comment Share on other sites More sharing options...
Angelblue05 4130 Posted May 24, 2015 Share Posted May 24, 2015 (edited) Well as null_pointer said you know what you can do. We do not write the path to database when playback starts. However I am super confused about the fact that you have smb path in 0.1.81 when the playback path using plugin:// has been in place since 0.1.0.... Were all the paths smb? or just the first ones? What I see in your log is it looks like the connection dropped right after your initial sync. 15:21:04 T:4780 ERROR: Starting new HTTP connection (1): 192.168.1.140 If you look at these lines too: The plugin:// seems to have responded quickly so the path redirection is not the problem. 15:21:38 T:1156 NOTICE: EMBY PlayUtils -> logMsg : Path exists. 15:21:39 T:1156 NOTICE: EMBY PlayUtils -> logMsg : File is direct playing. 15:21:39 T:4800 NOTICE: DVDPlayer: Opening: smb://USERNAME:PASSWORD@MEDIASERVER-3/TV/The Blacklist/Season 2/The Blacklist - 2x01 - Lord Baltimore.mkv 15:30:34 T:4076 NOTICE: EMBY PlayUtils -> logMsg : Path exists. 15:30:34 T:4076 NOTICE: EMBY PlayUtils -> logMsg : File is direct playing. 15:30:34 T:4800 NOTICE: DVDPlayer: Opening: smb://USERNAME:PASSWORD@MEDIASERVER-3/Movies/Project Almanac (2015)/Project Almanac (2015).mkv It looks like the problem is there. I think the only way to find out what Kodi is doing is if you set back your Emby for Kodi log back to info and enable actual Kodi debug so we see whats holding up when you click the item, and the parameter is returned to the addon. 15:21:29 T:1156 NOTICE: -->Python Interpreter Initialized<-- 15:21:38 T:1156 NOTICE: Parameter string: ?id=d0327f2c125ff96baab3cca2174c781b&mode=play Either way, it's up to you how you want to deal with this, go back or keep trying to help us out to improve the add-on. When I look at your playback later, it seems to have taken 2-3seconds each time. Edited May 24, 2015 by Angelblue05 Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 hi i have just done a clean install of your addon on my pi2, i deleted all current databases, and i have just gone to play avatar and it took longer then 10 seconds to play please find attached log file https://dl.dropboxusercontent.com/u/8871364/Captures/kodi%2024-05-2015.log also here is the part of the log stating the initial play of the video showing, also the sync update and then me stopping it and it running the update again 14:10:12 T:1956884480 DEBUG: OnPlayMedia plugin://plugin.video.emby/movies/dbb6d7af2127fda91ccb63a2f9e24dc8/?id=dbb6d7af2127fda91ccb63a2f9e24dc8&mode=play 14:10:12 T:1956884480 DEBUG: CAnnouncementManager - Announcement: OnAdd from xbmc 14:10:12 T:1956884480 DEBUG: GOT ANNOUNCEMENT, type: 2, from xbmc, message OnAdd 14:10:12 T:1956884480 DEBUG: StartScript - calling plugin Emby('plugin://plugin.video.emby/movies/dbb6d7af2127fda91ccb63a2f9e24dc8/','1','?id=dbb6d7af2127fda91ccb63a2f9e24dc8&mode=play') 14:10:12 T:1494217760 NOTICE: Thread LanguageInvoker start, auto delete: false 14:10:12 T:1956884480 DEBUG: WaitOnScriptResult - waiting on the Emby (id=9) plugin... 14:10:12 T:1494217760 INFO: initializing python engine. 14:10:12 T:1494217760 DEBUG: CPythonInvoker(9, /home/osmc/.kodi/addons/Emby.Kodi-master/default.py): start processing 14:10:12 T:1863316512 DEBUG: PushCecKeypress - received key b duration 77 14:10:12 T:1494217760 NOTICE: -->Python Interpreter Initialized<-- 14:10:12 T:1494217760 DEBUG: CPythonInvoker(9, /home/osmc/.kodi/addons/Emby.Kodi-master/default.py): the source file to load is "/home/osmc/.kodi/addons/Emby.Kodi-master/default.py" 14:10:12 T:1494217760 DEBUG: CPythonInvoker(9, /home/osmc/.kodi/addons/Emby.Kodi-master/default.py): setting the Python path to /home/osmc/.kodi/addons/Emby.Kodi-master:/home/osmc/.kodi/addons/script.module.requests/lib:/usr/lib/python2.7:/usr/lib/python2.7/plat-arm-linux-gnueabihf:/usr/lib/python2.7/lib-tk:/usr/lib/python2.7/lib-old:/usr/lib/python2.7/lib-dynload:/usr/local/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages:/usr/lib/python2.7/dist-packages/PILcompat:/usr/lib/python2.7/dist-packages/gtk-2.0 14:10:12 T:1494217760 DEBUG: CPythonInvoker(9, /home/osmc/.kodi/addons/Emby.Kodi-master/default.py): entering source directory /home/osmc/.kodi/addons/Emby.Kodi-master 14:10:12 T:1494217760 DEBUG: CPythonInvoker(9, /home/osmc/.kodi/addons/Emby.Kodi-master/default.py): instantiating addon using automatically obtained id of "plugin.video.emby" dependent on version 2.1.0 of the xbmc.python api 14:10:13 T:1494217760 NOTICE: Parameter string: ?id=dbb6d7af2127fda91ccb63a2f9e24dc8&mode=play 14:10:13 T:1494217760 NOTICE: PLAY Called 14:10:13 T:1494217760 NOTICE: EMBY PlayUtils -> File is direct playing. 14:10:13 T:1956884480 DEBUG: WaitOnScriptResult- plugin returned successfully 14:10:13 T:1494217760 INFO: CPythonInvoker(9, /home/osmc/.kodi/addons/Emby.Kodi-master/default.py): script successfully run 14:10:13 T:1956884480 DEBUG: Loading settings for smb://scott:password@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers(smb://USERNAME:PASSWORD@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv) 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: system rules 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: matches rule: system rules 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtv 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: hdhomerun/myth/mms/udp 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: lastfm/shout 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtmp 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: rtsp 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: streams 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvd 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: dvdimage 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: sdp/asf 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: nsv 14:10:13 T:1956884480 DEBUG: CPlayerSelectionRule::GetPlayers: considering rule: radio 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers: matched 0 rules with players 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers: adding videodefaultplayer (1) 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=0 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers: for video=1, audio=1 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers: adding player: DVDPlayer (1) 14:10:13 T:1956884480 DEBUG: CPlayerCoreFactory::GetPlayers: added 1 players 14:10:13 T:1956884480 NOTICE: DVDPlayer: Opening: smb://USERNAME:PASSWORD@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv 14:10:13 T:1956884480 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED 14:10:13 T:1956884480 DEBUG: CMMALRenderer::CMMALRenderer 14:10:13 T:1956884480 DEBUG: CRenderManager::UpdateDisplayLatency - Latency set to 0 msec 14:10:13 T:1956884480 DEBUG: CMMALRenderer::UnInit 14:10:13 T:1956884480 DEBUG: CMMALRenderer::PreInit 14:10:13 T:1387258912 NOTICE: Thread CMMALRenderer start, auto delete: false 14:10:13 T:1378870304 NOTICE: Thread DVDPlayer start, auto delete: false 14:10:13 T:1378870304 NOTICE: Creating InputStream 14:10:13 T:1378870304 DEBUG: CSMBFile::Open - opened x$/Kids movies/Avatar (2009)/Avatar (2009).mkv, fd=10000 14:10:13 T:1494217760 INFO: Python script stopped 14:10:13 T:1494217760 DEBUG: Thread LanguageInvoker 1494217760 terminating 14:10:13 T:1378870304 DEBUG: ScanForExternalSubtitles: Searching for subtitles... 14:10:13 T:1956884480 DEBUG: ------ Window Init (DialogBusy.xml) ------ 14:10:19 T:1595200544 DEBUG: script.module.osmcsetting.updates : - blurp 52 - DialogBusy.xml 14:10:40 T:1523373088 DEBUG: Thread JobWorker 1523373088 terminating (autodelete) 14:10:40 T:1460663328 DEBUG: Thread JobWorker 1460663328 terminating (autodelete) 14:10:41 T:1956884480 DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-arm.so) 14:10:41 T:1956884480 DEBUG: Unloading: /ImageLib-arm.so 14:10:54 T:1863316512 DEBUG: PushCecKeypress - received key ea duration 0 14:10:54 T:1956884480 DEBUG: OnKey: 234 (0xea) pressed, action is PlayPause 14:10:54 T:1863316512 DEBUG: PushCecKeypress - received key ea duration 77 14:11:09 T:1595200544 DEBUG: script.module.osmcsetting.updates : - blurp 52 - DialogBusy.xml 14:11:12 T:1378870304 DEBUG: ScanForExternalSubtitles: END (total time: 59553 ms) 14:11:12 T:1378870304 NOTICE: Creating Demuxer 14:11:12 T:1378870304 DEBUG: Open - probing detected format [matroska,webm] 14:11:12 T:1378870304 DEBUG: Open - avformat_find_stream_info starting 14:11:13 T:1378870304 DEBUG: Open - av_find_stream_info finished 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Input #0, matroska,webm, from 'smb://scott:password@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv': 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: encoder : mkv2rls v1.2 (date: 2010 febr 17) 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Duration: 02:41:41.65, start: 0.000000, bitrate: 9674 kb/s 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.0: start 0.000000, end 377.961000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:00:00.000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.1: start 377.961000, end 473.598000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:06:17.961 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.2: start 473.598000, end 724.891000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:07:53.598 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.3: start 724.891000, end 840.465000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:12:04.891 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.4: start 840.465000, end 1200.574000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:14:00.465 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.5: start 1200.574000, end 1440.230000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:20:00.574 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.6: start 1440.230000, end 1613.278000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:24:00.230 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.7: start 1613.278000, end 1901.900000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:26:53.278 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.8: start 1901.900000, end 2013.428000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:31:41.900 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.9: start 2013.428000, end 2143.850000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:33:33.428 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.10: start 2143.850000, end 2611.859000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:35:43.850 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.11: start 2611.859000, end 2963.627000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:43:31.859 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.12: start 2963.627000, end 3269.975000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:49:23.627 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.13: start 3269.975000, end 3596.051000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:54:29.975 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.14: start 3596.051000, end 3910.198000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 00:59:56.051 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.15: start 3910.198000, end 4296.417000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:05:10.198 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.16: start 4296.417000, end 4511.006000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:11:36.417 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.17: start 4511.006000, end 4829.116000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:15:11.006 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.18: start 4829.116000, end 5081.910000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:20:29.116 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.19: start 5081.910000, end 5764.801000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:24:41.910 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.20: start 5764.801000, end 5875.786000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:36:04.801 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.21: start 5875.786000, end 6273.100000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:37:55.786 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.22: start 6273.100000, end 6495.489000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:44:33.100 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.23: start 6495.489000, end 6833.868000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:48:15.489 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.24: start 6833.868000, end 6932.884000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:53:53.868 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.25: start 6932.884000, end 7118.820000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:55:32.884 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.26: start 7118.820000, end 7325.568000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 01:58:38.820 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.27: start 7325.568000, end 7533.859000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:02:05.568 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.28: start 7533.859000, end 7801.835000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:05:33.859 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.29: start 7801.835000, end 8167.284000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:10:01.835 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.30: start 8167.284000, end 8390.841000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:16:07.284 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.31: start 8390.841000, end 8750.325000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:19:50.841 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.32: start 8750.325000, end 9074.065000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:25:50.325 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.33: start 9074.065000, end 9305.296000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:31:14.065 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Chapter #0.34: start 9305.296000, end 9701.651000 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : 02:35:05.296 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Stream #0:0(eng): Video: h264 (High), yuv420p, 1920x1080, SAR 1:1 DAR 16:9, 23.98 fps, 23.98 tbr, 1k tbn, 47.95 tbc (default) 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Stream #0:1(eng): Audio: dts (DTS), 48000 Hz, 5.1(side), fltp, 1536 kb/s (default) 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : English DTS 1509kbps 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Stream #0:2(eng): Subtitle: subrip (forced) 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : English 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Stream #0:3(eng): Subtitle: subrip 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: Metadata: 14:11:13 T:1378870304 INFO: ffmpeg[522FE420]: title : English 14:11:13 T:1378870304 DEBUG: CDVDDemuxFFmpeg::AddStream(0, ...) -> 0 14:11:13 T:1378870304 DEBUG: CDVDDemuxFFmpeg::AddStream(1, ...) -> 1 14:11:13 T:1378870304 DEBUG: CDVDDemuxFFmpeg::AddStream(2, ...) -> 2 14:11:13 T:1378870304 DEBUG: CDVDDemuxFFmpeg::AddStream(3, ...) -> 3 14:11:13 T:1378870304 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.clock input port 80 output port 81 m_handle 0x741dbcd0 14:11:13 T:1378870304 DEBUG: OMXClock::OMXStop 14:11:13 T:1378870304 DEBUG: OMXClock::OMXSetSpeed(0.00) pause_resume:1 14:11:13 T:1378870304 NOTICE: Opening stream: 0 source: 256 14:11:13 T:1378870304 DEBUG: DllBcm: Using omx system library 14:11:13 T:1378870304 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_decode input port 130 output port 131 m_handle 0x741f5410 14:11:13 T:1378870304 DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.video_decode) - port(130), nBufferCountMin(1), nBufferCountActual(120), nBufferSize(81920), nBufferAlignmen(16) 14:11:13 T:1378870304 DEBUG: COMXVideo::Open - decoder_component(0x0x741f5410), input_port(0x82), output_port(0x83) deinterlace 1 hdmiclocksync 0 14:11:13 T:1378870304 INFO: OMXPlayerVideo::OpenDecoder : Video codec omx-h264 width 1920 height 1080 profile 100 fps 23.976025 14:11:13 T:1378870304 NOTICE: Creating video thread 14:11:13 T:1378870304 NOTICE: Opening stream: 1 source: 256 14:11:13 T:1460663328 NOTICE: Thread OMXPlayerVideo start, auto delete: false 14:11:13 T:1460663328 DEBUG: COMXPlayerVideo - CDVDMsg::PLAYER_STARTED 0 14:11:13 T:1378870304 NOTICE: Creating audio thread 14:11:13 T:1460663328 DEBUG: COMXPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE 14:11:13 T:1378870304 NOTICE: Opening stream: 2 source: 256 14:11:13 T:1523373088 NOTICE: Thread OMXPlayerAudio start, auto delete: false 14:11:13 T:1378870304 DEBUG: FactoryCodec - Overlay: Text Subtitle Decoder - Opening 14:11:13 T:1378870304 DEBUG: FactoryCodec - Overlay: Text Subtitle Decoder - Opened 14:11:13 T:1523373088 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_STARTED 0 14:11:13 T:1523373088 DEBUG: COMXPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE 14:11:13 T:1378870304 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: smb://scott:password@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv 14:11:13 T:1378870304 DEBUG: OnPlayBackStarted: play state was 1, starting 1 14:11:13 T:1378870304 DEBUG: CDVDPlayer::SetCaching - caching state 3 14:11:13 T:1460663328 DEBUG: COMXPlayerVideo - CDVDMsg::PLAYER_SETSPEED 0 14:11:13 T:1460663328 DEBUG: COMXPlayerVideo - CDVDMsg::PLAYER_STARTED 0 14:11:13 T:1523373088 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 0 14:11:13 T:1523373088 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_STARTED 0 14:11:13 T:1460663328 INFO: COMXPlayerVideo - Stillframe left, switching to normal playback 14:11:13 T:1460663328 DEBUG: OMXVideo::Decode VDec : setStartTime 0.000000 14:11:13 T:1460663328 INFO: Output - renderer not started 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages - player started 2 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages player started 2 (s:1000 a:0 v:1) 14:11:13 T:1523373088 DEBUG: COMXAudioCodecOMX::Decode(0x4fd11120,2012) format=8(8) chan=6 samples=512 size=2048 data=0x556f84b0,0x6fdd8d60,0x6fda7340,0x5a1cd750,0x6fd0f660,0x6fd20200,(nil),(nil) 14:11:13 T:1523373088 DEBUG: COMXAudioCodecOMX::GetData size=12288/12288 line=2048/2048 buf=0x55638560, desired=49152 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages - player started 1 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages player started RESET 14:11:13 T:1378870304 NOTICE: OMXClock using audio as reference 14:11:13 T:1378870304 DEBUG: OMXClock::OMXReset audio / video : 1 / 1 wait mask 0->3 state : 2->1 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages player started 1 (s:1000 a:1 v:1) 14:11:13 T:1378870304 DEBUG: CDVDPlayer::SetCaching - caching state 4 14:11:13 T:1523373088 DEBUG: COMXPlayerAudio - CDVDMsg::PLAYER_SETSPEED 1000 14:11:13 T:1460663328 DEBUG: COMXPlayerVideo - CDVDMsg::PLAYER_SETSPEED 1000 14:11:13 T:1523373088 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(-4503599627370496.000000, 10000.000000, 1) 14:11:13 T:1460663328 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(-4503599627370496.000000, 0) 14:11:13 T:1460663328 INFO: Output - renderer not started 14:11:13 T:1523373088 INFO: Previous line repeats 3 times. 14:11:13 T:1523373088 DEBUG: COMXAudio::SetCodingType OMX_AUDIO_CodingPCM 14:11:13 T:1523373088 DEBUG: COMXAudio:SetAudioProps hdmi_stream_channels 0 hdmi_channel_map 0b02c4c8 14:11:13 T:1523373088 INFO: COMXAudio::Initialize remap:(nil) chan:6->6 norm:0 upmix:0 60f:3f 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 1.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 0.00 1.00 0.00 0.00 0.00 0.00 0.00 0.00 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 0.00 0.00 1.00 0.00 0.00 0.00 0.00 0.00 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 0.00 0.00 0.00 1.00 0.00 0.00 0.00 0.00 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 0.00 0.00 0.00 0.00 1.00 0.00 0.00 0.00 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 0.00 0.00 0.00 0.00 0.00 1.00 0.00 0.00 14:11:13 T:1523373088 INFO: COMXAudio::Initialize 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 14:11:13 T:1523373088 INFO: Previous line repeats 1 times. 14:11:13 T:1523373088 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_decode input port 120 output port 121 m_handle 0x5a1042f8 14:11:13 T:1460663328 INFO: Output - renderer not started 14:11:13 T:1523373088 INFO: Previous line repeats 3 times. 14:11:13 T:1523373088 DEBUG: COMXCoreComponent::AllocInputBuffers component(OMX.broadcom.audio_decode) - port(120), nBufferCountMin(4), nBufferCountActual(16), nBufferSize(49152), nBufferAlignmen(16) 14:11:13 T:1460663328 INFO: Output - renderer not started 14:11:13 T:1956884480 INFO: Previous line repeats 3 times. 14:11:13 T:1956884480 DEBUG: ------ Window Init (VideoOverlay.xml) ------ 14:11:13 T:1956884480 INFO: Loading skin file: VideoOverlay.xml, load type: KEEP_IN_MEMORY 14:11:13 T:1523373088 DEBUG: COMXAudio::Initialize Input bps 32 samplerate 48000 channels 6 buffer size 2304000 bytes per second 1152000 14:11:13 T:1523373088 DEBUG: pcm->direction : input 14:11:13 T:1523373088 DEBUG: pcm->nPortIndex : 0 14:11:13 T:1523373088 DEBUG: pcm->eNumData : 0 14:11:13 T:1523373088 DEBUG: pcm->eEndian : 1 14:11:13 T:1523373088 DEBUG: pcm->bInterleaved : 1 14:11:13 T:1523373088 DEBUG: pcm->nBitPerSample : 32 14:11:13 T:1523373088 DEBUG: pcm->ePCMMode : 0 14:11:13 T:1523373088 DEBUG: pcm->nChannels : 6 14:11:13 T:1523373088 DEBUG: pcm->nSamplingRate : 48000 14:11:13 T:1523373088 DEBUG: COMXAudio::Initialize device passthrough 0 hwdecode 0 14:11:13 T:1523373088 INFO: Audio codec channels 6 samplerate 48000 bitspersample 16 14:11:13 T:1523373088 DEBUG: COMXAudio::Decode ADec : setStartTime 0.000000 14:11:13 T:1523373088 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_mixer input port 232 output port 231 m_handle 0x55f9d5b0 14:11:13 T:1523373088 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.audio_render input port 100 output port 100 m_handle 0x5a132370 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=0.00 (* 1000.00 * 0.00) 14:11:13 T:1523373088 DEBUG: COMXAudio::PortSettingsChanged - Output bps 16 samplerate 48000 channels 8 buffer size 2304000 bytes per second 768000 14:11:13 T:1523373088 DEBUG: pcm->direction : output 14:11:13 T:1523373088 DEBUG: pcm->nPortIndex : 231 14:11:13 T:1523373088 DEBUG: pcm->eNumData : 0 14:11:13 T:1523373088 DEBUG: pcm->eEndian : 1 14:11:13 T:1523373088 DEBUG: pcm->bInterleaved : 1 14:11:13 T:1523373088 DEBUG: pcm->nBitPerSample : 16 14:11:13 T:1523373088 DEBUG: pcm->ePCMMode : 0 14:11:13 T:1523373088 DEBUG: pcm->nChannels : 8 14:11:13 T:1523373088 DEBUG: pcm->nSamplingRate : 48000 14:11:13 T:1523373088 DEBUG: COMXAudio::PortSettingsChanged - bits:32 mode:0 channels:6 srate:48000 nopassthrough 14:11:13 T:1460663328 INFO: Output - renderer not started 14:11:13 T:1460663328 INFO: Previous line repeats 11 times. 14:11:13 T:1460663328 DEBUG: COMXVideo::PortSettingsChanged - 1920x1080@23.98 interlace:0 deinterlace:0 14:11:13 T:1460663328 DEBUG: ResolutionUpdateCallBack - change configuration. video:1920x1080. framerate: 23.98. 1920x1080 format: BYPASS 14:11:13 T:1460663328 DEBUG: CMMALRenderer::Configure - 1920x1080->1920x1080@23.98 flags:10 format:14 ext:0 orient:0 14:11:13 T:1460663328 NOTICE: Display resolution USER : 1920x1080 (1920x1080) @ 59.94 - Full Screen (23) 14:11:13 T:1460663328 DEBUG: CXBMCRenderManager::Configure - 3 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=0.00 (* 1000.00 * 0.00) 14:11:13 T:1956884480 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1460663328 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_render input port 90 output port 90 m_handle 0x5501ee98 14:11:13 T:1956884480 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1956884480 DEBUG: Activating window ID: 12005 14:11:13 T:1460663328 DEBUG: COMXCoreComponent::Initialize OMX.broadcom.video_scheduler input port 10 output port 11 m_handle 0x54cff6b0 14:11:13 T:1956884480 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------ 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1523373088 INFO: COMXPlayerAudio - Switching to normal playback 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages - player started 1 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages player started RESET 14:11:13 T:1378870304 DEBUG: CDVDPlayer::HandleMessages player started 1 (s:1000 a:1 v:1) 14:11:13 T:1378870304 DEBUG: CDVDPlayer::SetCaching - caching state 0 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1956884480 DEBUG: ------ Window Init (VideoFullScreen.xml) ------ 14:11:13 T:1956884480 INFO: Loading skin file: VideoFullScreen.xml, load type: KEEP_IN_MEMORY 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1378870304 DEBUG: CDVDPlayer::OMXDoProcessing Resume 0.36,1.45 (A:01 V:01) EOF:0 FULL:0 T:0.20 14:11:13 T:1378870304 DEBUG: OMXClock::OMXSetSpeed(1.00) pause_resume:1 14:11:13 T:1956884480 DEBUG: PlayFile: OpenFile succeed, play state 2 14:11:13 T:1956884480 DEBUG: OnPlayBackStarted: play state was 2, starting 0 14:11:13 T:1956884480 DEBUG: ------ Window Deinit (VideoOverlay.xml) ------ 14:11:13 T:1956884480 DEBUG: OMXPlayerVideo::SetVideoRect 0,0,1920,1080 -> 47,28,1873,1055 (0,0,0,0,mono) 14:11:13 T:1956884480 DEBUG: COMXVideo::SetVideoRect 0,0,1920,1080 -> 47,28,1826,1027 mode:1 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1956884480 DEBUG: CGUIInfoManager::SetCurrentMovie(smb://USERNAME:PASSWORD@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1956884480 INFO: Previous line repeats 3 times. 14:11:13 T:1956884480 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc 14:11:13 T:1956884480 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1561383968 NOTICE: EMBY Player -> onPlayBackStarted: smb://scott:password@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:13 T:1523373088 INFO: Previous line repeats 19 times. 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.32) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.37) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.41) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.33) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.20) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.12) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.06) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.03) 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.02) 14:11:13 T:1523373088 INFO: Previous line repeats 3 times. 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:13 T:1956884480 INFO: Previous line repeats 47 times. 14:11:13 T:1956884480 DEBUG: ------ Window Deinit (DialogBusy.xml) ------ 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:13 T:1561383968 INFO: Previous line repeats 11 times. 14:11:13 T:1561383968 NOTICE: EMBY Player -> Sending POST play started. 14:11:13 T:1362093088 NOTICE: EMBY WebSocketThread -> 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","Mute","Unmute","SetVolume","Play","Playstate","PlayNext"],"QueueableMediaTypes":["Video"],"PlayableMediaTypes":["Audio","Video"],"Id":"167a004eb84b5ee206ddbdac4d6cbe47","UserId":"bd22e3af178580034fb62751dfc2cdbe","UserPrimaryImageTag":"efec01a4cf132f783b9958e8b11ff9bf","UserName":"scott","AdditionalUsers":[],"ApplicationVersion":"0.1.91","Client":"Kodi","LastActivityDate":"2015-05-24T14:11:11.8187422Z","DeviceName":"Kodi Lounge","NowPlayingItem":{"Name":"Avatar","Id":"dbb6d7af2127fda91ccb63a2f9e24dc8","Type":"Movie","MediaType":"Video","RunTimeTicks":97016510000,"PrimaryImageTag":"e9a1c94a41785d3b0bdf4841f7beeaed","PrimaryImageItemId":"dbb6d7af2127fda91ccb63a2f9e24dc8","LogoImageTag":"bbbfe21edd6e64d3d0c8b21257857d6c","LogoItemId":"dbb6d7af2127fda91ccb63a2f9e24dc8","BackdropImageTag":"44be64034e95ffcd7bd68e1395625282","BackdropItemId":"dbb6d7af2127fda91ccb63a2f9e24dc8","ProductionYear":2009,"Artists":[],"MediaStreams":[{"Codec":"h264","Language":"eng","IsInterlaced":false,"BitRate":9674075,"BitDepth":8,"RefFrames":4,"IsDefault":true,"IsForced":false,"Height":1080,"Width":1920,"AverageFrameRate":23.97602,"RealFrameRate":23.97602,"Profile":"High","Type":"Video","AspectRatio":"16:9","Index":0,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"PixelFormat":"yuv420p","Level":41,"IsAnamorphic":false,"IsCabac":true},{"Codec":"dca","Language":"eng","IsInterlaced":false,"ChannelLayout":"5.1","BitRate":1536000,"Channels":6,"SampleRate":48000,"IsDefault":true,"IsForced":false,"Profile":"DTS","Type":"Audio","Index":1,"IsExternal":false,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Level":0},{"Codec":"srt","Language":"eng","IsInterlaced":false,"IsDefault":false,"IsForced":true,"Type":"Subtitle","Index":2,"IsExternal":false,"IsTextSubtitleStream":true,"SupportsExternalStream":true,"Level":0},{"Codec":"srt","Language":"eng","IsInterlaced":false,"IsDefault":false,"IsForced":false,"Type":"Subtitle","Index":3,"IsExternal":false,"IsTextSubtitleStream":true,"SupportsExternalStream":true,"Level":0}],"ChapterImagesItemId":"dbb6d7af2127fda91ccb63a2f9e24dc8","Chapters":[{"StartPositionTicks":0,"Name":"Chapter 1","ImageTag":"b0940280f2a86edd640355eb5c1f863e"},{"StartPositionTicks":3779610000,"Name":"Chapter 2","ImageTag":"9c86891e6cb1da57aad1dfce0338e809"},{"StartPositionTicks":4735980000,"Name":"Chapter 3","ImageTag":"ecf834d3945aafedd6c3addeff57b5c5"},{"StartPositionTicks":7248910000,"Name":"Chapter 4","ImageTag":"ecf0b56ff8b61af85e1d1330adaec0d1"},{"StartPositionTicks":8404650000,"Name":"Chapter 5","ImageTag":"ca43a710687472e45ec3b66bdc23ee32"},{"StartPositionTicks":12005740000,"Name":"Chapter 6","ImageTag":"6e46c02d43a2c6b140ee499573c07664"},{"StartPositionTicks":14402300000,"Name":"Chapter 7","ImageTag":"c5f564cd47e02022794526adb6bf0192"},{"StartPositionTicks":16132780000,"Name":"Chapter 8","ImageTag":"ea02be48dcaffde068297eae7ae15ef7"},{"StartPositionTicks":19019000000,"Name":"Chapter 9","ImageTag":"26fe86effb82f6c901adc1ae081ea0fd"},{"StartPositionTicks":20134280000,"Name":"Chapter 10","ImageTag":"98d04fa4eede535f0343ca245128c357"},{"StartPositionTicks":21438500000,"Name":"Chapter 11","ImageTag":"313a2ff1ca11aa6f00ef9ecb4048d529"},{"StartPositionTicks":26118590000,"Name":"Chapter 12","ImageTag":"6f971c3e0fb49d330e83e02f648c0aac"},{"StartPositionTicks":29636270000,"Name":"Chapter 13","ImageTag":"1ccd84b49f7899c56333398313f01c2c"},{"StartPositionTicks":32699750000,"Name":"Chapter 14","ImageTag":"7ae2e1b1d77a92d2b16d2c99e63ca4b4"},{"StartPositionTicks":35960510000,"Name":"Chapter 15","ImageTag":"4358bdc63ae6a1ad8763be18fdfaf550"},{"StartPositionTicks":39101980000,"Name":"Chapter 16","ImageTag":"a9b8694407d6439e28e65df987c01c8d"},{"StartPositionTicks":42964170000,"Name":"Chapter 17","ImageTag":"323dc61ab6029165c81eefa79bae5ca3"},{"StartPositionTicks":45110060000,"Name":"Chapter 18","ImageTag":"cc73eb2c6dc1a52fdeb0585c75eba4ff"},{"StartPositionTicks":48291160000,"Name":"Chapter 19","ImageTag":"76571aed6acfa9824c6dab6f7e48a922"},{"StartPositionTicks":50819100000,"Name":"Chapter 20","ImageTag":"fb43afcd176ba24e11434513bbe4da61"},{"StartPositionTicks":57648010000,"Name":"Chapter 21","ImageTag":"ac25ff1aeedf1bc8fcff4a9135aec07b"},{"StartPositionTicks":58757860000,"Name":"Chapter 22","ImageTag":"0aaee5e40883aa4b1947ac6f30eab984"},{"StartPositionTicks":62731000000,"Name":"Chapter 23","ImageTag":"91d87234335588e6529340e9fe73c16e"},{"StartPositionTicks":64954890000,"Name":"Chapter 24","ImageTag":"4c64beb7af92e6d788fcf46e449a57c7"},{"StartPositionTicks":68338680000,"Name":"Chapter 25","ImageTag":"0fafd14135489897e06fc579d64890e6"},{"StartPositionTicks":69328840000,"Name":"Chapter 26","ImageTag":"b1fe430cabfee1a88cc29c286ed08d7e"},{"StartPositionTicks":71188200000,"Name":"Chapter 27","ImageTag":"d0de176a5fa6305a79081d5ee035ac4c"},{"StartPositionTicks":73255680000,"Name":"Chapter 28","ImageTag":"76358bf332e82cf11e10dcb55a7479e2"},{"StartPositionTicks":75338590000,"Name":"Chapter 29","ImageTag":"4ed92a908124900749691b461bf0889d"},{"StartPositionTicks":78018350000,"Name":"Chapter 30","ImageTag":"ebbdec58917a0ec33522aa31a502fd72"},{"StartPositionTicks":81672840000,"Name":"Chapter 31","ImageTag":"a9d479939301baf5fed151902aa054ed"},{"StartPositionTicks":83908410000,"Name":"Chapter 32","ImageTag":"37688fcb28300ae6169910c2b131b55d"},{"StartPositionTicks":87503250000,"Name":"Chapter 33","ImageTag":"a94f045e79c767d02caf3dbc9ff767c1"},{"StartPositionTicks":90740650000,"Name":"Chapter 34","ImageTag":"7370aca979e8a0dcffb31b91d5df974c"},{"StartPositionTicks":93052960000,"Name":"Chapter 35","ImageTag":"3d3bde3cf780fbc9ed34ec9bc868d03c"}]},"DeviceId":"E4F75B40B26E47498C620071CB917F6E","SupportsRemoteControl":true,"PlayState":{"PositionTicks":0,"CanSeek":true,"IsPaused":false,"IsMuted":false,"AudioStreamIndex":1,"SubtitleStreamIndex":2,"MediaSourceId":"dbb6d7af2127fda91ccb63a2f9e24dc8","PlayMethod":"DirectPlay"}}} 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:13 T:1561383968 INFO: Previous line repeats 2 times. 14:11:13 T:1561383968 NOTICE: EMBY Player -> ADDING_FILE: {'smb://scott:password@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv': {'refresh_id': 'dbb6d7af2127fda91ccb63a2f9e24dc8', 'AudioStreamIndex': '1', 'SubtitleStreamIndex': '2', 'currentPosition': 0, 'item_id': 'dbb6d7af2127fda91ccb63a2f9e24dc8', 'currentfile': 'smb://scott:password@MEDIASERVER/x$/Kids movies/Avatar (2009)/Avatar (2009).mkv', 'runtime': '97016510000', 'Type': 'Movie', 'playmethod': 'DirectPlay'}} 14:11:13 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:14 T:1362093088 INFO: Previous line repeats 9 times. 14:11:14 T:1362093088 NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"UserDataChanged","Data":{"UserId":"bd22e3af178580034fb62751dfc2cdbe","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":1,"IsFavorite":false,"LastPlayedDate":"2015-05-24T14:11:11.8187422Z","Played":false,"Key":"19995","ItemId":"dbb6d7af2127fda91ccb63a2f9e24dc8"},{"PlayedPercentage":1.77514792899408,"UnplayedItemCount":166,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":false,"Key":"1756a1b1-9c82-088a-a8d2-fd407f0bc90d","ItemId":"1756a1b19c82088aa8d2fd407f0bc90d"}]}} 14:11:14 T:1362093088 NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged 14:11:14 T:1362093088 NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : UserDataList : [{u'ItemId': u'dbb6d7af2127fda91ccb63a2f9e24dc8', u'IsFavorite': False, u'Played': False, u'LastPlayedDate': u'2015-05-24T14:11:11.8187422Z', u'PlaybackPositionTicks': 0, u'Key': u'19995', u'PlayCount': 1}, {u'ItemId': u'1756a1b19c82088aa8d2fd407f0bc90d', u'IsFavorite': False, u'Played': False, u'PlayedPercentage': 1.77514792899408, u'UnplayedItemCount': 166, u'PlaybackPositionTicks': 0, u'Key': u'1756a1b1-9c82-088a-a8d2-fd407f0bc90d', u'PlayCount': 0}] 14:11:14 T:1362093088 NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : Processing Updated : [u'dbb6d7af2127fda91ccb63a2f9e24dc8', u'1756a1b19c82088aa8d2fd407f0bc90d'] 14:11:14 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:14 T:1956884480 INFO: Previous line repeats 1 times. 14:11:14 T:1956884480 DEBUG: ------ Window Init (DialogKaiToast.xml) ------ 14:11:14 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:14 T:1561383968 INFO: Previous line repeats 11 times. 14:11:14 T:1561383968 NOTICE: EMBY WebSocketThread -> sendProgressUpdate 14:11:14 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:15 T:1362093088 INFO: Previous line repeats 11 times. 14:11:15 T:1362093088 NOTICE: UPDATE movie to Kodi library -> Id: dbb6d7af2127fda91ccb63a2f9e24dc8 - Title: Avatar 14:11:15 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:19 T:1561383968 INFO: Previous line repeats 84 times. 14:11:19 T:1561383968 NOTICE: EMBY WebSocketThread -> sendProgressUpdate 14:11:19 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:20 T:1494217760 INFO: Previous line repeats 25 times. 14:11:20 T:1494217760 NOTICE: Thread VideoInfoScanner start, auto delete: false 14:11:20 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:20 T:1956884480 INFO: Previous line repeats 3 times. 14:11:20 T:1956884480 DEBUG: ------ Window Init (DialogExtendedProgressBar.xml) ------ 14:11:20 T:1494217760 NOTICE: VideoInfoScanner: Starting scan .. 14:11:20 T:1494217760 DEBUG: CAnnouncementManager - Announcement: OnScanStarted from xbmc 14:11:20 T:1494217760 DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanStarted 14:11:20 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:20 T:1956884480 INFO: Previous line repeats 6 times. 14:11:20 T:1956884480 DEBUG: ------ Window Deinit (DialogKaiToast.xml) ------ 14:11:20 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:20 T:1494217760 INFO: Previous line repeats 1 times. 14:11:20 T:1494217760 NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00 14:11:20 T:1494217760 DEBUG: CAnnouncementManager - Announcement: OnScanFinished from xbmc 14:11:20 T:1494217760 DEBUG: GOT ANNOUNCEMENT, type: 16, from xbmc, message OnScanFinished 14:11:20 T:1494217760 DEBUG: Thread VideoInfoScanner 1494217760 terminating 14:11:20 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:20 T:1956884480 INFO: Previous line repeats 2 times. 14:11:20 T:1956884480 DEBUG: ------ Window Deinit (DialogExtendedProgressBar.xml) ------ 14:11:20 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:21 T:1569772576 INFO: Previous line repeats 22 times. 14:11:21 T:1569772576 DEBUG: RunQuery took 5 ms for 0 items query: select * from movieview WHERE (movieview.idFile IN (SELECT DISTINCT idFile FROM bookmark WHERE type = 1)) 14:11:21 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:21 T:1586811936 DEBUG: RunQuery took 12 ms for 0 items query: select * from movieview WHERE (movieview.idFile IN (SELECT DISTINCT idFile FROM bookmark WHERE type = 1)) 14:11:21 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.01) 14:11:22 T:1523373088 INFO: Previous line repeats 2 times. 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 DEBUG: RunQuery took 177 ms for 24 items query: SELECT * FROM tvshowview WHERE ( ((tvshowview.watchedcount > 0 AND tvshowview.watchedcount < tvshowview.totalCount) OR (tvshowview.watchedcount = 0 AND EXISTS (SELECT 1 FROM episodeview WHERE episodeview.idShow = tvshowview.idShow AND episodeview.resumeTimeInSeconds > 0)))) 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1586811936 DEBUG: RunQuery took 192 ms for 24 items query: SELECT * FROM tvshowview WHERE ( ((tvshowview.watchedcount > 0 AND tvshowview.watchedcount < tvshowview.totalCount) OR (tvshowview.watchedcount = 0 AND EXISTS (SELECT 1 FROM episodeview WHERE episodeview.idShow = tvshowview.idShow AND episodeview.resumeTimeInSeconds > 0)))) 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 INFO: Previous line repeats 1 times. 14:11:22 T:1569772576 DEBUG: RunQuery took 11 ms for 49 items query: select * from episodeview WHERE (episodeview.idShow = 107) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1586811936 INFO: Previous line repeats 1 times. 14:11:22 T:1586811936 DEBUG: RunQuery took 15 ms for 49 items query: select * from episodeview WHERE (episodeview.idShow = 107) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:22 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 DEBUG: RunQuery took 14 ms for 85 items query: select * from episodeview WHERE (episodeview.idShow = 16) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1586811936 INFO: Previous line repeats 1 times. 14:11:22 T:1586811936 DEBUG: RunQuery took 19 ms for 85 items query: select * from episodeview WHERE (episodeview.idShow = 16) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:22 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1569772576 DEBUG: RunQuery took 5 ms for 4 items query: select * from episodeview WHERE (episodeview.idShow = 94) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 INFO: Previous line repeats 2 times. 14:11:22 T:1569772576 DEBUG: RunQuery took 11 ms for 2 items query: select * from episodeview WHERE (episodeview.idShow = 40) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1586811936 DEBUG: RunQuery took 15 ms for 4 items query: select * from episodeview WHERE (episodeview.idShow = 94) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:22 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 INFO: Previous line repeats 1 times. 14:11:22 T:1569772576 DEBUG: RunQuery took 37 ms for 286 items query: select * from episodeview WHERE (episodeview.idShow = 97) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1586811936 DEBUG: RunQuery took 5 ms for 2 items query: select * from episodeview WHERE (episodeview.idShow = 40) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:22 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1586811936 INFO: Previous line repeats 1 times. 14:11:22 T:1586811936 DEBUG: RunQuery took 41 ms for 286 items query: select * from episodeview WHERE (episodeview.idShow = 97) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:22 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 INFO: Previous line repeats 1 times. 14:11:22 T:1569772576 DEBUG: RunQuery took 5 ms for 4 items query: select * from episodeview WHERE (episodeview.idShow = 47) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1569772576 INFO: Previous line repeats 1 times. 14:11:22 T:1569772576 DEBUG: RunQuery took 7 ms for 1 items query: select * from episodeview WHERE (episodeview.idShow = 3) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:22 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:22 T:1586811936 DEBUG: RunQuery took 8 ms for 4 items query: select * from episodeview WHERE (episodeview.idShow = 47) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:22 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:22 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 1 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 11 ms for 19 items query: select * from episodeview WHERE (episodeview.idShow = 62) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1586811936 DEBUG: RunQuery took 11 ms for 1 items query: select * from episodeview WHERE (episodeview.idShow = 3) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1561383968 NOTICE: EMBY WebSocketThread -> sendProgressUpdate 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 DEBUG: RunQuery took 18 ms for 102 items query: select * from episodeview WHERE (episodeview.idShow = 30) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1586811936 DEBUG: RunQuery took 6 ms for 19 items query: select * from episodeview WHERE (episodeview.idShow = 62) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 2 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 5 ms for 1 items query: select * from episodeview WHERE (episodeview.idShow = 33) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1586811936 DEBUG: RunQuery took 17 ms for 102 items query: select * from episodeview WHERE (episodeview.idShow = 30) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 1 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 13 ms for 19 items query: select * from episodeview WHERE (episodeview.idShow = 53) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1586811936 DEBUG: RunQuery took 11 ms for 1 items query: select * from episodeview WHERE (episodeview.idShow = 33) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 1 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 6 ms for 6 items query: select * from episodeview WHERE (episodeview.idShow = 72) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1586811936 DEBUG: RunQuery took 15 ms for 19 items query: select * from episodeview WHERE (episodeview.idShow = 53) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 1 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 12 ms for 10 items query: select * from episodeview WHERE (episodeview.idShow = 76) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1586811936 DEBUG: RunQuery took 10 ms for 6 items query: select * from episodeview WHERE (episodeview.idShow = 72) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 DEBUG: RunQuery took 7 ms for 21 items query: select * from episodeview WHERE (episodeview.idShow = 28) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1586811936 DEBUG: RunQuery took 11 ms for 10 items query: select * from episodeview WHERE (episodeview.idShow = 76) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 1 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 11 ms for 13 items query: select * from episodeview WHERE (episodeview.idShow = 78) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1586811936 DEBUG: RunQuery took 12 ms for 21 items query: select * from episodeview WHERE (episodeview.idShow = 28) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:23 T:1569772576 INFO: Previous line repeats 1 times. 14:11:23 T:1569772576 DEBUG: RunQuery took 16 ms for 40 items query: select * from episodeview WHERE (episodeview.idShow = 37) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:23 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1586811936 DEBUG: RunQuery took 6 ms for 13 items query: select * from episodeview WHERE (episodeview.idShow = 78) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:23 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:23 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1569772576 INFO: Previous line repeats 2 times. 14:11:24 T:1569772576 DEBUG: RunQuery took 12 ms for 19 items query: select * from episodeview WHERE (episodeview.idShow = 60) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:24 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1586811936 DEBUG: RunQuery took 14 ms for 40 items query: select * from episodeview WHERE (episodeview.idShow = 37) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:24 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1569772576 INFO: Previous line repeats 1 times. 14:11:24 T:1569772576 DEBUG: RunQuery took 8 ms for 24 items query: select * from episodeview WHERE (episodeview.idShow = 79) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:24 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1586811936 DEBUG: RunQuery took 7 ms for 19 items query: select * from episodeview WHERE (episodeview.idShow = 60) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:24 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1569772576 INFO: Previous line repeats 2 times. 14:11:24 T:1569772576 DEBUG: RunQuery took 10 ms for 1 items query: select * from episodeview WHERE (episodeview.idShow = 82) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:24 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1586811936 DEBUG: RunQuery took 12 ms for 24 items query: select * from episodeview WHERE (episodeview.idShow = 79) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:24 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1586811936 INFO: Previous line repeats 2 times. 14:11:24 T:1586811936 DEBUG: RunQuery took 6 ms for 1 items query: select * from episodeview WHERE (episodeview.idShow = 82) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:24 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1569772576 DEBUG: RunQuery took 12 ms for 20 items query: select * from episodeview WHERE (episodeview.idShow = 19) AND (((episodeview.playCount IS NULL OR episodeview.playCount < 1))) 14:11:24 T:1569772576 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1586811936 INFO: Previous line repeats 1 times. 14:11:24 T:1586811936 DEBUG: RunQuery took 13 ms for 20 items query: select * from episodeview WHERE (episodeview.idShow = 19) AND (((episodeview.playCount IS NULL OR episodeview.playCount = 0))) 14:11:24 T:1586811936 DEBUG: DatabaseUtils::GetSortFieldList: unknown field 25 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1569772576 INFO: Previous line repeats 1 times. 14:11:24 T:1569772576 DEBUG: RunQuery took 53 ms for 386 items query: select * from movieview WHERE ((movieview.playCount IS NULL OR movieview.playCount < 1)) 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:24 T:1586811936 DEBUG: RunQuery took 47 ms for 386 items query: select * from movieview WHERE ((movieview.playCount IS NULL OR movieview.playCount = 0)) 14:11:24 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:25 T:1569772576 INFO: Previous line repeats 25 times. 14:11:25 T:1569772576 DEBUG: RunQuery took 430 ms for 3951 items query: select * from episodeview WHERE ((episodeview.playCount IS NULL OR episodeview.playCount < 1)) 14:11:25 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:25 T:1586811936 DEBUG: RunQuery took 435 ms for 3951 items query: select * from episodeview WHERE ((episodeview.playCount IS NULL OR episodeview.playCount < 1)) 14:11:25 T:1523373088 INFO: COMXAudio::ApplyVolume - Volume=1.00 (* 1000.00 * 0.00) 14:11:27 T:1561383968 INFO: Previous line repeats 30 times. 14:11:27 T:1561383968 NOTICE: EMBY WebSocketThread -> sendProgressUpdate also once it started playing kodi did a increment database update please see attached photo of the of the change in the database that you have stated it doensn't do yet there it is in the photo after the play of the file so from this it is doing excactly what i have been saying this shows that what i have been saying along is happening, and shows that you guys have been contradicting everything you have been saying regarding this matter 1 Link to comment Share on other sites More sharing options...
CBers 6742 Posted May 24, 2015 Share Posted May 24, 2015 Hopefully this will get sorted soon. There's not a lot more you can do other than wait for the devs to work out a solution. Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 (edited) That is interesting. You definitely do NOT have the path to your TV shows added as source right? Can you check that sources.xml is blank? You seem to be getting very frustrated by this - we are trying to help but don't understand what is going wrong - but we will get it resolved. We are all using this ourselves and are not seeing this - I just checked my own db. xnappo Edited May 24, 2015 by xnappo Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 (edited) That is interesting. You definitely do NOT have the path to your TV shows added as source right? Can you check that sources.xml is blank? You seem to be getting very frustrated by this - we are trying to help but don't understand what is going wrong - but we will get it resolved. We are all using this ourselves and are not seeing this - I just checked my own db. xnappo No there are no sources added to kodi at all. All information comes from the emby server via your add on. The thing is once the path is changed to the smb path in the database the file plays Instantly Edited May 24, 2015 by scalda Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 No there are no sources added to kodi at all. All information comes from the emby server via your add on. The thing is once the path is changed to the smb path in the database the file plays Instantly Oh - so you edited the DB manually, and now it is fast. Yes that makes sense - we need to figure out why going through the Python script is slow. Again, we had to change it to do that to fix a bunch of other problems! Thanks, xnappo 1 Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 Oh - so you edited the DB manually, and now it is fast. Yes that makes sense - we need to figure out why going through the Python script is slow. Again, we had to change it to do that to fix a bunch of other problems! Thanks, xnappo I never edited the database manually your emby addon does itself when a file is first played. Even angleblue stated in one of the previous post that when a file is first played the database gets changed to the direct smb path and then you guys decided that's not what its doing even thou I quoted it a few times, and what I was saying is wrong according to you all Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 That is interesting. You definitely do NOT have the path to your TV shows added as source right? Can you check that sources.xml is blank? You seem to be getting very frustrated by this - we are trying to help but don't understand what is going wrong - but we will get it resolved. We are all using this ourselves and are not seeing this - I just checked my own db. xnappo @@xnappo if this is a view of your database, do you have folders in your plugin folder for all the movies and tv shows? with the id as i don't have folders in mine? Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 No - the ids are now stored in another table in the database instead of the .strm files. Look in the DB viewer at the 'emby' table. I fired up my Pi (which I only use for debugging Pi issues) and I definitely see that it is slow to start playing. I stripped the code down to just the bare minimum needed to start playback, and it gets close to the speed of just having the path. But then.. A bunch of stuff won't work right (resume, artwork during playback, server reporting and control..). So I am not sure what the fix is here - having the direct path causes all sorts of havok because the Kodi DB code tries to take over. xnappo Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 Can a moderator change the title of this thread to: plugin path play slow vs direct smb path play instant Link to comment Share on other sites More sharing options...
CBers 6742 Posted May 24, 2015 Share Posted May 24, 2015 Can a moderator change the title of this thread to: plugin path play slow vs direct smb path play instant Done. Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 (edited) No - the ids are now stored in another table in the database instead of the .strm files. Look in the DB viewer at the 'emby' table. I fired up my Pi (which I only use for debugging Pi issues) and I definitely see that it is slow to start playing. I stripped the code down to just the bare minimum needed to start playback, and it gets close to the speed of just having the path. But then.. A bunch of stuff won't work right (resume, artwork during playback, server reporting and control..). So I am not sure what the fix is here - having the direct path causes all sorts of havok because the Kodi DB code tries to take over. xnappo Then why doesn't it cause havoc once you add on changes the file path in the database? And what pi are you using? As this is my pi2 model b, but I do have the same thing on the pi1 model be 2. Also what os are you using? And version of kodi on that os? Edited May 24, 2015 by scalda Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 Then why doesn't it cause havoc once you add on changes the file path in the database? And what pi are you using? As this is my pi2 model b, but I do have the same thing on the pi1 model be 2. Also what os are you using? And version of kodi on that os? Yeah, I know - it does seem to work. We made this change a long time ago (to me anyway) and I am trying to dig up the bugs we had that led us to give up this line of operation. Certainly off-network playback and transcoding will not work - but if it were just that it could be made an option to use real paths. xnappo Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 @@xnappo Would you like me to record a video of me playing a new file and showing what it does and then post a screenshot of the database? Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 Yeah, I know - it does seem to work. We made this change a long time ago (to me anyway) and I am trying to dig up the bugs we had that led us to give up this line of operation. Certainly off-network playback and transcoding will not work - but if it were just that it could be made an option to use real paths. xnappo Also I said a couple of posts back that it would be great for remote access but for local network play it's pointless. So why can't it be enabled when http is used instead of smb is enabled? Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 I am still confused - are you saying when you play a file back, the SMB path is being ADDED to the database automatically? So yes - since I am still confused, please post a video. Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 (edited) I am still confused - are you saying when you play a file back, the SMB path is being ADDED to the database automatically? So yes - since I am still confused, please post a video. @@xnappo yes it is doing it's self i am not manually editing the database like you think i am i have no need to do it that would mess up what i'm trying to get across i have just played 5 videos and they took quicker then what avatar did earlier i wish i caught that one really, but as you can see i played videos and then in the corner you can see it running the increment database update, then the image is of the database changes it made video: https://www.youtube.com/watch?v=W8k_JYlBEtk Log file: https://dl.dropboxusercontent.com/u/8871364/Captures/kodi%20log%202%20with%205%20movies%2024-05-2015.log DB image Edited May 24, 2015 by scalda Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 Thanks - that helps a lot. The time from when you click a movie to playback starting doesn't look all that bad - but this weird database issue is definitely a problem. @@marcelveldt - any ideas here? I can't seem to recreate this problem... Link to comment Share on other sites More sharing options...
scalda 69 Posted May 24, 2015 Author Share Posted May 24, 2015 (edited) Thanks - that helps a lot. The time from when you click a movie to playback starting doesn't look all that bad - but this weird database issue is definitely a problem. @@marcelveldt - any ideas here? I can't seem to recreate this problem... yes the play isn't bad but once that smb path is in its even faster and instant this is a screenshot of my daughters database using the same version as my main pi and it shows the same smb path updates I have just installed a new pi in my bedroom so i will be checking that one as well once i go and reboot for it to do the initial sync,. once that is done i will be doing the same thing again, to check it Edited May 24, 2015 by scalda Link to comment Share on other sites More sharing options...
xnappo 1592 Posted May 24, 2015 Share Posted May 24, 2015 @@scalda - one thing I see if your logs that is not in mine is even where there is not .srt file you get: ScanForExternalSubtitles: Searching for subtitles... I am wondering if when it searches the path for subtitles it ends up scraping the path into the db. I tried playing around with the subtitles settings, but could not reproduce this log message. Do you know how to turn it on/off? Link to comment Share on other sites More sharing options...
Recommended Posts