Plugin.video.netflix: Netflix addon causes high CPU load when starting music playback

[mrblond18]

Hello all,
I am enjoying the Netflix addon a lot and it works very nice, WAF is rather high.

However, I observe a strange error. When I play my music files it always used to show the lyrics, using the CU Lyrics addon. When I enable the Netflix addon, no lyrics are shown when playing music (from a large playlist, single albums still work to make it even more crazy). I have described it in more detail here:
https://forum.kodi.tv/showthread.php?tid=356465&pid=2972517#pid2972517

It looks like the netflix addon causes high CPU usage for a certain amount of time (depending on the playlist size) when starting music playback.

Any idea how to fix?

[CastagnaIT]

The behavior is particularly strange, because the netflix service is idle when not used for playback or auto-sync.

First is mandatory a Kodi log taken when this problem happen, but before you have to enable netflix debug info, see the readme for how to, and reboot kodi.

I need to know if you use netflix with some sync feature or scheduled update (whats settings sets?)

I do not know CU Lyrics addon,
so i need you explain steps to install (download link and related github? i do not found your version) and how use it in order to try reproduce it in my station

[mrblond18]

The behavior is particularly strange, because the netflix service is idle when not used for playback or auto-sync.

First is mandatory a Kodi log taken when this problem happen, but before you have to enable netflix debug info, see the readme for how to, and reboot kodi.

I need to know if you use netflix with some sync feature or scheduled update (whats settings sets?)

I do not know CU Lyrics addon,
so i need you explain steps to install (download link and related github? i do not found your version) and how use it in order to try reproduce it in my station

clear, will supply the requested info tonight

[mrblond18]

OK, I am using the latest Netflix plugin 1.8.0 and the CU LRC Lyrics plugin version 5.7.4 from the Kodi Add-on repository (https://gitlab.com/ronie/script.cu.lrclyrics/)

Here a debug log when Netflix addon is disbabled and lyrics do appear. What I do is starting Kodi with debug logging enabled, going into the music section and then into songs. Next I start playback of a track (Sex laws by Beck). I go into the music visualization screen (where the lyrics are shown during playback) and the lyrics show up after a few seconds. I stop playback and quit kodi. Since debug logging is enabled I can see the CPU usage and Kodi CPU usage is at about 40% during music playback.
https://paste.kodi.tv/aqubomukol.kodi

Here a log where Netflix is enabled and no lyrics appear. What I did here is opening kodi (with Netflix enabled) goto the Netflix addon settings enabling verbose logging, going into the system settings and enabling verbose logging there. Next, I go into the music section and then into songs. Next I start playback of a track (Sex laws by Beck). I go into the music visualization screen (where the lyrics are shown during playback). No lyrics are shown and after about 30s I stop playback. Because verbose logging is enabled I can see the CPU usage and I can see that Kodi CPU usage is constantly above 110% during music playback. After stopping the music playback I quit kodi.
https://paste.kodi.tv/izepehucih.kodi

My netflix settings are here:
https://paste.kodi.tv/eladocaqaf

Is this enough info?

[CastagnaIT]

well, i have tried to install your version of CU Lyrics on Kodi 18
but i have not found your problems on my station

These are my tests and results on my station:

• i have tried several times to play mp3 of various artists and displaying texts lyrics and has worked as expected
• i have verify the NF service by put in some more debug point to try track some activity, as a result there are no service activities
• i have tried play a netflix video, and after play a mp3 with show lyrics, but has worked as expected

In all my cases the CPU usage is regular.

In your the second log

https://paste.kodi.tv/izepehucih.kodi

there is no netflix debug info and there is no addon initialization trace,
so or you have forgot to enable netflix or you have forgot to enable netflix verbose debug or you have taken a wrong file
then is needed a new good log

At the moment i have no idea what kind of problem there is in your Kodi

In the past some users have found strange behavior of Kodi, when a Kodi's database is corrupted,
you can try making a backup copy of Kodi user data folder,
then delete the Kodi user data folder, so kodi starts from scratch,
try to see if the issue persist, if it persists you can restore the Kodi user data backup

[mrblond18]

In your the second log

https://paste.kodi.tv/izepehucih.kodi

there is no netflix debug info and there is no addon initialization trace,
so or you have forgot to enable netflix or you have forgot to enable netflix verbose debug or you have taken a wrong file
then is needed a new good log

What I did in that log was enabling verbose logging after kodi was started. Here is a log where verbose was already on at startup (both kodi and netflix verbose logging):
https://paste.kodi.tv/jefoqifipi.kodi
Does this give the required info?

I have already started with a clean kodi settings, however, the only thing I kept intact (because my music library is stored there) was the database using an external mysql library. Do you think it is useful to also start with a clean (music) library/database?

[CastagnaIT]

@mrblond18 yes now the debug is good, but i do not seem to see nothing of particular

@ronie can you tell me some more info? you have said

i suspect it's the netflix background service that's doing something odd.
it's causing very high cpu usage for around 15 seconds whenever i start music playback.
... and that's with cu lrc lyrics disabled.

how i can reproduce it on my station? i tried but without success (on window 10)
is there any particular setting/setup?
Does it only occur in a linux environment?

[ronie]

i'm running kodi 19 (current master) on Manjaro Linux.

I've tested it with no other addons installed, besides Netflix.
(i'm not familiar with your addon, don't have a netflix account, did not configure anything)

so what i did:

• set debug logging level to verbose in the netflix addon
• enabled debug logging in kodi
• played some music

this is causing high cpu usage for ~ 15 seconds when playback starts:

debuglog: https://paste.kodi.tv/qucosotowa.kodi

the high cpu usage does not occur if play music with the Netflix addon disabled.

[mrblond18]

I am running kodi 18.8 on Ubuntu 20.04 where this problem occurs.

As a test I also tested this on Kodi 18.8 on Windows 10. I have the same kind of problems there.
I started with a completely fresh kodi install. I only added my music source and let it create a new local database with the music info. I installed cu lrc lyrics addon. Lyrics were shown and no high cpu usage (windows only shows total cpu usage by kodi, it is about 25%).
Then I installed the netflix addon (did not configure it) and then the CPU usage is high all of a sudden when playing music (between 60% and 70%). When I stop music playback it drops back to about 15-20%. If I disable the netflix addon, cpu usage is back to normal again while playing music.

[mrblond18]

@ronie
offtopic:
we hebben dezelfde muzieksmaak zie ik...

[CastagnaIT]

Tried again, this time under Kubuntu + Kodi 19
and i cannot reproduce the problem...perhaps missing some operation?!?

This is what i do:
-Add to Music library an external hdd folder with various albums
-Wait the Kodi screaper done
-Select an album, on the album name with context menu select "Play"
-Now i open sidebar, and click on "4 arrows":

the lyrics now appears, but CPU is normal...
what missing?

[mrblond18]

I do see a difference. What I do is opening the complete "Songs" list under the Music menu item and starting playback from there. I have the impression the high cpu only occurs for larger playlist (my songs collection is about 25k tracks). Selecting a single album will only be a dozen of tracks...

Further, all my songs are stored on a samba share. I do not know how you access them.

[CastagnaIT]

well,
now i tested again by opening "Songs" list, with a list of more than 2000 songs
but i have differents results from you:

These are the tests:
Windows 10 + Kodi 18.8 + installed NF and Disney add-ons
in all tests tried to play 5 differents songs (play then stop, than play etc.. not pressed next button)

Test 1: NF + disney all enabled
Test 2: NF + disney all disabled
Test 3: NF + nf disabled + disney enabled

in all tests i have always same results
some songs the lyrics works in other played songs the lyrics are stucked from about 8 to 15 secs
the CPU is always normal, perhaps my old AMD better manage the situation ?! boh..

then from my test the issue seem not related to a specific add-on

[CastagnaIT]

I have forced lrc lyrics to output debug info

This is the log:
https://paste.kodi.tv/bogunefoyo.kodi

Every time that the problem happen, the script was stucked at line 838 from module lyricsScraper.py

DEBUG: script.cu.lrclyrics: TTPlayer: searching lyrics for Ricky Martin & Christina Aguil - Solo Quiero Amarte [Nobody Wan

Then after a lot of second has raised an error, line 849:

DEBUG: script.cu.lrclyrics: TTPlayer: LyricsFetcher::get_lyrics (149) [[Errno socket error] timed out]

After this error, the lyrics are appears on screen

This is an example of the url composed requested by uurllib from TTPlayer:
http://ttlrccnc.qianqian.com/dll/lyricsvr.dll?sh?Artist=67007200650065006e00640061007900&Title=6a006100640065006400&Flags=0

seem that the server called is not working well or not working at all... and this stuck the lirics addon

I think it is better handle the urllib call with a timeout value
and better handle the exceptions to not stuck the addon script

[CastagnaIT]

@mrblond18 can you try install and use this pathed version?
script.cu.lrclyrics_leia_patched.zip

[mrblond18]

Too bad, same problem. I enabled kodi debug logging and cu lrc lyrics logging.

Single album works without a problem. Playback starts immediately and lyrics load immediately, skipping to next song immediately show lyrics for that song. CPU load is 40-50% (cpu-kodi in status window with debug logging enabled). Kodi quits properly.
Log here:
https://paste.kodi.tv/owarehiwoy.kodi

Playing from the complete Songs section makes it hang for about 10s before starting playback and gives a CPU load of about 115% (cpu-kodi) and no lyrics (also no lyrics status message in the top right corner). CPU usage stays high even after stopping playback, and kodi does not quit properly (have to kill it from the terminal).
Log here (log was too large for kodi paste service):
https://bartthbo.stackstorage.com/s/aUfINNG6kmB1ga02

Had another weird behaviour (which I think can be very useful). When trying out the songs section playback again, suddenly I got lyrics for the first song I started and CPU stayed low for the first few seconds. After a few seconds CPU increased. Going to the next track did not give any new lyrics, the old lyrics just stayed on top. Even after stopping playback the lyrics window stayed open (so it overlapped the overview in the songs section). Stopping kodi failed, had to manually quit again. Maybe I started playback very fast after starting kodi, so a service that causes the high cpu load after playback of a song had not started yet...
Log here (log was too large for kodi paste service):
https://bartthbo.stackstorage.com/s/6GaHuPNicJmJ13BD

[jakermx]

Hi there..... it looks that your Samba Share is looking externally for NAS or Windows Based Networking Device that is causing the mess, try using local mp3 files, I would also suggest you to use File Based Network Resolution for Samba Daemon.

Look at your logs, when it works fine, it calls an smb share using its IP (192.168.1.96 if this is your device IP change the advanced settings to user 127.0.0.1 instead , it ill be better and faster) and when it goes high CPU is usinh name based smb share (NUC). Based on this I think that when the background services from Netflix Starts, some Add-On or its Dependencies, recall yours settings but do a mess.

So For Diagnosis try to use all local, and share your findings, then try disable Netflix an Lyric Add Ons, restart Kodi, Then Enable Netflix First then Lyric Service, that way you will force a Setting Over ride and play some files local or smb, it would work fine till you restart caus the service boot order.

It is just a suggestion that I would do fo testing it.... I had that issue in the past when have Head End Srver and HTS Client running on the same machine that have the netflix AddOn.

Cheers!

[jakermx]

Update....

I Got a i3 Laptop, I did a clean Ubuntu Mate 18.04.04 LTS Install, then updated and upgraded via apt-get...rebooted and added kodi ppa repositories installed 18.8 version, added CULyrics rebooted played and showed Lyrics as suppoused to do it, then added Netflix Repo, installed Add On and reboot.....it went a mess.

I disabled CULyrics and then enabled it...and it fixed it.

Finally, I Disabled and Enabled Netflix AddOn and when playing music, Lyrics go faster and got in loop...but, CPU never went up to 40%

I am still testing.... soon I will share the logs, of these tests

[jakermx]

I can confirm that it is not Netflix Add On related issue....

It is HTTP request calls queue irelated issue....the way to reproduce it is:

Start KODI wit NF AddOn Disabled

Go Music Select a song... then go player...then go Next...wait Lyrics then go Next wait 1 sec and go Next and go Next...wait for Lyrics...and finally go Back Back Back....with 1 sec waiting between calls... it will display otrher song lyrics and finally hang the Lyric Display, till stop and wait till all script instances ends.

https://github.com/jakermx/experimental/blob/master/kodi.log

[jakermx]

I did the test using local files and smb files, settting CULyrics to download and use local files....wit the same results.

I think that CULyrics needs a watchdog like AddOn Signals to react as fast as the Player notify any update, And also needs to handle HTTP Request calls, instead of queueig them. without watchdog. Caus any other AddOn HTTP calls will have the same results

[CastagnaIT]

Side note: the netflix http servers answer all on 127.0.0.1 but only to a specific port that is randomized every time the addon is restarted, then is not possible that lrclyrics known every time what NF port to call. Even if it happens, unrecognized http calls are immediately rejected by NF http server without any waiting.

@jakermx you have to enable debug in lrclyrics settings to see something

I think that CULyrics needs a watchdog like AddOn Signals to react as fast as the Player notify any update

if possible methods calls with Addon Signals should always be avoided,
NF addon use it because the service side is particular,
the service live with multiple threads that host http servers that within host the classes to be execute, the AddOn Signals is the only way to call a method in another thread/server (I forgot that it is used for IPC between client-service instaces, is not the case of CULyrics)

instead CULyrics is a script, that currently live with a single thread, exept for the GUI Dialog because is modal

I think that in CULyrics code need more improvements, and also the code is rather scruffy dead style (no offense to ronies is a big work but need more love...)
I have not analyzed the code well, at a glance, seem there are some critical issues:

• The large use of xbmc.getCondVisibility that is some cases should be avoided to avoid unexpected problems, like prefetch the value to a common variables
• myPlayerChanged seem to be the core, but is in the main thread, so if a screaper is too slow and blocks the execution, or the user change/stop track too fast can happen a disaster and therefore can no longer works for a bit of time or view wrong results.
  So i think that myPlayerChanged should be called in a separated thread every time, maybe with a thread enclosed on a Monitor or Player object to intercept playback changes and in case terminate automatically the thread without continuing with screaper or viewing GUI, or in any case something of similar...

in my test case internal screaper TTPlayer are too slow and not respond, then stuck the code until about 15 secs,
and cause the critical issues mentioned before and therefore the CULyrics addon is unresponsive to user actions,
and i think this is all related also to your problems

[jakermx]

@CastagnaIT Yes I did...also I enabled component debug

[CastagnaIT]

there is no CULyrics debug info

[jakermx]

ooopps, let me Redo it

[jakermx]

https://github.com/jakermx/experimental/blob/master/NF-Enabled.log
https://github.com/jakermx/experimental/blob/master/NF-Disabled.log

Done!

I did a lot of keystrokes to delimitating when starting playing and when it hanged.

[CastagnaIT]

well done, seem you have encountered same issue that i found

@ronie CULyrics seem need to be partially modified to manage some problems, see my last comments
and need to be check the TTPlayer that not works, i suggest also a smaller timeout in urllib like max 4-5 secs instead 10
in worst case scenario if every screaper takes 10secs (for any problem), blocks the code for very long time

[CastagnaIT]

Here i close, i have nothing to do from my part

[mrblond18]

that's ok, I am trying to tackle this with ronie, the developper of the cu lrc lyrics pluging. Thanks for the help