Completed Resume Does not appear to work

[kolbasz 20]

I need to see if my main player allows resume later, but as a whole, the feature does not appear to translate/function.

 

I watched a show on rpi last night, getting to 30 of 46 minutes, so like 70%.  When I open kodi on my computer, I waitied a few seconds and all the watched status for previous shows synced, this was good to see.  However, the episode I started and never finished was also shown as watched.  When I clicked it, I only had the option to play as opposed to resume/play. 

 

My installation is bare bones at the moment, openelec 5.0.8 on rpi, emby repository and emby plugin.  I assume it has nothing to do with the player and more with the resume state feature in the add-on as it translates as watched instead or partially watched.

[kolbasz 20]

The server sees it as watched

[kolbasz 20]

I know, that's what I am saying, I was at 70% not 90% and it was marked watched as opposed to resumable

[Angelblue05 4130]

@@kolbasz

 

Have you been able to repeat this bug in some way? Or it was just that one time?

If you play the content until half way through, does it mark as watched or are you able to resume correctly in this case? (either on Kodi or web client)

 

Is your playback via HTTP or local (SMB)?

 

Thanks.

[kolbasz 20]

I can repeat it, are info logs enough?

 

I use path re-direction from docker mount to nfs:// path, so neither smb or http

[Angelblue05 4130]

Yeah, let's start with info log and go from there Thanks.

 

Also tell me the steps you are taking, so I can try to reproduce on it.

Edited April 22, 2015 by Angelblue05

[kolbasz 20]

OK, just realized there is a newer version of server, will install, test and report.

 

But essentially, running rpi, emby plug-in, start playback, stop playback (call it halfway through episode), server reports as watched. Open kodi on computer, only option is play, same with rpi.

 

I am new to mb/emby from mysql/headless kodi where this worked perfectly. After correcting my dB sync issue (missing parent folder) this is next on the list on my way to media bliss.

 

Thanks, will report once I'm on latest server. Do I need to re-add docker container to force upgrade or is there a better way? Do you know, before I go on the hunt.

[Angelblue05 4130]

Well, start with updating the server. Do you see the playback report going in the Emby server dashboard when you play content?

 

I don't think the paths are an issue since you are able to get playback in the first place. We haven't implemented every features yet since we are still working on stabilizing the current process. Anyway, if the server doesn't show the playback report then it means the Kodi is not communicating this information correctly in the first place.

 

Edit: If it does display playback, how often does it refresh? You can mouseover the active device and the overlay should appear with the timer going. How often does the timer refresh with the new playback position?

Edited April 22, 2015 by Angelblue05

[Angelblue05 4130]

@@kolbasz

 

Can you validate that the file named advancedsettings in the %appdata/Roaming/Kodi/UserData/advancedsettings.xml has nothing written in it or does not exists. Maybe this is what's causing the problem, an old settings. I have no been able to duplicate this problem so it might be environmental. Let me know!  Oh, if you have additional profiles, also verify the advancedsettings contained in the profile folder. If deleting the advancedsettings.xml does not correct the issue, do you think you are able to erase the whole UserData folder and start from Emby for Kodi scratch?

[kolbasz 20]

OK, updated server, Version 3.0.5588.0 and tried again.  Using my laptop vs rpi, but the results are the same.  It is just easier to pull logs this way.  

 

emby add-on updated on start, restarted kodi to ensure function after server update.  Started media, I see it under active devices and it lists the playback position, 32 seconds, 1 minutes, 4 minutes, etc.  Stop video, play icon appears as expected for a resumable video and immediately replaced with a check mark to signify watched when I am only a handful of minutes into the episode.  Full kodi log attached, if we need something else, let me know.

kodi.zip

Edited April 22, 2015 by kolbasz

[kolbasz 20]

@@kolbasz

 

Can you validate that the file named advancedsettings in the %appdata/Roaming/Kodi/UserData/advancedsettings.xml has nothing written in it or does not exists. Maybe this is what's causing the problem, an old settings. I have no been able to duplicate this problem so it might be environmental. Let me know!  Oh, if you have additional profiles, also verify the advancedsettings contained in the profile folder. If deleting the advancedsettings.xml does not correct the issue, do you think you are able to erase the whole UserData folder and start from Emby for Kodi scratch?

file does not even exist.  At the time, it was a new installation.'  Proceeding with delete of user data folder.

[kolbasz 20]

OK, I deleted everything in %AppData%\Roaming\Kodi\userdata

 

upon starting kodi emby immediately found server and allowed me to connect and start db sync.

 

sync completed and I started an episode, watched 5 minutes of 42 and when stopped it was marked as watched.  Let me know if I should have done something else, such as completely uninstalling kodi, deleting all folders and starting again.

 

 

kodi.zip

[Angelblue05 4130]

Ok, that's good enough for now, I'm currently checking your log to see if we can find any clue. Thanks!

 

Edit: I think I found the problem or maybe not. 

Edited April 22, 2015 by Angelblue05

[kolbasz 20]

thanks.  working with kodi on windows makes the troubleshooting way faster and easier and faster than on rpi where the db sync takes forever.  If I need to blow things away, thats fine, emby and the repository are the one 2 things installed and configured, so I am not super invested where starting over is an issue.

[Angelblue05 4130]

@

 

Could this have a bad side effect. It seems to trigger multiple times:

        if method == "VideoLibrary.OnUpdate":
            jsondata = json.loads(data)
            if jsondata != None:
                
                playcount = None
                playcount = jsondata.get("playcount")
                item = jsondata.get("item").get("id")
                type = jsondata.get("item").get("type")
                if playcount != None:
                    utils.logMsg("MB# Sync","Kodi_Monitor--> VideoLibrary.OnUpdate : " + str(data),2)
                    WriteKodiDB().updatePlayCountFromKodi(item, type, playcount)

Like this:

18:14:15 T:928  NOTICE: Emby -> updatePlayCountFromKodi Called
18:14:15 T:928  NOTICE: Emby -> watchedurl -->http://192.168.0.146:8096/mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/a53c32a4684e56e25d746558d1388395
18:14:15 T:928  NOTICE: Emby -> updatePlayCountFromKodi Called
18:14:15 T:928  NOTICE: Emby -> watchedurl -->http://192.168.0.146:8096/mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/a53c32a4684e56e25d746558d1388395
18:14:15 T:928  NOTICE: Emby -> updatePlayCountFromKodi Called
18:14:15 T:928  NOTICE: Emby -> watchedurl -->http://192.168.0.146:8096/mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/a53c32a4684e56e25d746558d1388395
18:14:15 T:928  NOTICE: Emby -> updatePlayCountFromKodi Called
18:14:15 T:928  NOTICE: Emby -> watchedurl -->http://192.168.0.146:8096/mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/a53c32a4684e56e25d746558d1388395
18:14:15 T:928  NOTICE: Emby -> updatePlayCountFromKodi Called
18:14:15 T:928  NOTICE: Emby -> watchedurl -->http://192.168.0.146:8096/mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/a53c32a4684e56e25d746558d1388395
18:14:15 T:928  NOTICE: Emby -> updating property...lastplayed

Technically, marking watched erases the resume position. So it could be what's causing the problem.

    def updatePlayCountFromKodi(self, id, type, playcount=0):
        #when user marks item watched from kodi interface update this in MB3
        xbmc.sleep(sleepVal)
        utils.logMsg("Emby", "updatePlayCountFromKodi Called")
        
        mb3Id = ReadKodiDB().getEmbyIdByKodiId(id, type)

        if(mb3Id != None):
            addon = xbmcaddon.Addon(id='plugin.video.emby')   
            
            downloadUtils = DownloadUtils()       
        
            watchedurl = "{server}/mediabrowser/Users/{UserId}/PlayedItems/%s" % mb3Id
            utils.logMsg("Emby","watchedurl -->" + watchedurl)
            if playcount != 0:
                downloadUtils.downloadUrl(watchedurl, postBody="", type="POST")
            else:
                downloadUtils.downloadUrl(watchedurl, type="DELETE")

Edited April 22, 2015 by Angelblue05

[Angelblue05 4130]

yeah it triggers every time you update the kodi lib, we update it with a few things so it triggers multiple times, it should always report the same thing though so I don't think that would be causing it and also it is not causing issues on any other system.

 

One thing to look at if run time, does the item have a run time in Emby?

 

Ok but that's the thing, should it even trigger if the item is not viewed completely? It seems playcount != None doesn't do anything? Everything has a playcount so it will never be None, so then it always proceeds to erase the resume point either way by sending played/delete play state to the API, no?

 

The only thing I can think of as to why it's not affecting any other system is because you've never actually viewed the item on your account, therefore playcount does equal None, but after you've viewed it once or what not, it's either 0+ so it never becomes None. Only brand new items will have no playcount.

 

I'm guessing by that logic, when there's a lib update, and the item has already been viewed in the past, it would trigger the watched or delete in the API, no matter the fact that there's a resume point.

 

Edit: At this point, I'm out of ideas...I'm testing on my machine to see if I can duplicate it hehe. Will report back if I'm able to.

 

@

 

I was able to replicate the problem. Pick a show you've already marked watched. Mark it unwatched, then play it from the start, skip 10 mins in then stop the show. It will be marked as watched. Let me know if you are able to reproduce it as well. (You can check your season level for the watched, give it a second a two). In my case, the resume persists. So it goes from unwatched with resume, to watched with resume.

Edited April 23, 2015 by Angelblue05

[kolbasz 20]

should the paths translate to anything?

Handler for Request not found:





Request.HttpMethod: GET

Request.PathInfo: /mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/5975b33ec467a1f4172e8e612b7ac1a9

Request.QueryString: System.Collections.Specialized.NameValueCollection

Request.RawUrl: /mediabrowser/Users/2ec276a2642e54a19b612b9418a8bd3b/PlayedItems/5975b33ec467a1f4172e8e612b7ac1a9

Second, I am not sure if it means anything to this or not, but tonight I fired up the rpi/openelec/emby, navigated to the show i wanted to watch when everything vanished...rebooted and things began repopulating silently, but slowly.  forced me to go my backup, plex/chromecast while thins populated.

 

Further, how long should it take something marked unwatched on rpi to show unwatched on computer/kodi?  unwatched some episodes on rpi and minutes later it was not translated to pc as unwatched so just curious

 

 

kodi.log

kodi.old.log

[kolbasz 20]

and so they are separate, here are my windows kodi logs.  seems there is a ton of syncing that is going on for an already synced DB that had no changes.  does this sort of things appear normail?

kodi.log

kodi.old.log

[kolbasz 20]

@null_pointer @@Angelblue05

 

After staring at the logs a bit, the only thing I am seeing that makes no sense is the 'PlaybackPositionTicks' It seems to always show 0, I am assuming this should change.

 

23:21:09 T:1821344832  NOTICE: emby WebSocketThread -> Message : Doing UserDataChanged : UserData : {u'ItemId': u'5975b33ec467a1f4172e8e612b7ac1a9', u'IsFavorite': False, u'Played': False, u'PlaybackPositionTicks': 0, u'Key': u'81578008004', u'PlayCount': 0}

 

I seached google and another users random log appeared and they have:

'PlaybackPositionTicks': 30617250976L,

http://xbmclogs.com/pzkmk6gsm

 

I would like to think that this has something to do with file position, but I have no clue...

[Angelblue05 4130]

@@kolbasz

 

Thanks for looking. I think we have enough information. We'll have to review the entire section about reporting to server.

 

I've added the issue to our brand new Trello board:

https://trello.com/b/qBJ49ka4/emby-for-kodi

 

You can track the progress there. Cheers!

[kolbasz 20]

to add to the fun, tonight I watched an episode and a half of the killing.  when stopped, it stays partially watched as expected and allows reboot.  I even rebooted and it remained, so i looked on the server.   the server showed it unwatched as well as the episode I finished, so this made it seem that kodi is not talking back to the server.  log attached.  I even started kodi on windows to see if it would appear despite what the server shows, it did not...all logs attached,  open with 7 zip...

 

 

rpi.zip

windowsi.zip

[kolbasz 20]

@@kolbasz

 

Thanks for looking. I think we have enough information. We'll have to review the entire section about reporting to server.

 

I've added the issue to our brand new Trello board:

https://trello.com/b/qBJ49ka4/emby-for-kodi

 

You can track the progress there. Cheers!

 

To further the above post, I wanted to provide a little more information about what I saw/see.

 

I am hoping the rpi log shows that it is not talking to the server as I think that might be key to this issue.  Meaning the issue is actually on the server side as opposed to the emby/add-on side.

 

The reasoning is such.  I watched 1.5 episodes of a show and neither appeared as watched on the server, essentially telling me that emby on the rpi did not talk back to the server.  This is good in that I still have the option to resume, but bad because nothing is updated on the server, so if I go to another player, say my computer, it shows episodes as not watched.

 

So, on the computer, I started an episode, skipped ahead and stopped it.  This time, the episode in kodi (on the computer) instead of allowing resume, marked as watched.  I then checked the server and it too reports watched, meaning unlike the rpi, it talked back to the server.

 

This got me thinking about the issue.  Usually when i see it happen, the resume icon appears when stopping and then quickly changes to the check mark.  My thought is that emby/kodi stops, it reports the resume point to the server, but the server kicks this back as watched, changing the status in kodi.  I mean if my rpi for whatever reason is not talking to the server, yet able to resume, then the bad info must not be coming from the kodi/add-on to mark shows as watched. 

 

I hope that makes sense

[Angelblue05 4130]

@@kolbasz

 

Can you validate something for me. Find an episode you've never watched before, try the resume and see if it switches to watched before the 90% mark. Thanks.

 

My theory being, this only happens when you rewatch something. If it's the first time watching the content, then it should behave properly. I had never seen the problem, because I normally don't rewatch my shows.

Edited April 24, 2015 by Angelblue05

[kolbasz 20]

When I see this happen, it is with unwatched media. I can go to a completely random episode of something if you want me to get logs, but all the episodes I have seen it with to date are ones I have never watched.

 

The other day I randomely skipped through 3 new episodes of ax men and all 3 even though stopped before 90% were marked watched.

 

Edit:

The show that showed last night as able to resume, that never updated to the server, today showed as unwatched and started at the beginning.

Edited April 25, 2015 by kolbasz

[kolbasz 20]

here are some server logs if they tell you anything.

server-63565344032.txt

server-63565430506.txt