Netflix addon causes high CPU load when starting music playback - 2nd try #859

mrblond18 · 2020-09-10T21:12:41Z

Bug report

Your Environment

Netflix add-on version: 1.9.0
Operating system version/name: Ubuntu 18.04
Device model: Intel NUC, CPU: Intel(R) Core(TM) i3-8109U CPU @ 3.00GHz, 4 cores available

Used Operating system:

Describe the bug

I have reported this bug earlier (#828), but then it was concluded that the CU LRC Lyrics addon was the problem. That addon is fixed and the problem still occurs, even with the lyrics addon not installed.

I started with a vanilla configuration, added my mysql music library (in advancedsettings.xml) and added my samba based music share (containing about 30k tracks). I played back a song from the music->songs menu and kodi cpu usage stayed below 30%. Logging here:
https://paste.kodi.tv/xopeberaya.kodi

Then I installed the netflix addon as well and started playback of the same song. Then CPU spikes to over 100% for about 15s. When I stop playback and start again, CPU spikes again for this 15 seconds. Third time, same result. Log here:
https://paste.kodi.tv/axesurezem.kodi

Expected behavior

CPU usage when starting music playback should not be higher when netflix addon is installed.

Actual behavior

cpu usage spikes for about 15s

Steps to reproduce the behavior

see "describe the bug" section

Possible fix

don't know

Debug log

see "describe the bug" section

Additional context or screenshots (if appropriate)

Installation

[ x] I'm using other Netflix Repo 1.0.1

Other information

started with a clean config, as described in the "describe the bug" section

Screenshots

jakermx · 2020-09-10T23:27:30Z

Could you try open a second session on console or via ssh and try sudo top -H command to see the CPU eater thread , you can run it in batch using sudo top -Hb andsave it to a file using > pipe

ps -aux is another option to check

CastagnaIT · 2020-09-11T07:01:56Z

POST EDIT: i see now same author of thread..

I could theorize a Kodi problem that with some CPU is not able to good handle the threads

I could tell you to do two tests:

you can redo the tests by installing
disney addon (no login) and keep disabled netflix
to see what happen
i can try provide you a modified nf addon version with 2 inactive thread instead of 3 inactive thread and see what happen

CastagnaIT · 2020-09-11T07:30:17Z

another try is install an older version of Kodi 18, e.g. 18.6
to see if it is a problem of last versions of Kodi
this is important to understand if the cause is external
because the netflix service is never changed, use the same behaviour from years

mrblond18 · 2020-09-11T09:32:40Z

Could you try open a second session on console or via ssh and try sudo top -H command to see the CPU eater thread , you can run it in batch using sudo top -Hb andsave it to a file using > pipe

ps -aux is another option to check

I think this is the info you need.
I started the "sudo top -Hb > top.log" command
I started kodi
Went into music->songs, started playback of a song (observed the high CPU usage)
I waited for the CPU usage to drop to normal levels (about 15-20 seconds).
Stopped the playback
Started playback of same song
Waited for cpu to drop and stopped playback
Quit kodi
stopped the top command.

Kodi log:
https://paste.kodi.tv/iyoqorubey.kodi

Top batch log:
https://paste.kodi.tv/ihifagehuk

My own investigation using your request already revealed it is the "LanguageInvoker" thread that is using all cpu...

mrblond18 · 2020-09-11T09:43:16Z

POST EDIT: i see now same author of thread..

I could theorize a Kodi problem that with some CPU is not able to good handle the threads

I could tell you to do two tests:
1. you can redo the tests by installing
   disney addon (no login) and keep disabled netflix
   to see what happen

2. i can try provide you a modified nf addon version with 2 inactive thread instead of 3 inactive thread and see what happen

I installed the disney+ addon (did not configure anything of the addon and did not install netflix addon), and the problem does not occur... Do you need debug log (kodi and top)?
more than willing to try it out :-)

mrblond18 · 2020-09-11T09:45:24Z

another try is install an older version of Kodi 18, e.g. 18.6
to see if it is a problem of last versions of Kodi
this is important to understand if the cause is external
because the netflix service is never changed, use the same behaviour from years

The problem does not occur for me since I updated kodi to latest version, but since I have decided to start including my music library in kodi... So let's see what the other results so far can help us. I'd rather not downgrade kodi on my htpc which I use on a daily basis. Switching configs is easy, kodi versions not so much (for me)...

CastagnaIT · 2020-09-11T09:56:33Z

Try this:
Before update with following zip,
turn off ""Sync the watched status of the viddeos with netflix" from addon settings
so try to see if the problem persist

After this, update with:
plugin.video.netflix_1.9.0_2server.zip
wait the NF service starts, but do not open the addon or will crash
so try to see if the problem persist again

mrblond18 · 2020-09-11T10:30:59Z

Try this:
Before update with following zip,
turn off ""Sync the watched status of the viddeos with netflix" from addon settings
so try to see if the problem persist

After this, update with:
plugin.video.netflix_1.9.0_2server.zip
wait the NF service starts, but do not open the addon or will crash
so try to see if the problem persist again

The previous tests I did were with an unconfigured netflix plugin, so "sync the watched status of videos with neflix" was already off.

I installed your updated plugin, but problem persists.

kodi debug log:
https://paste.kodi.tv/eposuyuzuq.kodi

top log:
https://paste.kodi.tv/ihajabaqug

Again LanguageInvoker is the one eating up CPU...

CastagnaIT · 2020-09-11T11:33:42Z

The LanguageInvoker are threads where each type of addons live (normal with gui, service, scripts ecc...)

the main problem is that Kodi 18 is EOL, the support is terminated,
if there is a bug in Kodi 18 will remain so,
it is better that you provide a report with Kodi 19

You can do in this way to not lost your current Kodi data+addons+userdata:

backup the hidden folder ".kodi" in home directory
delete kodi 18
install kodi 19 and try reproduce the problem

Then to restore Kodi 18:

delete kodi 19
install kodi 18
delete the hidden folder ".kodi" and restore the backup one

After this i can open a thread in the Kodi forum to ask to Kodi dev
some help because i do not see clear this situation

mrblond18 · 2020-09-11T12:13:43Z

The LanguageInvoker are threads where each type of addons live (normal with gui, service, scripts ecc...)

the main problem is that Kodi 18 is EOL, the support is terminated,
if there is a bug in Kodi 18 will remain so,
it is better that you provide a report with Kodi 19

You can do in this way to not lost your current Kodi data+addons+userdata:

backup the hidden folder ".kodi" in home directory

delete kodi 18

install kodi 19 and try reproduce the problem

Then to restore Kodi 18:

delete kodi 19

install kodi 18

delete the hidden folder ".kodi" and restore the backup one

After this i can open a thread in the Kodi forum to ask to Kodi dev
some help because i do not see clear this situation

Thanks, I have used the “trick” with the .kodi folder a lot. However, how do I upgrade to kodi 19 and downgrade to kodi 18 later on?

CastagnaIT · 2020-09-11T12:16:38Z

oh good
you can try to upgrade it by installing kodi 19 over 18 (you have also to upgrade NF addon the v18 is not compatible)
but rollback from 19 to 18, i don't recommend it, you could break all dependncies

mrblond18 · 2020-09-11T12:18:45Z

oh good
you can try to upgrade it by installing kodi 19 over 18
but rollback from 19 to 18, i don't recommend it, you could break all dependncies

Then I’ll be stuck on 19 which is an alpha release which I can not rely on. Since this is my main device for consuming media I am reluctant. I will try to find more info online...

CastagnaIT · 2020-09-11T12:21:22Z

why? it is only a temporary attempt to understand if the issue persist on Kodi 19
you have not to maintain the version 19

mrblond18 · 2020-09-11T13:37:45Z

why? it is only a temporary attempt to understand if the issue persist on Kodi 19
you have not to maintain the version 19

I think you stated before that going from kodi 19 back to kodi 18 is not recommended/unwise. I do not want to go to alpha version for normal media consumption...

Anyway, I'll find a way to test on kodi 19. I'll keep you posted

CastagnaIT · 2020-09-11T14:11:52Z

i think you do not understand
there is two similar way to do these thing

Use the Kodi automatic migration:
so you can install Kodi 19 over Kodi 18
but you can not use this method to rollback automatically (install 18 over 19) could broke the dependencies and your data.
do install from scratch and use an existent kodi 18 user data:
so you need a backup copy of the hidden .kodi of your current Kodi 18
and use it every time you install from scratch Kodi 18 or 19 to restore all your current data
in this way you do not need to do the rollback because you restore all data manually

mrblond18 · 2020-09-11T15:34:26Z

The LanguageInvoker are threads where each type of addons live (normal with gui, service, scripts ecc...)

the main problem is that Kodi 18 is EOL, the support is terminated,
if there is a bug in Kodi 18 will remain so,
it is better that you provide a report with Kodi 19

You can do in this way to not lost your current Kodi data+addons+userdata:
* backup the hidden folder ".kodi" in home directory

* delete kodi 18

* install kodi 19 and try reproduce the problem
Then to restore Kodi 18:
* delete kodi 19

* install kodi 18

* delete the hidden folder ".kodi" and restore the backup one
After this i can open a thread in the Kodi forum to ask to Kodi dev
some help because i do not see clear this situation

OK, I succeeded to install Kodi 19 Matrix (and later on downgrade to 18 Leia). After updating to 19, I started with a fresh configuration, added my mysql musicdatabes and added my samba music source.

Unfortunately (or not) the problem is exactly the same.

Before installing Netflix I tried playback of music, there no increase in CPU usage can be observed. Log here:
https://paste.kodi.tv/xuwenireva.kodi

I then installed Netflix. First I tried it using the repo zip (from https://github.com/castagnait/repository.castagnait/raw/matrix/repository.castagnait-1.0.0.zip). I succesfully installed the zip, it showed the castagnait repository, but it was empty... I installed the version from your dropbox (plugin.video.netflix_1.8.0+matrix.1_20200909.zip). Then I started music playback and observed the high CPU load. Waited for CPU to drop, started playback again and observed high CPU load again. It took between 15 and 60 seconds for the CPU load to drop. Log here:
https://paste.kodi.tv/ecogusacol.kodi

CastagnaIT · 2020-09-11T15:50:32Z

good,
now i will try to open a thread in kodi forum
to try ask to Kodi dev some help
i will see if they can tell me something to do

mrblond18 · 2020-09-11T20:07:13Z

good,
now i will try to open a thread in kodi forum
to try ask to Kodi dev some help
i will see if they can tell me something to do

Can you give me a link to the kodi forum thread?

CastagnaIT · 2020-09-12T07:21:32Z

I did not had time, will do today

opened here: https://forum.kodi.tv/showthread.php?tid=357047

mrblond18 · 2020-09-16T18:32:45Z

I investigated some more. I tried the same on my Windows 10 notebook with the same type of results. Observations:

It does not matter if kodi is run on Windows or Ubuntu (tried on Windows 10 and Ubuntu 18.04)

It does not matter if the music library is stored locally or on a samba share (tried with an external usb hdd with the exact same library).

It does not matter if the music database is stored in the local kodi settings folder or in a mysql database.

It does matter how large the playlist is you start playback from (400 songs in the database give no problems, 6583 songs shows high cpu usage for a second or two, 25k songs gives unusable behaviour because of high cpu load for more than 30s. If you first select a specific artist (leading to less tracks in the playlist) no increase in CPU is observed).

It does matter if you install the netflix addon (without the netflix addon no increase in cpu usage is observed. Also when you install the netflix addon but disable it (leaving all the dependencies enabled), no increase in cpu is observed).

It does not matter if you configure the netflix addon or not (I tried both with logged in netflix addon and without any configuration change after installing the addon).

It does not matter if you use Kodi 18.8 or Kodi 19 Alpha1 (with the appropriate netflix addon for that kodi version).

CastagnaIT · 2020-09-17T06:21:52Z

i reported it also to kodi forum, unfortunately it does not help to restrict the field
I will try to prepare you a new version with more detailed debug on all code that could be influenced by Kodi activity
even if I didn't find anything the first time

mrblond18 · 2020-09-17T06:22:57Z

@CastagnaIT : it looks like we are suffering from this (general) kodi issue.
https://forum.kodi.tv/showthread.php?tid=213737

Netflix addon makes it worse, but the root cause is in the playlist handling... Do you think there is something to do on the Netflix addon side?

CastagnaIT · 2020-09-17T06:45:44Z

not exactly, the only thing that could be are the Monitor objects

a Monitor object is to receive what Kodi do in this moment (events) then receive a sort of message+data
it does not matter if the addon uses these messages or not, always receives them

so i can put a debug point to see if it gets something

CastagnaIT · 2020-09-17T06:53:08Z

Here
plugin.video.netflix_1.9.0_20200917_monitor_log.zip

if/when the addon will reveive monitor message we can see in the log something like:

2020-09-17 08:50:32.933 T:2764 ERROR : [plugin.video.netflix (0)] RECEIVED onNotification MESSAGE: Info.OnChanged

so if we find thousands of these it could be the possible cause

mrblond18 · 2020-09-17T07:35:05Z

Here
plugin.video.netflix_1.9.0_20200917_monitor_log.zip

if/when the addon will reveive monitor message we can see in the log something like:

2020-09-17 08:50:32.933 T:2764 ERROR : [plugin.video.netflix (0)] RECEIVED onNotification MESSAGE: Info.OnChanged

so if we find thousands of these it could be the possible cause

do we need debug logging for this (kodi and/or netflix)?

CastagnaIT · 2020-09-17T07:40:03Z

yes better enable kodi debug, nf debug verbose is not really needed but enable it, always without login

mrblond18 · 2020-09-17T08:04:39Z

Here you go:
https://bartthbo.stackstorage.com/s/c902l9KHDjvxKpKC
I see a lot of these (about 5000 times, often followed by a message that the line repeated for a few or a few thousand times...):
2020-09-17 09:43:18.992 T:78368 ERROR: [plugin.video.netflix (0)] RECEIVED onNotification MESSAGE: Playlist.OnAdd

What I did:
Debug logging on, nf logging to verbose.
High cpu when loading songs list, waited for it to go low again.
High cpu when starting playback
after 6minutes and 40 seconds cpu goes to normal level
7:00 I stopped playback
Cpu becomes high again (because playlist is generated once again).
Waited for cpu to become low again
Quit kodi

p.s. I noticed that if I disable kodi debug logging and netflix verbose logging the CPU usage goes low quicker (after about 3 minutes and 40 seconds). That might be due to the log flooding with messages.

CastagnaIT · 2020-09-17T08:40:44Z

This might confirm my suspicions
so that the Kodi playlist cause problems with Monitor object when a massive playlist operation is done

if so, creating an Test addon with the same Monitor objects should present the same CPU problems

I will create an addon test and if it confirms this theory,
means that Kodi has problems managing a wide flow of Monitor messages and need Kodi dev fix it

mrblond18 · 2020-09-17T09:03:51Z

This might confirm my suspicions
so that the Kodi playlist cause problems with Monitor object when a massive playlist operation is done

if so, creating an Test addon with the same Monitor objects should present the same CPU problems

I will create an addon test and if it confirms this theory,
means that Kodi has problems managing a wide flow of Monitor messages and need Kodi dev fix it

nice!

CastagnaIT · 2020-09-17T11:53:24Z

Try install this test addon, and disable netflix:
test.addon.zip

after reproduce the problem, exit from Kodi only by Power menu>Exit
(do not close with "X" window button otherwise addon service will stuck due to a Kodi 18 bug, fixed on Kodi 19)
get the log only after Kodi will be closed

mrblond18 · 2020-09-17T12:38:08Z

Try install this test addon, and disable netflix:
test.addon.zip

after reproduce the problem, exit from Kodi only by Power menu>Exit
(do not close with "X" window button otherwise addon service will stuck due to a Kodi 18 bug, fixed on Kodi 19)
get the log only after Kodi will be closed

Here you go:
https://bartthbo.stackstorage.com/s/qFu8A8sxJqaQBkfv

I waited for cpu to drop to normal values after playback (after about 5minutes, 30s of playback) and then quit kodi.

CastagnaIT · 2020-09-17T12:42:16Z

do you confirm that also with this test addon the CPU is in high load?

mrblond18 · 2020-09-17T12:49:24Z

do you confirm that also with this test addon the CPU is in high load?

yes, definitely. It starts when playback is started from a big (~25k songs) playlist and high cpu loads lasts for about 5 minutes 30s.

CastagnaIT · 2020-09-17T12:55:53Z

good,
then is a Kodi bug...
i do not think it will be solved for Kodi 18 because is EOL
but it will be for Kodi 19

i will open a thread issue to Kodi to report this problem
I will mention you in case the Kodi developers need to ask you for a new log or some more details

mrblond18 · 2020-09-17T13:02:14Z

good,
then is a Kodi bug...
i do not think it will be solved for Kodi 18 because is EOL
but it will be for Kodi 19

i will open a thread issue to Kodi to report this problem
I will mention you in case the Kodi developers need to ask you for a new log or some more details

great, keep me posted and please send me a link when you opened the thread on kodi forum...

mrblond18 · 2020-10-05T13:31:38Z

@CastagnaIT : I gave all latest(/nightly) versions a try and problem seems to be fixed there (but got another problem). Yeah!

I installed:

Kodi nightly 20201005
cu lrc lyrics 6.3.1
plugin.video.netflix-1.10.0+matrix.1.zip

Lyrics popup after about 10s (which is perfect) regardless of the netflix addon running or not. CPU usage does not go through the roof. Do you need me to do a test with the testplugin you created earlier (will it run on kodi matrix nightly?)

However, when I exit Kodi it takes a long time (3 minutes or so). I see in the log that the netflix addon causes the delay ( AppData\Roaming\Kodi\addons\plugin.video.netflix\service.py: script didn't stop in 5 seconds - let's kill it ).
Log here:
https://paste.kodi.tv/fifemeveke.kodi

CastagnaIT · 2020-10-05T14:22:46Z

resolved? how?
the Issue thread on Kodi github is not marked as resolved
I have not seen any changes regarding this problem

and on K18 the problem still happens?

Do you need me to do a test with the testplugin you created earlier (will it run on kodi matrix nightly?)

yes can be used with both kodi 18-19

However, when I exit Kodi it takes a long time (3 minutes or so). I see in the log that the netflix addon causes the delay

i do not know about this delay,
is usually associated with some uncompleted processing delay or other problems in Kodi core,
to my station with K19 not happen,
but until Kodi 19 is in the Alpha state i do not give importance

mrblond18 · 2020-10-05T18:56:30Z

resolved? how?

It does not consume 100% cpu power (at least not more than a few seconds) after starting music playback from a long (play)list (in my case 24k songs).

the Issue thread on Kodi github is not marked as resolved
I have not seen any changes regarding this problem

Agree, but my test case shows improvement. I did not change anything on my side, I only installed all the bleeding edge versions of the packages.

and on K18 the problem still happens?

yes

Do you need me to do a test with the testplugin you created earlier (will it run on kodi matrix nightly?)

yes can be used with both kodi 18-19

Done, log here: https://bartthbo.stackstorage.com/s/RHRi3ociwQvpoxKx (updated, the test addon was not running in the previous link I shared). Here you see that the test addon still receives all the notifications, but my cpu does not go to 100% anymore...

However, when I exit Kodi it takes a long time (3 minutes or so). I see in the log that the netflix addon causes the delay

i do not know about this delay,
is usually associated with some uncompleted processing delay or other problems in Kodi core,
to my station with K19 not happen,
but until Kodi 19 is in the Alpha state i do not give importance

You can see the delay in the log I linked to in my previous post, there you can see that kodi complains about the netflix addon not closing properly.
Kodi 19 is alpha state now, right. Alpha 1 was release about two months ago...

CastagnaIT · 2020-10-06T13:08:19Z

You can see the delay in the log I linked to in my previous post, there you can see that kodi complains about the netflix addon not closing properly.

yes have seen, but i have nothing to add to my previous response

if for you the current situation with K19 is good, i will close the issue on Kodi GH

mrblond18 · 2020-10-06T16:32:01Z

I do not know if it is actually "good". I see in the test addon that all the notification are still caught by your test-plugin, so underwater it is not OK I would say...

Still, if I uninstall the netflix addon, the lyrics are shown more quickly and kodi is more responsive...

CastagnaIT · 2020-10-07T06:41:41Z

I left the thread Issue on Kodi GH opened for future improvements
here now i close

mrblond18 · 2020-10-07T11:21:05Z

@CastagnaIT : thanks for all the help, let's see what the kodi developpers come up with.

Keep up the good work on the netflix plugin!

CastagnaIT mentioned this issue Sep 17, 2020

Playing huge playlists of music causes 100% CPU load due to xbmc.Monitor notifications xbmc/xbmc#18437

Closed

6 tasks

CastagnaIT added Resolution: External The bug was not in the code, caused by external factors Resolution: Waiting Kodi fixes labels Sep 18, 2020

CastagnaIT closed this as completed Oct 7, 2020

Netflix addon causes high CPU load when starting music playback - 2nd try #859

Netflix addon causes high CPU load when starting music playback - 2nd try #859

Comments

mrblond18 commented Sep 10, 2020

Bug report

Your Environment

Describe the bug

Expected behavior

Actual behavior

Steps to reproduce the behavior

Possible fix

Debug log

Additional context or screenshots (if appropriate)

Installation

Other information

Screenshots

jakermx commented Sep 10, 2020 • edited

CastagnaIT commented Sep 11, 2020 • edited

CastagnaIT commented Sep 11, 2020 • edited

mrblond18 commented Sep 11, 2020

mrblond18 commented Sep 11, 2020

mrblond18 commented Sep 11, 2020

CastagnaIT commented Sep 11, 2020

mrblond18 commented Sep 11, 2020

CastagnaIT commented Sep 11, 2020

mrblond18 commented Sep 11, 2020

CastagnaIT commented Sep 11, 2020 • edited

mrblond18 commented Sep 11, 2020

CastagnaIT commented Sep 11, 2020

mrblond18 commented Sep 11, 2020 • edited

CastagnaIT commented Sep 11, 2020

mrblond18 commented Sep 11, 2020

CastagnaIT commented Sep 11, 2020

mrblond18 commented Sep 11, 2020

CastagnaIT commented Sep 12, 2020 • edited

mrblond18 commented Sep 16, 2020 • edited

CastagnaIT commented Sep 17, 2020 • edited

mrblond18 commented Sep 17, 2020

CastagnaIT commented Sep 17, 2020

CastagnaIT commented Sep 17, 2020 • edited

mrblond18 commented Sep 17, 2020

CastagnaIT commented Sep 17, 2020

mrblond18 commented Sep 17, 2020 • edited

CastagnaIT commented Sep 17, 2020

mrblond18 commented Sep 17, 2020

CastagnaIT commented Sep 17, 2020

mrblond18 commented Sep 17, 2020

CastagnaIT commented Sep 17, 2020

mrblond18 commented Sep 17, 2020

CastagnaIT commented Sep 17, 2020

mrblond18 commented Sep 17, 2020

mrblond18 commented Oct 5, 2020

CastagnaIT commented Oct 5, 2020

mrblond18 commented Oct 5, 2020 • edited

CastagnaIT commented Oct 6, 2020

mrblond18 commented Oct 6, 2020

CastagnaIT commented Oct 7, 2020

mrblond18 commented Oct 7, 2020

jakermx commented Sep 10, 2020 •

edited

CastagnaIT commented Sep 11, 2020 •

edited

CastagnaIT commented Sep 11, 2020 •

edited

CastagnaIT commented Sep 11, 2020 •

edited

mrblond18 commented Sep 11, 2020 •

edited

CastagnaIT commented Sep 12, 2020 •

edited

mrblond18 commented Sep 16, 2020 •

edited

CastagnaIT commented Sep 17, 2020 •

edited

CastagnaIT commented Sep 17, 2020 •

edited

mrblond18 commented Sep 17, 2020 •

edited

mrblond18 commented Oct 5, 2020 •

edited