embyforkodi (next-gen) 6.X.X support

[quickmic 1342]

8 hours ago, bozrdnag said:

Another twist on the partially re-watched issue.  I resumed a few in progress (but already marked as watched) movies and stopped them after a few minutes.  Most times it marks the movie as unwatched but its also messing up the last played date because they drop off my In Progress widget in Kodi.  So I go into Emby and sort movies by Date Played descending and filter for Continue Playing playstate.  All the ones I just resumed are at the end of my list.  They should be at the top.  I think they do not have a play date set at all.

 

This didn't happen every single time I tried, but it did 5 out of 7 tries.  Here is a log snippet for one that it happened on:

 

2021-02-09 20:46:31.014 T:25248  NOTICE: EMBY.hooks.monitor.Monitor -> -->[ kodi scan/video ]
2021-02-09 20:46:31.060 T:25248  NOTICE: EMBY.hooks.monitor.Monitor -> --<[ kodi scan/video ]
2021-02-09 20:47:24.153 T:25218  NOTICE: VideoPlayer::OpenFile: smb://192.168.1.42/Videos/Movies/Zootopia (2016)/Zootopia (2016) - Blu-Ray Remux.mkv
2021-02-09 20:47:24.154 T:565  NOTICE: Creating InputStream
2021-02-09 20:47:24.216 T:565  NOTICE: Creating Demuxer
2021-02-09 20:47:24.254 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onPlayBackStarted ]
2021-02-09 20:47:24.274 T:565  NOTICE: Opening stream: 0 source: 256
2021-02-09 20:47:24.274 T:565  NOTICE: Creating video codec with codec id: 27
2021-02-09 20:47:24.275 T:565  NOTICE: CDVDVideoCodecAndroidMediaCodec::Open Testing codec:OMX.Nvidia.mp2.decoder
2021-02-09 20:47:24.275 T:565  NOTICE: CDVDVideoCodecAndroidMediaCodec::Open Testing codec:OMX.Nvidia.wma.decoder
2021-02-09 20:47:24.275 T:565  NOTICE: CDVDVideoCodecAndroidMediaCodec::Open Testing codec:OMX.Nvidia.h264.decode
2021-02-09 20:47:24.293 T:567  NOTICE: EMBY.hooks.player.Player -> -->[ play/149456 ] {'Volume': 100, 'PlaySessionId': '874303f46f274918ba8e1798986db4d6', 'CurrentPosition': -1, 'Track': True, 'Server': <emby.client.EmbyClient instance at 0x24ae46a810>, 'Paused': False, 'MediaSourceId': u'f137a2dd21bbc1b99aa5c0f6bf02a805', 'Muted': False, 'DeviceId': '1331b08d-a8b0-4126-9675-0ea322c25045', 'Path': 'smb://192.168.1.42/Videos/Movies/Zootopia (2016)/Zootopia (2016) - Blu-Ray Remux.mkv', 'ServerId': None, 'RunTime': -1, 'Type': u'Movie', 'Id': u'149456', 'PlayMethod': 'DirectPlay'}
2021-02-09 20:47:24.336 T:565  NOTICE: Creating video thread
2021-02-09 20:47:24.339 T:576  NOTICE: running thread: video_thread
2021-02-09 20:47:24.344 T:565  NOTICE: Opening stream: 1 source: 256
2021-02-09 20:47:24.344 T:565  NOTICE: Finding audio codec for: 86020
2021-02-09 20:47:24.344 T:565  NOTICE: Creating audio thread
2021-02-09 20:47:24.345 T:565  NOTICE: Opening stream: 2 source: 256
2021-02-09 20:47:24.347 T:577  NOTICE: running thread: CVideoPlayerAudio::Process()
2021-02-09 20:47:24.469 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onAVChange ]
2021-02-09 20:47:24.492 T:577  NOTICE: Creating audio stream (codec id: 86020, channels: 8, sample rate: 48000, pass-through)
2021-02-09 20:47:24.547 T:25218  NOTICE: Instancing CRendererMediaCodecSurface
2021-02-09 20:47:24.548 T:25218  NOTICE: CRendererMediaCodecSurface::Configure
2021-02-09 20:47:24.594 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onAVChange ]
2021-02-09 20:47:24.619 T:25225  NOTICE: Trying to open: samplerate: 192000, channelMask: 6396, encoding: 13
2021-02-09 20:47:24.641 T:25225  NOTICE: CAESinkAUDIOTRACK::Initializing with: m_sampleRate: 192000 format: AE_FMT_S16LE (AE) method: IEC (PT) stream-type: STREAM_TYPE_DTSHD_MA min_buffer_size: 196864 m_frames: 6152 m_frameSize: 16 channels: 8
2021-02-09 20:47:24.704 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onAVChange ]
2021-02-09 20:47:24.710 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onAVStarted ]
2021-02-09 20:47:24.729 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onAVChange ]
2021-02-09 20:47:24.835 T:588  NOTICE: EMBY.hooks.monitor.Monitor -> [ UserDataChanged ] {'MonitorMethod': 'UserDataChanged', u'UserId': u'e2d7a192270d4ecda2332cf6ef46407c', u'UserDataList': [{u'ItemId': u'149456', u'IsFavorite': False, u'Played': True, u'PlayedPercentage': 9.3664473587232635, u'LastPlayedDate': u'2021-02-10T01:47:28.0000000+00:00', u'PlaybackPositionTicks': 6100000000, u'PlayCount': 4}, {u'ItemId': u'147426', u'PlayCount': 0, u'PlaybackPositionTicks': 0, u'IsFavorite': False, u'Played': False}]}
2021-02-09 20:47:24.840 T:588  NOTICE: EMBY.library.Library -> ---[ userdata:2 ]
2021-02-09 20:47:26.736 T:25299  NOTICE: EMBY.helper.wrapper -> Stopping db writing!
2021-02-09 20:47:30.709 T:25218  NOTICE: Previous line repeats 3 times.
2021-02-09 20:47:30.710 T:25218  NOTICE: CVideoPlayer::CloseFile()
2021-02-09 20:47:30.710 T:25218  NOTICE: VideoPlayer: waiting for threads to exit
2021-02-09 20:47:30.720 T:565  NOTICE: CVideoPlayer::OnExit()
2021-02-09 20:47:30.720 T:565  NOTICE: Closing stream player 1
2021-02-09 20:47:30.720 T:565  NOTICE: Waiting for audio thread to exit
2021-02-09 20:47:30.728 T:577  NOTICE: thread end: CVideoPlayerAudio::OnExit()
2021-02-09 20:47:30.728 T:565  NOTICE: Closing audio device
2021-02-09 20:47:30.765 T:25299  NOTICE: EMBY.helper.wrapper -> Stopping db writing!
2021-02-09 20:47:30.793 T:565  NOTICE: Deleting audio codec
2021-02-09 20:47:30.793 T:565  NOTICE: Closing stream player 2
2021-02-09 20:47:30.793 T:565  NOTICE: waiting for video thread to exit
2021-02-09 20:47:30.796 T:576  NOTICE: thread end: video_thread
2021-02-09 20:47:30.797 T:565  NOTICE: deleting video codec
2021-02-09 20:47:30.811 T:565  NOTICE: Closing stream player 3
2021-02-09 20:47:30.820 T:25218  NOTICE: VideoPlayer: finished waiting
2021-02-09 20:47:30.820 T:25218  NOTICE: CVideoPlayer::CloseFile()
2021-02-09 20:47:30.820 T:25218  NOTICE: VideoPlayer: waiting for threads to exit
2021-02-09 20:47:30.820 T:25218  NOTICE: VideoPlayer: finished waiting
2021-02-09 20:47:30.873 T:25225  NOTICE: Trying to open: samplerate: 44100, channelMask: 12, encoding: 4
2021-02-09 20:47:30.927 T:25225  NOTICE: CAESinkAUDIOTRACK::Initializing with: m_sampleRate: 44100 format: AE_FMT_FLOAT (AE) method: PCM stream-type: PCM-STREAM min_buffer_size: 22688 m_frames: 1418 m_frameSize: 8 channels: 2
2021-02-09 20:47:30.992 T:597  NOTICE: EMBY.hooks.monitor.Monitor ->  [ update/0 ] kodi_id: 2096 media: movie
2021-02-09 20:47:31.252 T:25248  NOTICE: EMBY.hooks.player.Player -> [ onPlayBackStopped ]
2021-02-09 20:47:31.606 T:25248  NOTICE: EMBY.hooks.player.Player -> --<[ playback ]
2021-02-09 20:47:31.783 T:25299  NOTICE: EMBY.library.Library -> -->[ q:download/157345120160 ]
2021-02-09 20:47:32.164 T:608  NOTICE: EMBY.hooks.monitor.Monitor -> [ UserDataChanged ] {'MonitorMethod': 'UserDataChanged', u'UserId': u'e2d7a192270d4ecda2332cf6ef46407c', u'UserDataList': [{u'ItemId': u'149456', u'IsFavorite': False, u'Played': False, u'PlayedPercentage': 9.4278666856657125, u'PlaybackPositionTicks': 6140000000, u'PlayCount': 0}, {u'ItemId': u'147426', u'PlayCount': 0, u'PlaybackPositionTicks': 0, u'IsFavorite': False, u'Played': False}]}
2021-02-09 20:47:32.168 T:608  NOTICE: EMBY.library.Library -> ---[ userdata:2 ]

 

 

Could have something to do with the Playcount.

Seems it was 4 and after second watch it's 0. Also PLayed was set from True to False

In you example, have you started the movie via Kodi movie selection or via plugin options menu (or a node which redirects you to plugin (movie) lists).

Edited February 10, 2021 by quickmic

[quickmic 1342]

@bozrdnag

I think I found the issue and fixed it.

It only appears, when you don't stop the movie/episode etc. after played and just play next. Currently the fix prevents Kodi status updates in such cases, not sure if Emby server has the correct status.

 

Further tests are required, please test 5.1.14 as soon as I upload the new version.

 

[bozrdnag 73]

I'm not understanding the situation you're saying where it happens. 

[quickmic 1342]

New Version available 5.1.14:

You can load from here, or wait till repo is synced.
http://embydata.com/downloads/addons/xbmb3c/multi-repo/beta-leia/plugin.video.emby-next-gen/plugin.video.emby-next-gen-5.1.14.zip

Fixes:
Incremental Sync rewritten: Remove unnecessary updates, should improve performance and correct issues
Progress update to Emby server corrected. Transcoding etc is now reported correctly

 
New:
Transcoding audio options added

Known issues:
Multiserver not working
Dynamic lists slow/artwork
Special episodes play index -> Kodi seems to have a bug. Index is one increment off (too low)

General info:
-

 

[quickmic 1342]

New Version available 5.1.15:

You can load from here, or wait till repo is synced.
http://embydata.com/downloads/addons/xbmb3c/multi-repo/beta-leia/plugin.video.emby-next-gen/plugin.video.emby-next-gen-5.1.15.zip

Fixes:
Background sync not paused while playback

 
New:
-

Known issues:
Multiserver not working
Dynamic lists slow/artwork
Special episodes play index -> Kodi seems to have a bug. Index is one increment off (too low)

General info:
-

 

Edited February 13, 2021 by quickmic

[dml33 23]

Hi. 

I have noticed an strange behavior I did not have with the old plug in. 

By default, all movies are started to be played with subtitles disabled and the last subtitle track selected. 

Then, I have to pause it, enable subtitles and choose the first subtitle track (English). 

This happens every time, even if I choose to save this choice (enabled and English track) as default for all movies... 

Is the plug in responsible for this? 

[DarWun 266]

@quickmic I just updated to to Emby for Kodi 5.1.15. After doing so, I am happy to report that forced HEVC transcoding from Emby for Kodi is now being detected by the Emby server.

Thanks!

Edited February 14, 2021 by DarWun

[bozrdnag 73]

On 2/10/2021 at 2:17 PM, quickmic said:

@bozrdnag

I think I found the issue and fixed it.

It only appears, when you don't stop the movie/episode etc. after played and just play next. Currently the fix prevents Kodi status updates in such cases, not sure if Emby server has the correct status.

 

Further tests are required, please test 5.1.14 as soon as I upload the new version.

 

I just installed 5.1.15 and this issue seems fixed.  I have tried about 15 espisodes/movies and none have been marked as unwatched.  Emby and Kodi both always update the new resume point so it is acting exactly as I would expect.  Thanks so much!

 

If you don't mind, for the sake of me understanding, can you explain the circumstances that would cause this?  I didn't understand your initial explanation.

[DarWun 266]

Minor glitch (I think). Emby for Kodi legacy shows an exclamation mark in the interface when transcoding which, when clicked on, tells why transcoding is occurring.

 

Emby for Kodi Next-Gen does not.

 

Edited February 14, 2021 by DarWun

[quickmic 1342]

7 hours ago, dml33 said:

Hi. 

I have noticed an strange behavior I did not have with the old plug in. 

By default, all movies are started to be played with subtitles disabled and the last subtitle track selected. 

Then, I have to pause it, enable subtitles and choose the first subtitle track (English). 

This happens every time, even if I choose to save this choice (enabled and English track) as default for all movies... 

Is the plug in responsible for this? 

 

Yes it is.

Problem: When srt subtiltes are loaded from Emby server, Kodi API always enables them. Even if no default subtitles are selected.

That's why I forced them to turn off on srt load. Maybe I find a better solution, respecting the subtitle settings...

[quickmic 1342]

4 hours ago, bozrdnag said:

I just installed 5.1.15 and this issue seems fixed.  I have tried about 15 espisodes/movies and none have been marked as unwatched.  Emby and Kodi both always update the new resume point so it is acting exactly as I would expect.  Thanks so much!

 

If you don't mind, for the sake of me understanding, can you explain the circumstances that would cause this?  I didn't understand your initial explanation.

It mostly happened when the "Stop event/End Event" was not triggered.
A movie/episode etc can end by push (remote) stop button -> Stop event, or movie has been fully watched -> End event, or by push (remote) next button -> jump to the next movie.
Most times the issue happens, when the Stop event was not triggered.

The actual problem was in the code design:
On playback started, the ID of the video was flagged as "skip updates" and here started the problems.

Background info: Currently playing files reports the progress each 4 seconds and immediately on playback start and playback end to the Emby server. The Emby server sends the status back to all connected clients via Websocket.
This would cause a loop. Kodi -> Server -> Kodi. Therefore self initiated playbacks are flagged as "skip updates".
This flag is set on playback start and removed on e.g. Stop event. -> as explained before.
If the Stop event was not triggered, the "skip updates" flag was overwritten by the new played file ID and never skipped the updates from Emby server.
This is a performance issue, cause e4k always updated itself. Also season info updates are send by Emby server which have a different ID as the ID saved in "skip updates" (currently played file ID).
Also the updates from Emby-server are not instantly. They are almost realtime, but still there can be a gap between stop event triggered and update infos send from Emby server.
The "skip updates" flag could be reset, before Emby server status updates are send.
You see these are all (performance) issues -> Cycle updated. Anyway, all of them should not cause a wrong status but there is another issue.

Kodi triggers also events when a state of a Kodi item has changed. This event is used to sync the watched/unwatched state with Emby server.
e.g. context menu -> mark as watched/unwatched fires the event. Also regular status changes (e.g. fully watched movies) fires the events.
This code was broken and reported (sometimes) wrong information.

Reason why I'm telling all this:
(Broken) status code send status to Server -> Server (sometimes) received wrong info.
Till here all good with Kodi status, but possibly wrong info are reported to Emby server.
Now, Emby server send the info back to all clients.
It could be, that the "skip updates" was still enabled and the wrong info were skipped. -> Kodi status correct
It could be, that the status info was correct even if not skipped. -> Kodi status correct
Issue, the status info was incorrect and not skipped. -> Kodi status corrupt.

I fixed the broken status report code. This prevents the issue, but not the useless update reports from Emby server.
I also redesigned the "skip updates" code. It saves all played files IDs and the corresponding season and tvshow IDs in an array to skip all of them until the update is received from the Emby server. So "skip updates" are not reset on Kodi stop events anymore. It's deleted after Kodi received the status updates back from Emby server. This prevents all the "self send" progress/status updates -> Cycle updates.

In a very unlikely scenario, that the movie was updated from Emby server due to other reasons (manually edit on server the tags) of a currently played movie, those infos are also skipped.
Therefore the infos are only updated on Kodi restart. On Kodi restart other update mechanism are used for sync (based on timestamps of the last Kodi start). So all info are refreshed here again, even if the came from the same device in a previous session. Explaining that would go too far, but I think you got an impression what went wrong.
It was a timing issue combined with broken code in some cases and unnecessary cycle updates.

 

btw, I'm still observing event updates. probably there are still some issues in the code.

Edited February 14, 2021 by quickmic

[quickmic 1342]

4 hours ago, DarWun said:

Minor glitch (I think). Emby for Kodi legacy shows an exclamation mark in the interface when transcoding which, when clicked on, tells why transcoding is occurring.

 

Emby for Kodi Next-Gen does not.

 

 

You are right, I didn't add this info. I'll re-add it in the next version.

[quickmic 1342]

Update:

There is still a bug in the status updates. It prevents updates incoming from other devices if the same tvshow was previously played on the current device.

I'll fix it soon.

[dml33 23]

7 hours ago, quickmic said:

 

Yes it is.

Problem: When srt subtiltes are loaded from Emby server, Kodi API always enables them. Even if no default subtitles are selected.

That's why I forced them to turn off on srt load. Maybe I find a better solution, respecting the subtitle settings...

Hi.

Thanks for looking at it. 

It seems that there is still a remanent problem with subtitle language flags, since I have Kodi configured to take English subtitles by default, but, when I play a movie, another track appears selected, which is not the English one. This mechanism was working correctly with the old plug in. 

Another thing is that the subtitle shall be enabled or disabled based on Kodi settings, too. But, if there is a limitation just related to Kodi API, a ticket shall be opened to Kodi to be able to give the correct behavior. 

Thanks again for your work. 

[quickmic 1342]

3 hours ago, dml33 said:

but, when I play a movie, another track appears selected

Are there srt subtitles involved? If not, it's a Kodi bug.

If yes, I can have a look.

Quote

But, if there is a limitation just related to Kodi API, a ticket shall be opened to Kodi

Not me, I learned my lesson reporting bugs to Kodi devs. Probably I can find a workaround.

[dml33 23]

27 minutes ago, quickmic said:

Are there srt subtitles involved? If not, it's a Kodi bug.

If yes, I can have a look.

Not me, I learned my lesson reporting bugs to Kodi devs. Probably I can find a workaround.

Yes, I always use srt external subtitles. 

Hahaha, once I submitted a pull request and it was incredibly painful. I gave up at the end 

[tosa65 16]

Quick question:
There is a red N at the top-left of the cover.
Is this from Emby and if so, how can I remove it?

Thanks in advance,
Tommy
 

[quickmic 1342]

New Version available 5.1.16:

You can load from here, or wait till repo is synced.
http://embydata.com/downloads/addons/xbmb3c/multi-repo/beta-leia/plugin.video.emby-next-gen/plugin.video.emby-next-gen-5.1.16.zip

Fixes:
Sync issue fixed: https://emby.media/community/index.php?/topic/90781-embyforkodi-500-preview/page/31/&tab=comments#comment-985696
Not absolute perfect yet, but close

 
New:
Transcode info added

Known issues:
Multiserver not working
Dynamic lists slow/artwork
Special episodes play index -> Kodi seems to have a bug. Index is one increment off (too low)

General info:
-

 

 

[quickmic 1342]

13 minutes ago, tosa65 said:

Quick question:
There is a red N at the top-left of the cover.
Is this from Emby and if so, how can I remove it?

Thanks in advance,
Tommy
 

Can you upload a screenshot?

[tosa65 16]

56 minutes ago, quickmic said:

Can you upload a screenshot?

Yes...sure
 

[quickmic 1342]

This looks like Netflix images.

[tosa65 16]

4 minutes ago, quickmic said:

This looks like Netflix images.

Yes, I know it looks like the Netflix logo.
I just don't know how it gets there?

If it doesn't come from EmbyforKodi, then I'll ask somewhere else again. Maybe it's the skin. I'll try that out right away. I'll get back to you if necessary... 

Thanks for now.
Tommy
 

[tosa65 16]

Sorry that I hadn't tried it with another skin before... In fact, it's gone with the other skin.

I have already told a skincoder.
 

[DarWun 266]

14 hours ago, quickmic said:

 

You are right, I didn't add this info. I'll re-add it in the next version.

Can confirm this is fixed in 5.1.16. Thank you @quickmic!

Something else I noticed today with subtitle selection. When selecting an HEVC video to play with force transcode enabled, there is a popup in Emby for Kodi asking for you to select the subtitle stream. Emby for Kodi next-gen starts playing the video after a couple of seconds without waiting for a subtitle selection. Also, Emby for Kodi legacy includes an option in the subtitle list for "none" so that you can play the media without subtitles. Emby for Kodi does not (although selecting the option to cancel subtitle selection seems to play the video with subtitles turned off). 

[e2zippo 21]

Hey @quickmic!

Last night I was trying to watch some stuff and I now have problems getting movies to play, I get the loading animation but the playback never starts.

It must related to some change made in perhaps  the last two versions, since I didn't have problem before that.

A reboot solves it, but the problems quickly comes back.

I tried to reset the Kodi database and resynced everything, but that didn't help.

Should I send you my embyserver.log from yesterday?