Jump to content

Emby/Kodi beta auto-deleting watched videos


mobamoba

Recommended Posts

xnappo

What kind of lag?  It may take up to 30 seconds.  Sometimes if you delete something, it is true it may not disappear until you go out and back in.  There hasn't been any change in the delete code itself - and I really can't think of anything else changed recently that could affect this (but I will look through the changes).

 

The amount of time it takes the server to do this is unpredictable.  In the old addon - I actually locked the user out from doing anything with a progress bar that waited the max amount of time I had seen it take, but that seems silly.  

 

xnappo

Edited by xnappo
Link to comment
Share on other sites

mobamoba

The lag is nothing drastic certainly, but there's no indicator that the process is working - it feels like you clicked delete and it just stays there. I wonder if you were onto something with indicating that the process was working. Instead of a progress indicator, would deleting from the Kodi library first and the Emby server second in the background make the show disappear instantly? Or even, on the dialogue box confirming that you want Emby to delete the file, an indicator a la, "Note: It may take a few minutes for Emby to remove the file from Kodi" or something?

 

Even as someone who understood what was going on due to this thread, I still couldn't totally tell if anything was happening or if the process was glitching.

Link to comment
Share on other sites

xnappo

Yeah, I will try to come up with something.  As I said in the old addon we had a progress indicator, and people didn't like it (it blocked moving on to doing anything else until complete).

 

Probably just an auto-timed message saying 'file deleted on server, update in progress' or something. 

Edited by xnappo
Link to comment
Share on other sites

mobamoba

There's still something glitching with Emby delete. Just now, I hit stop at the end of a video I was watching and Emby delete never appeared. Instead the video immediately vanished from the list as something (Emby? Kodi?) had marked it watched and swept it out of view. I then had to get rid of it manually (show watched videos, context menu to manage library, etc.). Below is the relevant portion of the log as maybe it will help debug why Emby delete never appeared at all:

20:57:57 T:7428  NOTICE: CDVDPlayer::CloseFile()
20:57:57 T:7428  NOTICE: DVDPlayer: waiting for threads to exit
20:57:57 T:8036  NOTICE: CDVDPlayer::OnExit()
20:57:57 T:8036  NOTICE: Closing stream player 1
20:57:57 T:8036  NOTICE: Waiting for audio thread to exit
20:57:57 T:2336  NOTICE: thread end: CDVDPlayerAudio::OnExit()
20:57:57 T:8036  NOTICE: Closing audio device
20:57:57 T:8036  NOTICE: Deleting audio codec
20:57:57 T:8036  NOTICE: Closing stream player 2
20:57:57 T:8036  NOTICE: waiting for video thread to exit
20:57:57 T:7008  NOTICE: thread end: video_thread
20:57:57 T:8036  NOTICE: deleting video codec
20:57:57 T:8036  NOTICE: DXVA::CDecoder::Close - closing decoder
20:57:57 T:8036  NOTICE: DXVA::Close - closing decoder context
20:57:57 T:8036  NOTICE: Closing stream player 3
20:57:57 T:7428  NOTICE: DVDPlayer: finished waiting
20:57:57 T:7004  NOTICE: Thread BackgroundLoader start, auto delete: false
20:57:57 T:1780  NOTICE: Thread JobWorker start, auto delete: true
20:57:57 T:7428  NOTICE: CDVDPlayer::CloseFile()
20:57:57 T:7428  NOTICE: DVDPlayer: waiting for threads to exit
20:57:57 T:7428  NOTICE: DVDPlayer: finished waiting
20:57:57 T:7428  NOTICE: CDVDPlayer::CloseFile()
20:57:57 T:7428  NOTICE: DVDPlayer: waiting for threads to exit
20:57:57 T:3716  NOTICE: EMBY Player -> onPlayBackStopped
20:57:57 T:7428  NOTICE: DVDPlayer: finished waiting
20:57:57 T:6440  NOTICE: Thread JobWorker start, auto delete: true
20:57:57 T:3716  NOTICE: Emby -> updatePlayCountFromKodi Called
20:57:57 T:7940  NOTICE: Thread BackgroundLoader start, auto delete: false
20:57:57 T:6572  NOTICE: Thread FileCache start, auto delete: false
20:57:58 T:2832  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"UserDataChanged","Data":{"UserId":"f23a949b5da2dd2cb526bf4fa8738d39","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":1,"IsFavorite":false,"Played":true,"Key":"259765002006","ItemId":"7e20d03d9893472ffe50af03405be550"},{"PlayedPercentage":20,"UnplayedItemCount":4,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":false,"Key":"259765002","ItemId":"3007c5d72c66a6ea5e16c8d74771869d"}]}}
20:57:58 T:2832  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged
20:57:58 T:2832  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : UserDataList : [{u'ItemId': u'7e20d03d9893472ffe50af03405be550', u'IsFavorite': False, u'Played': True, u'PlaybackPositionTicks': 0, u'Key': u'259765002006', u'PlayCount': 1}, {u'ItemId': u'3007c5d72c66a6ea5e16c8d74771869d', u'IsFavorite': False, u'Played': False, u'PlayedPercentage': 20, u'UnplayedItemCount': 4, u'PlaybackPositionTicks': 0, u'Key': u'259765002', u'PlayCount': 0}]
20:57:58 T:2832  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : Processing Updated : [u'7e20d03d9893472ffe50af03405be550', u'3007c5d72c66a6ea5e16c8d74771869d']
20:57:58 T:7988  NOTICE: Thread FileCache start, auto delete: false
20:57:58 T:2832  NOTICE: UPDATE episode to Kodi library -> Id: 7e20d03d9893472ffe50af03405be550 - Title: Armies of One
20:57:58 T:4520  NOTICE: Thread VideoInfoScanner start, auto delete: false
20:57:58 T:4520  NOTICE: VideoInfoScanner: Starting scan ..
20:57:58 T:4520  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
20:57:58 T:6972  NOTICE: Thread BackgroundLoader start, auto delete: false
20:57:58 T:7604  NOTICE: Thread FileCache start, auto delete: false
20:57:59 T:2832  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-12T00:57:59.5815443Z","EndTimeUtc":"2015-06-12T00:57:59.5815443Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
20:58:01 T:3828  NOTICE: Thread FileCache start, auto delete: false
20:58:06 T:1520  NOTICE: Thread BackgroundLoader start, auto delete: false
20:58:11 T:7520  NOTICE: Thread FileCache start, auto delete: false
20:58:13 T:4508  NOTICE: Previous line repeats 2 times.
20:58:13 T:4508  NOTICE: Thread BackgroundLoader start, auto delete: false
20:58:19 T:3716  NOTICE: Intercepted remove from sender: xbmc method: VideoLibrary.OnRemove data: {"id":54,"type":"episode"}
20:58:19 T:6692  NOTICE: Thread BackgroundLoader start, auto delete: false
20:58:19 T:3716  NOTICE: Deleting Emby ID: 7e20d03d9893472ffe50af03405be550 from database
20:58:21 T:3716  NOTICE: Deleting via URL: {server}/mediabrowser/Items/7e20d03d9893472ffe50af03405be550
20:58:21 T:3716  NOTICE: Intercepted remove from sender: xbmc method: VideoLibrary.OnRemove data: {"id":54,"type":"episode"}
20:58:23 T:3656  NOTICE: Previous line repeats 1 times.
20:58:23 T:3656  NOTICE: Thread BackgroundLoader start, auto delete: false
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"LibraryChanged","Data":{"FoldersAddedTo":[],"FoldersRemovedFrom":["3007c5d72c66a6ea5e16c8d74771869d"],"ItemsAdded":[],"ItemsRemoved":["7e20d03d9893472ffe50af03405be550"],"ItemsUpdated":[]}}
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Message : WebSocket LibraryChanged : Items Added : []
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Message : WebSocket LibraryChanged : Items Updated : []
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Message : WebSocket LibraryChanged : Items Removed : [u'7e20d03d9893472ffe50af03405be550']
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Type: None
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Message : Doing LibraryChanged : Items Removed : Calling deleteItemFromKodiLibrary: 7e20d03d9893472ffe50af03405be550
20:58:26 T:2832  NOTICE: EMBY WebSocketThread -> Message : Doing LibraryChanged : Items Removed : Calling deleteItemFromKodiLibrary (musiclibrary): 7e20d03d9893472ffe50af03405be550
20:58:26 T:2832   ERROR: ERROR:root:global name 'WriteKodiMusicDB' is not defined
20:58:26 T:2832  NOTICE: .
20:58:27 T:6644  NOTICE: Thread BackgroundLoader start, auto delete: false
20:59:37 T:7452  NOTICE: Previous line repeats 4 times.
20:59:37 T:7452  NOTICE: ES: Client  from 127.0.0.1 timed out
Link to comment
Share on other sites

xnappo

That is weird that the music delete is triggering.   That missing import could maybe be causing the watched state issue some people are having 

Link to comment
Share on other sites

Angelblue05

This is the problem, the door is way too open. It needs to also validate that the item to remove is actually a music item. which it doesn't.:

        #Process music library
        addon = xbmcaddon.Addon(id='plugin.video.emby')
        if addon.getSetting("enableMusicSync") == "true":
            connection = utils.KodiSQL("music")
            cursor = connection.cursor()
            for item in itemsRemoved:
                self.logMsg("Message : Doing LibraryChanged : Items Removed : Calling deleteItemFromKodiLibrary (musiclibrary): " + item, 0)
                WriteKodiMusicDB().deleteItemFromKodiLibrary(item, connection, cursor)
            connection.commit()
            cursor.close()

Then, realizing that WriteKodiMusicDB() is not imported causing the websocket to maybe restart or close (maybe connected to people that has the server offline online problem).

Edited by Angelblue05
Link to comment
Share on other sites

xnappo

Yep, this makes sense since we recently defaulted music sync on instead of off.

Link to comment
Share on other sites

mobamoba

I'm using 1.0.08 and the new behavior is that Emby delete shows up on stop but it doesn't delete from Kodi library. Looking in the logs I can see an error is being thrown during the stop/delete/library removal process, and I've pasted it below:

 

20:18:58 T:5852  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:58 T:7444   ERROR: ERROR:root:no such column: None
20:18:58 T:7444  NOTICE: .
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\websocket.py", line 894, in _callback
20:18:58 T:7444   ERROR:     callback(self, *args)
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\WebSocketClient.py", line 174, in on_message
20:18:58 T:7444   ERROR:     self.remove_items(itemsRemoved)
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\WebSocketClient.py", line 266, in remove_items
20:18:58 T:7444   ERROR:     showTotalCount = ReadKodiDB().getShowTotalCount(showId, connection, cursor) # Check if there are no episodes left
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\ReadKodiDB.py", line 104, in getShowTotalCount
20:18:58 T:7444   ERROR:     cursor.execute(command)
20:18:58 T:6428   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.AttributeError'>
                                            Error Contents: 'str' object has no attribute 'get'
                                            Traceback (most recent call last):
                                              File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\KodiMonitor.py", line 146, in onNotification
                                                item = result.get("Items")[0]
                                            AttributeError: 'str' object has no attribute 'get'
                                            -->End of Python script error report<--
20:18:58 T:6428  NOTICE: Intercepted remove from sender: xbmc method: VideoLibrary.OnRemove data: {"id":94,"type":"episode"}
20:19:56 T:3260  NOTICE: Previous line repeats 1 times.
20:19:56 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
 

Link to comment
Share on other sites

mobamoba

Well earlier today I reset the Kodi database because things were showing up in Emby and they weren't showing up in Kodi and so the current log is enormous with a list of all my stuff in it so I'd rather not post the whole thing. I watched three shows and the above error showed up in the log after hitting stop for all three. If there's a way I can cut the log down to just the info you need to understand the error, let me know and I'll post that.

Link to comment
Share on other sites

Angelblue05

Ok, if you can capture at least 50 lines before the error - hopefully it will be enough info....

Link to comment
Share on other sites

mobamoba

Is this enough?:

 

'runtime': '36747900000', 'Type': 'Episode', 'playmethod': 'DirectPlay'}}
19:23:45 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"UserDataChanged","Data":{"UserId":"f23a949b5da2dd2cb526bf4fa8738d39","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":1,"IsFavorite":false,"LastPlayedDate":"2015-06-16T23:23:44.5520028Z","Played":false,"Key":"259765002010","ItemId":"8cdc9153e428504730c468ac7c5cc4c7"},{"PlayedPercentage":0,"UnplayedItemCount":1,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":false,"Key":"259765002","ItemId":"3007c5d72c66a6ea5e16c8d74771869d"}]}}
19:23:45 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged
19:23:45 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : UserDataList : [{u'ItemId': u'8cdc9153e428504730c468ac7c5cc4c7', u'IsFavorite': False, u'Played': False, u'LastPlayedDate': u'2015-06-16T23:23:44.5520028Z', u'PlaybackPositionTicks': 0, u'Key': u'259765002010', u'PlayCount': 1}, {u'ItemId': u'3007c5d72c66a6ea5e16c8d74771869d', u'IsFavorite': False, u'Played': False, u'PlayedPercentage': 0, u'UnplayedItemCount': 1, u'PlaybackPositionTicks': 0, u'Key': u'259765002', u'PlayCount': 0}]
19:23:45 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : Processing Updated : [u'8cdc9153e428504730c468ac7c5cc4c7', u'3007c5d72c66a6ea5e16c8d74771869d']
19:23:45 T:7444  NOTICE: UPDATE episode to Kodi library -> Id: 8cdc9153e428504730c468ac7c5cc4c7 - Title: Bullets and Tears
19:23:45 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:23:45 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:23:45 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:23:45 T:5604  NOTICE: Thread VideoInfoScanner start, auto delete: false
19:23:45 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:23:45 T:5604  NOTICE: VideoInfoScanner: Starting scan ..
19:23:45 T:5604  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
19:23:46 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:23:46 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:23:46 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:23:47 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:23:47 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:23:47 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:23:48 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:23:48 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:23:48 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:24:49 T:3260  NOTICE: Previous line repeats 15 times.
19:24:49 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:24:51 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:25:53 T:5336  NOTICE: Previous line repeats 15 times.
19:25:53 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:25:53 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:25:54 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:25:54 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:25:54 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:25:54 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:25:55 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:25:55 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:25:55 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:25:55 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:25:55 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:25:56 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:25:56 T:5336  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x720)
19:25:56 T:5336  NOTICE: DXVA::CDecoder::Close - closing decoder
19:25:56 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:26:24 T:7444  NOTICE: Previous line repeats 7 times.
19:26:24 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:26:24.0131234Z","EndTimeUtc":"2015-06-16T23:26:24.0131234Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:26:26 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:26:26 T:7440  NOTICE: Thread JobWorker start, auto delete: true
19:26:27 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:27:52 T:3260  NOTICE: Previous line repeats 21 times.
19:27:52 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:27:52 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:31:25 T:7444  NOTICE: Previous line repeats 51 times.
19:31:25 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:31:25.2213515Z","EndTimeUtc":"2015-06-16T23:31:25.2213515Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:31:26 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:32:44 T:3260  NOTICE: Previous line repeats 18 times.
19:32:44 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:32:45 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:36:26 T:7444  NOTICE: Previous line repeats 53 times.
19:36:26 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:36:26.4105786Z","EndTimeUtc":"2015-06-16T23:36:26.4105786Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:36:26 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:40:43 T:3260  NOTICE: Previous line repeats 62 times.
19:40:43 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:40:44 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:41:27 T:7444  NOTICE: Previous line repeats 10 times.
19:41:27 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:41:27.6018057Z","EndTimeUtc":"2015-06-16T23:41:27.6018057Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:41:29 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:46:28 T:7444  NOTICE: Previous line repeats 72 times.
19:46:28 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:46:28.7940330Z","EndTimeUtc":"2015-06-16T23:46:28.7940330Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:46:29 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:47:17 T:3260  NOTICE: Previous line repeats 11 times.
19:47:17 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:47:18 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:51:30 T:7444  NOTICE: Previous line repeats 61 times.
19:51:30 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:51:29.9902604Z","EndTimeUtc":"2015-06-16T23:51:29.9902604Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:51:33 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:55:55 T:3260  NOTICE: Previous line repeats 63 times.
19:55:55 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:55:56 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:56:31 T:7444  NOTICE: Previous line repeats 8 times.
19:56:31 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-16T23:56:31.1814875Z","EndTimeUtc":"2015-06-16T23:56:31.1814875Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
19:56:33 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
19:57:42 T:3260  NOTICE: Previous line repeats 16 times.
19:57:42 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
19:57:43 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:01:32 T:7444  NOTICE: Previous line repeats 55 times.
20:01:32 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-17T00:01:32.3667144Z","EndTimeUtc":"2015-06-17T00:01:32.3667144Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
20:01:33 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:02:35 T:3260  NOTICE: Previous line repeats 15 times.
20:02:35 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
20:02:38 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:06:33 T:7444  NOTICE: Previous line repeats 57 times.
20:06:33 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-17T00:06:33.5629418Z","EndTimeUtc":"2015-06-17T00:06:33.5629418Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
20:06:36 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:07:25 T:3260  NOTICE: Previous line repeats 11 times.
20:07:25 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
20:07:26 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:11:34 T:7444  NOTICE: Previous line repeats 60 times.
20:11:34 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-17T00:11:34.7531689Z","EndTimeUtc":"2015-06-17T00:11:34.7531689Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
20:11:36 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:16:05 T:3260  NOTICE: Previous line repeats 65 times.
20:16:05 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out
20:16:07 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:16:36 T:7444  NOTICE: Previous line repeats 6 times.
20:16:36 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-17T00:16:35.9453961Z","EndTimeUtc":"2015-06-17T00:16:35.9453961Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
20:16:36 T:6428  NOTICE: EMBY WebSocketThread -> sendProgressUpdate
20:18:40 T:5412  NOTICE: Previous line repeats 30 times.
20:18:40 T:5412  NOTICE: CDVDPlayer::CloseFile()
20:18:40 T:5412  NOTICE: DVDPlayer: waiting for threads to exit
20:18:40 T:7040  NOTICE: CDVDPlayer::OnExit()
20:18:40 T:7040  NOTICE: Closing stream player 1
20:18:40 T:7040  NOTICE: Waiting for audio thread to exit
20:18:40 T:3532  NOTICE: thread end: CDVDPlayerAudio::OnExit()
20:18:40 T:7040  NOTICE: Closing audio device
20:18:40 T:7040  NOTICE: Deleting audio codec
20:18:40 T:7040  NOTICE: Closing stream player 2
20:18:40 T:7040  NOTICE: waiting for video thread to exit
20:18:40 T:5336  NOTICE: thread end: video_thread
20:18:40 T:7040  NOTICE: deleting video codec
20:18:40 T:7040  NOTICE: DXVA::CDecoder::Close - closing decoder
20:18:40 T:7040  NOTICE: DXVA::Close - closing decoder context
20:18:40 T:7040  NOTICE: Closing stream player 3
20:18:40 T:5412  NOTICE: DVDPlayer: finished waiting
20:18:40 T:3328  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:40 T:6428  NOTICE: EMBY Player -> onPlayBackStopped
20:18:40 T:5412  NOTICE: CDVDPlayer::CloseFile()
20:18:40 T:6428  NOTICE: EMBY Player -> emby Service -> played_information : {'R:\\Recorded TV\\Sorted\\Banshee\\Season 2\\10 - Bullets and Tears.mkv': {'paused': 'false', 'refresh_id': 'a7745896c480487de37207ec076e2d2b', 'AudioStreamIndex': '1', 'SubtitleStreamIndex': '2', 'currentPosition': 3356.38623046875, 'item_id': '8cdc9153e428504730c468ac7c5cc4c7', 'currentfile': 'R:\\Recorded TV\\Sorted\\Banshee\\Season 2\\10 - Bullets and Tears.mkv', 'runtime': '36747900000', 'Type': 'Episode', 'playmethod': 'DirectPlay'}}
20:18:40 T:5412  NOTICE: DVDPlayer: waiting for threads to exit
20:18:40 T:6428  NOTICE: EMBY Player -> emby Service -> item_url  : R:\Recorded TV\Sorted\Banshee\Season 2\10 - Bullets and Tears.mkv
20:18:40 T:5412  NOTICE: DVDPlayer: finished waiting
20:18:40 T:6428  NOTICE: EMBY Player -> emby Service -> item_data : {'paused': 'false', 'refresh_id': 'a7745896c480487de37207ec076e2d2b', 'AudioStreamIndex': '1', 'SubtitleStreamIndex': '2', 'currentPosition': 3356.38623046875, 'item_id': '8cdc9153e428504730c468ac7c5cc4c7', 'currentfile': 'R:\\Recorded TV\\Sorted\\Banshee\\Season 2\\10 - Bullets and Tears.mkv', 'runtime': '36747900000', 'Type': 'Episode', 'playmethod': 'DirectPlay'}
20:18:40 T:5412  NOTICE: CDVDPlayer::CloseFile()
20:18:40 T:6428  NOTICE: EMBY Player -> emby Service -> runtimeticks:36747900000
20:18:40 T:5412  NOTICE: DVDPlayer: waiting for threads to exit
20:18:40 T:6428  NOTICE: EMBY Player -> emby Service -> Percent Complete:0.913354567327 Mark Played At:0.9
20:18:40 T:5412  NOTICE: DVDPlayer: finished waiting
20:18:40 T:7444  NOTICE: EMBY WebSocketThread -> 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","Mute","Unmute","SetVolume","Play","Playstate","PlayNext"],"QueueableMediaTypes":["Video"],"PlayableMediaTypes":["Audio","Video"],"Id":"88d4564917841e701ea7a34e613e48fd","UserId":"f23a949b5da2dd2cb526bf4fa8738d39","UserName":"Matt","AdditionalUsers":[],"ApplicationVersion":"1.0.08","Client":"Kodi","LastActivityDate":"2015-06-17T00:18:40.3855137Z","DeviceName":"Kodi","DeviceId":"5F6752490791471382C9E065476E32AB","SupportsRemoteControl":true,"PlayState":{"CanSeek":false,"IsPaused":false,"IsMuted":false}}}
20:18:40 T:8044  NOTICE: Thread JobWorker start, auto delete: true
20:18:40 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"UserDataChanged","Data":{"UserId":"f23a949b5da2dd2cb526bf4fa8738d39","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":1,"IsFavorite":false,"LastPlayedDate":"2015-06-16T23:23:44.5520028Z","Played":true,"Key":"259765002010","ItemId":"8cdc9153e428504730c468ac7c5cc4c7"},{"PlayedPercentage":100,"UnplayedItemCount":0,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":true,"Key":"259765002","ItemId":"3007c5d72c66a6ea5e16c8d74771869d"}]}}
20:18:40 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged
20:18:40 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : UserDataList : [{u'ItemId': u'8cdc9153e428504730c468ac7c5cc4c7', u'IsFavorite': False, u'Played': True, u'LastPlayedDate': u'2015-06-16T23:23:44.5520028Z', u'PlaybackPositionTicks': 0, u'Key': u'259765002010', u'PlayCount': 1}, {u'ItemId': u'3007c5d72c66a6ea5e16c8d74771869d', u'IsFavorite': False, u'Played': True, u'PlayedPercentage': 100, u'UnplayedItemCount': 0, u'PlaybackPositionTicks': 0, u'Key': u'259765002', u'PlayCount': 0}]
20:18:40 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : Processing Updated : [u'8cdc9153e428504730c468ac7c5cc4c7', u'3007c5d72c66a6ea5e16c8d74771869d']
20:18:41 T:7444  NOTICE: UPDATE episode to Kodi library -> Id: 8cdc9153e428504730c468ac7c5cc4c7 - Title: Bullets and Tears
20:18:41 T:6164  NOTICE: Thread VideoInfoScanner start, auto delete: false
20:18:41 T:6164  NOTICE: VideoInfoScanner: Starting scan ..
20:18:41 T:6164  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
20:18:41 T:1820  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:42 T:6428  NOTICE: Deleting via URL: {server}/mediabrowser/Items/8cdc9153e428504730c468ac7c5cc4c7
20:18:43 T:6428  NOTICE: Emby -> updatePlayCountFromKodi Called
20:18:43 T:8088  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:54 T:7760  NOTICE: Previous line repeats 3 times.
20:18:54 T:7760  NOTICE: Thread JobWorker start, auto delete: true
20:18:55 T:1908  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:55 T:7892  NOTICE: Thread JobWorker start, auto delete: true
20:18:57 T:6428  NOTICE: Intercepted remove from sender: xbmc method: VideoLibrary.OnRemove data: {"id":94,"type":"episode"}
20:18:57 T:7444  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"LibraryChanged","Data":{"FoldersAddedTo":[],"FoldersRemovedFrom":["3007c5d72c66a6ea5e16c8d74771869d"],"ItemsAdded":[],"ItemsRemoved":["8cdc9153e428504730c468ac7c5cc4c7"],"ItemsUpdated":[]}}
20:18:57 T:7444  NOTICE: EMBY WebSocketThread -> Message : WebSocket LibraryChanged : Items Added : []
20:18:57 T:7444  NOTICE: EMBY WebSocketThread -> Message : WebSocket LibraryChanged : Items Updated : []
20:18:57 T:7444  NOTICE: EMBY WebSocketThread -> Message : WebSocket LibraryChanged : Items Removed : [u'8cdc9153e428504730c468ac7c5cc4c7']
20:18:57 T:6428  NOTICE: Deleting Emby ID: 8cdc9153e428504730c468ac7c5cc4c7 from database
20:18:57 T:7444  NOTICE: EMBY WebSocketThread -> Type: episode
20:18:57 T:7444  NOTICE: EMBY WebSocketThread -> Message : Doing LibraryChanged : Items Removed : Calling deleteItemFromKodiLibrary: 8cdc9153e428504730c468ac7c5cc4c7
20:18:58 T:6192  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:58 T:7444  NOTICE: EMBY WebSocketThread -> ShowID: None
20:18:58 T:5852  NOTICE: Thread BackgroundLoader start, auto delete: false
20:18:58 T:7444   ERROR: ERROR:root:no such column: None
20:18:58 T:7444  NOTICE: .
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\websocket.py", line 894, in _callback
20:18:58 T:7444   ERROR:     callback(self, *args)
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\WebSocketClient.py", line 174, in on_message
20:18:58 T:7444   ERROR:     self.remove_items(itemsRemoved)
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\WebSocketClient.py", line 266, in remove_items
20:18:58 T:7444   ERROR:     showTotalCount = ReadKodiDB().getShowTotalCount(showId, connection, cursor) # Check if there are no episodes left
20:18:58 T:7444   ERROR:   File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\ReadKodiDB.py", line 104, in getShowTotalCount
20:18:58 T:7444   ERROR:     cursor.execute(command)
20:18:58 T:6428   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.AttributeError'>
                                            Error Contents: 'str' object has no attribute 'get'
                                            Traceback (most recent call last):
                                              File "C:\Users\Matt\AppData\Roaming\Kodi\addons\plugin.video.emby\resources\lib\KodiMonitor.py", line 146, in onNotification
                                                item = result.get("Items")[0]
                                            AttributeError: 'str' object has no attribute 'get'
                                            -->End of Python script error report<--
20:18:58 T:6428  NOTICE: Intercepted remove from sender: xbmc method: VideoLibrary.OnRemove data: {"id":94,"type":"episode"}
20:19:56 T:3260  NOTICE: Previous line repeats 1 times.
20:19:56 T:3260  NOTICE: ES: Client  from 127.0.0.1 timed out

  • Like 1
Link to comment
Share on other sites

  • 2 weeks later...
mobamoba

I'm still having sporadic problems with this FYI. Sometimes I'll get Emby Delete and sometimes a show will get marked watched without Emby Delete ever appearing. Here's part of my log from a recent example if this helps sort out the problem:

 

15:00:51 T:5888  NOTICE: ES: Client  from 127.0.0.1 timed out
15:03:06 T:1832  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"ScheduledTaskEnded","Data":{"StartTimeUtc":"2015-06-30T19:03:05.8535513Z","EndTimeUtc":"2015-06-30T19:03:05.8535513Z","Status":"Completed","Name":"Organize new media files","Key":"AutoOrganize","Id":"415f8db75e909cdef2a3da79d1e2c636"}}
15:04:28 T:5696  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x736)
15:04:28 T:5696  NOTICE: DXVA::CDecoder::Close - closing decoder
15:04:28 T:2232  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 23
15:04:28 T:5696  NOTICE: Previous line repeats 1 times.
15:04:28 T:5696  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x736)
15:04:28 T:5696  NOTICE: DXVA::CDecoder::Close - closing decoder
15:04:28 T:2232  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 23
15:04:29 T:5696  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x736)
15:04:29 T:5696  NOTICE: DXVA::CDecoder::Close - closing decoder
15:04:29 T:2232  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 23
15:04:30 T:5696  NOTICE: Previous line repeats 1 times.
15:04:30 T:5696  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x736)
15:04:30 T:5696  NOTICE: DXVA::CDecoder::Close - closing decoder
15:04:30 T:2232  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 23
15:04:32 T:5696  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x736)
15:04:32 T:5696  NOTICE: DXVA::CDecoder::Close - closing decoder
15:04:32 T:2232  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 23
15:04:33 T:5696  NOTICE: CDVDVideoCodecFFmpeg::GetFormat - Creating DXVA(1280x736)
15:04:33 T:5696  NOTICE: DXVA::CDecoder::Close - closing decoder
15:04:33 T:2232  NOTICE: CDVDPlayerAudio::OutputPacket skipping a packets of duration 23
15:05:34 T:5888  NOTICE: ES: Client  from 127.0.0.1 timed out
15:07:33 T:3236  NOTICE: CDVDPlayer::CloseFile()
15:07:33 T:3236  NOTICE: DVDPlayer: waiting for threads to exit
15:07:33 T:6956  NOTICE: CDVDPlayer::OnExit()
15:07:33 T:6956  NOTICE: Closing stream player 1
15:07:33 T:6956  NOTICE: Waiting for audio thread to exit
15:07:33 T:2232  NOTICE: thread end: CDVDPlayerAudio::OnExit()
15:07:33 T:6956  NOTICE: Closing audio device
15:07:33 T:6956  NOTICE: Deleting audio codec
15:07:33 T:6956  NOTICE: Closing stream player 2
15:07:33 T:6956  NOTICE: waiting for video thread to exit
15:07:33 T:5696  NOTICE: thread end: video_thread
15:07:33 T:6956  NOTICE: deleting video codec
15:07:33 T:6956  NOTICE: DXVA::CDecoder::Close - closing decoder
15:07:33 T:6956  NOTICE: DXVA::Close - closing decoder context
15:07:33 T:6956  NOTICE: Closing stream player 3
15:07:33 T:3236  NOTICE: DVDPlayer: finished waiting
15:07:33 T:5468  NOTICE: Thread BackgroundLoader start, auto delete: false
15:07:33 T:3236  NOTICE: Previous line repeats 1 times.
15:07:33 T:3236  NOTICE: CDVDPlayer::CloseFile()
15:07:33 T:3236  NOTICE: DVDPlayer: waiting for threads to exit
15:07:33 T:3236  NOTICE: DVDPlayer: finished waiting
15:07:33 T:3236  NOTICE: CDVDPlayer::CloseFile()
15:07:33 T:3236  NOTICE: DVDPlayer: waiting for threads to exit
15:07:33 T:3236  NOTICE: DVDPlayer: finished waiting
15:07:33 T:4692  NOTICE: EMBY Player -> onPlayBackStopped
15:07:33 T:2776  NOTICE: Thread JobWorker start, auto delete: true
15:07:33 T:2776  NOTICE: Previous line repeats 1 times.
15:07:33 T:2776 WARNING: XFILE::CFileFactory::CreateLoader - unsupported protocol(plugin) in plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=f5518c4cce591deb6ed488031a458882&mode=play
15:07:33 T:2776   ERROR: InputStream: Error opening, plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=f5518c4cce591deb6ed488031a458882&mode=play
15:07:33 T:2776 WARNING: XFILE::CFileFactory::CreateLoader - unsupported protocol(plugin) in plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
15:07:33 T:2776   ERROR: InputStream: Error opening, plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
15:07:34 T:7844  NOTICE: Thread FileCache start, auto delete: false
15:07:34 T:1832  NOTICE: Previous line repeats 1 times.
15:07:34 T:1832  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"UserDataChanged","Data":{"UserId":"f23a949b5da2dd2cb526bf4fa8738d39","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":2,"IsFavorite":false,"LastPlayedDate":"2015-06-30T18:49:42.0255750Z","Played":true,"Key":"183411003006","ItemId":"f5518c4cce591deb6ed488031a458882"},{"PlayedPercentage":50,"UnplayedItemCount":1,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":false,"Key":"183411003","ItemId":"f4c638d66fdce748ff6a7eefb99a368c"}]}}
15:07:34 T:1832  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged
15:07:34 T:1832  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : UserDataList : [{u'ItemId': u'f5518c4cce591deb6ed488031a458882', u'IsFavorite': False, u'Played': True, u'LastPlayedDate': u'2015-06-30T18:49:42.0255750Z', u'PlaybackPositionTicks': 0, u'Key': u'183411003006', u'PlayCount': 2}, {u'ItemId': u'f4c638d66fdce748ff6a7eefb99a368c', u'IsFavorite': False, u'Played': False, u'PlayedPercentage': 50, u'UnplayedItemCount': 1, u'PlaybackPositionTicks': 0, u'Key': u'183411003', u'PlayCount': 0}]
15:07:34 T:1832  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : Processing Updated : [u'f5518c4cce591deb6ed488031a458882', u'f4c638d66fdce748ff6a7eefb99a368c']
15:07:34 T:8032  NOTICE: Thread FileCache start, auto delete: false
15:07:34 T:2776  NOTICE: VideoInfoScanner: Starting scan ..
15:07:34 T:2776  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
15:07:34 T:3892  NOTICE: Thread BackgroundLoader start, auto delete: false
15:07:34 T:2776 WARNING: XFILE::CFileFactory::CreateLoader - unsupported protocol(plugin) in plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
15:07:34 T:2776   ERROR: InputStream: Error opening, plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
15:07:34 T:5020  NOTICE: Thread BackgroundLoader start, auto delete: false
15:07:34 T:2776 WARNING: XFILE::CFileFactory::CreateLoader - unsupported protocol(plugin) in plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
15:07:34 T:2776   ERROR: InputStream: Error opening, plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
15:07:34 T:5820  NOTICE: Thread FileCache start, auto delete: false
15:07:39 T:7516  NOTICE: Previous line repeats 1 times.
15:07:39 T:7516  NOTICE: Thread BackgroundLoader start, auto delete: false
15:07:39 T:2776 WARNING: XFILE::CFileFactory::CreateLoader - unsupported protocol(plugin) in plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=f5518c4cce591deb6ed488031a458882&mode=play
15:07:39 T:2776   ERROR: InputStream: Error opening, plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=f5518c4cce591deb6ed488031a458882&mode=play
15:07:41 T:3140  NOTICE: Thread FileCache start, auto delete: false
15:07:46 T:5628  NOTICE: Previous line repeats 4 times.

Link to comment
Share on other sites

mobamoba

I'm on the beta channel so I'm using whatever is the most recent update you guys pushed. It just happened again, i.e. the item gets marked as watched on stop but Emby delete doesn't show up. BTW this behavior is inconsistent as sometimes Emby delete does show up. Below is from a recent log where it didn't show up.

 

14:20:17 T:5888  NOTICE: ES: Client  from 127.0.0.1 timed out
14:22:28 T:3236  NOTICE: CDVDPlayer::CloseFile()
14:22:28 T:3236  NOTICE: DVDPlayer: waiting for threads to exit
14:22:28 T:1208280  NOTICE: CDVDPlayer::OnExit()
14:22:28 T:1208280  NOTICE: Closing stream player 1
14:22:28 T:1208280  NOTICE: Waiting for audio thread to exit
14:22:28 T:1208300  NOTICE: thread end: CDVDPlayerAudio::OnExit()
14:22:28 T:1208280  NOTICE: Closing audio device
14:22:28 T:1208280  NOTICE: Deleting audio codec
14:22:28 T:1208280  NOTICE: Closing stream player 2
14:22:28 T:1208280  NOTICE: waiting for video thread to exit
14:22:28 T:1208296  NOTICE: thread end: video_thread
14:22:28 T:1208280  NOTICE: deleting video codec
14:22:28 T:1208280  NOTICE: DXVA::CDecoder::Close - closing decoder
14:22:28 T:1208280  NOTICE: DXVA::Close - closing decoder context
14:22:28 T:1208280  NOTICE: Closing stream player 3
14:22:28 T:3236  NOTICE: DVDPlayer: finished waiting
14:22:28 T:1318496  NOTICE: Thread BackgroundLoader start, auto delete: false
14:22:28 T:1318508  NOTICE: Thread JobWorker start, auto delete: true
14:22:28 T:3236  NOTICE: CDVDPlayer::CloseFile()
14:22:28 T:3236  NOTICE: DVDPlayer: waiting for threads to exit
14:22:28 T:3236  NOTICE: DVDPlayer: finished waiting
14:22:28 T:3236  NOTICE: CDVDPlayer::CloseFile()
14:22:28 T:3236  NOTICE: DVDPlayer: waiting for threads to exit
14:22:28 T:3236  NOTICE: DVDPlayer: finished waiting
14:22:28 T:4416  NOTICE: EMBY Player -> onPlayBackStopped
14:22:29 T:2136  NOTICE: EMBY WebSocketThread -> Message : {"MessageType":"UserDataChanged","Data":{"UserId":"f23a949b5da2dd2cb526bf4fa8738d39","UserDataList":[{"PlaybackPositionTicks":0,"PlayCount":1,"IsFavorite":false,"LastPlayedDate":"2015-07-01T18:03:24.7584372Z","Played":true,"Key":"183411003010","ItemId":"af41433648ab42c84a4da2397d3615a7"},{"PlayedPercentage":100,"UnplayedItemCount":0,"PlaybackPositionTicks":0,"PlayCount":0,"IsFavorite":false,"Played":true,"Key":"183411003","ItemId":"f4c638d66fdce748ff6a7eefb99a368c"}]}}
14:22:29 T:2136  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged
14:22:29 T:2136  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : UserDataList : [{u'ItemId': u'af41433648ab42c84a4da2397d3615a7', u'IsFavorite': False, u'Played': True, u'LastPlayedDate': u'2015-07-01T18:03:24.7584372Z', u'PlaybackPositionTicks': 0, u'Key': u'183411003010', u'PlayCount': 1}, {u'ItemId': u'f4c638d66fdce748ff6a7eefb99a368c', u'IsFavorite': False, u'Played': True, u'PlayedPercentage': 100, u'UnplayedItemCount': 0, u'PlaybackPositionTicks': 0, u'Key': u'183411003', u'PlayCount': 0}]
14:22:29 T:2136  NOTICE: EMBY WebSocketThread -> Message : Doing UserDataChanged : Processing Updated : [u'af41433648ab42c84a4da2397d3615a7', u'f4c638d66fdce748ff6a7eefb99a368c']
14:22:29 T:1318508  NOTICE: VideoInfoScanner: Starting scan ..
14:22:29 T:1318508  NOTICE: VideoInfoScanner: Finished scan. Scanning for video info took 00:00
14:22:29 T:1318632  NOTICE: Thread BackgroundLoader start, auto delete: false
14:22:34 T:1318508  NOTICE: Previous line repeats 2 times.
14:22:34 T:1318508 WARNING: XFILE::CFileFactory::CreateLoader - unsupported protocol(plugin) in plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
14:22:34 T:1318508   ERROR: InputStream: Error opening, plugin://plugin.video.emby/tvshows/93ac24798b4fd3a0e5c7d29e80f8551b/?id=af41433648ab42c84a4da2397d3615a7&mode=play
14:22:37 T:1319404  NOTICE: Thread LanguageInvoker start, auto delete: false

Link to comment
Share on other sites

xnappo

You are talking about it offering you the option to delete?

 

Do you have the 'Auto play next' feature also enabled? (Netflix style thing)

 

Thanks,

xnappo

Edited by xnappo
Link to comment
Share on other sites

mobamoba

Yeah I'm talking about the thing that asks if you want to delete the file from the Emby server - it doesn't show up consistently. I don't have the Netflix-style thing enabled.

 

ETA: Actually I'm stlil on 1.1.13. I'm using Isengard beta2 so I can't force refresh to update the addon and for whatever reason, it's not updating me automatically (I have it set to auto update). I tried seting auto update to "notify" then manually updating the addon but "update" is grayed out so that doesn't work either.

Edited by mobamoba
Link to comment
Share on other sites

xnappo

Can't see what is going on.  Please bump up the log level and post the whole thing (see 'how to report a problem' sticky)

Link to comment
Share on other sites

mobamoba

Okay. Like I mentioned, it's sporadic, so I'll increase the log level and upload next time it happens.

Link to comment
Share on other sites

mobamoba

Log is attached (I put the level to Info not Debug). If you jump to 21:32:24, you'll see a show I watched last night where Emby delete worked, i.e. I hit stop at the end, the show was marked as watched, and Emby asked me if I wanted to delete, and, after hitting yes, the show was removed from both the library and physically on my disk. If you then jump to 13:28:07, you'll see a show I watched today where Emby delete failed, i.e. I hit stop at the end and the show was marked as watched but the Emby delete dialogue never appeared and I had to go find the show and delete it manually through the Kodi context menu from both the library and the physical disk.

 

My computer wasn't rebooted nor was Kodi restarted between those two shows. Emby delete simply worked on one then didn't on the other and perhaps my log will help you understand why. Thanks.

kodi.log

Link to comment
Share on other sites

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