Launching some windows uses 100% CPU. #25

Closed
kboone opened this Issue May 28, 2015 · 42 comments

Comments

Projects
None yet
9 participants

kboone commented May 28, 2015

I ran into an issue with launching spotify with pixel-saver enabled. Calling win.get_compositor_private() in line 207 of decoration.js for this window always returns nil. This gets pixel-saver stuck in an infinite loop of calling onWindowAdded, using 100% CPU.

There should probably be some sort of max retries there. Simply disabling the callback to onWindowAdded() with return false; after the if (!win.get_compositor_private()) { call is a workaround, but probably not the right solution.

Thanks!

Owner

deadalnix commented May 29, 2015

Is that valid that some window have no compositor at all ? (Against all expectation, I'm far from being a linux UI guru).

kboone commented May 29, 2015

I don't know anything about this, sorry. I just traced down where it was getting stuck.

kboone commented May 29, 2015

I took a deeper look. It looks like spotify is actually spawning 2 windows. One of these is processed fine, but the other is never actually displayed. I'm guessing that it is the login window, and it is probably created and then immediately closed because I'm already logged in. It could be that it is assigned a compositor, but that compositor is closed before the pixel-saver function gets to it. Regardless, it never has one when pixel-saver tries to call get_compositor_private()

Owner

deadalnix commented May 29, 2015

OK I guess a retry limit of 3 or so should do the trick. Could you test this on your side and make a PR if it fixes things ?

I'm away from home right now and can't really work on a PR.

kboone commented May 29, 2015

I'll give this a shot later today.

On Thu, 28 May 2015 at 22:15 deadalnix notifications@github.com wrote:

OK I guess a retry limit of 3 or so should do the trick. Could you test
this on your side and make a PR if it fixes things ?

I'm away from home right now and can't really work on a PR.


Reply to this email directly or view it on GitHub
#25 (comment)
.

kboone commented May 29, 2015

I created a pull request which fixes it for me. Thanks for maintaining this great extension!

herrlado commented Jun 2, 2015

OK guys, I have also the same problem. I have pulled the version of @kboone and it solves the issue. Thanks!

Owner

deadalnix commented Jun 2, 2015

Ok guys, sorry for the delays, I'm completely swamped. I'm just back home from that week end and have various things to catch up. Please ping that task if I forgot.

herrlado commented Jun 2, 2015

Hey, everything is fine, it work, this is what matters :)

Owner

deadalnix commented Jun 4, 2015

Is the new master work for you guys ? If yes, let's close this task.

kboone commented Jun 4, 2015

Looks good!

herrlado commented Jun 4, 2015

I think the bug is still there. After longer observation cpu goes up to 100% after a while. I will double check this.

herrlado commented Jun 5, 2015

By the way, is there any way to debug a gnome shell extension?

Owner

deadalnix commented Jun 5, 2015

You have some log function in pixel saver. They'll dump log in a system dependant location (because fuck convenience) so you'll have ask your distro guys to know where they go.

That is very inconvenient, but it works.

kboone commented Jun 5, 2015

I used this to view the log:

journalctl /usr/bin/gnome-session -f -o cat
Contributor

chazzbg commented Jun 8, 2015

Hello there , i have noticed some issues with high load even with this fix. I'm using PHPStorm and when i launch two windows of the IDE ( for two different projects ), gnome-shell start to take up to 50% of the cpu.
How could i debug this and provide some valuable information ?

Owner

deadalnix commented Jun 8, 2015

The best thing you can do for a start is make sure this is due to the extension, by trying to disable all extension and repro. if it does repro, then it is a gnome shell problem.

Second step, enable just this extension and repro. If you can repro, then shit, that's on us :)

If not, try to enable other extension one by one and repro. This can come from this other extention, or a bad interaction betwen 2 extension.

If that is pixel saver, then edit the code to uncomment log line on top of various .js file. Then you need to find out where gnome shell dump its log (distro dependent, can't really tell you on that one) and provide what is logged by pixel saver while you repro.

I got the same problem. Debian 8, gnome 3.14, pixel saver from extensions.gnome.org

Got this CPU load 5-30 minutes after session start. CPU goes up to 70%-90% and stays there until log out. No other extensions running, pretty sure the problem comes from pixel saver. Any more information needed? Ah, I see. Ok, will see if I can manage that log thing.

Owner

deadalnix commented Jun 27, 2015

There is a fix, but only for 3.16 . Debian package gnome 3.16 so you can upgrade.

I encounter these symptoms reliably when opening VLC player.
I'm running on master under GNOME 3.16, I guess the fix you are talking about is not yet there ...
If I can debug anything for you, let me know.

Owner

deadalnix commented Jul 8, 2015

The fix is in master. I'm not sure if it is on the gnome extension website yet.

michaudg commented Aug 6, 2015

Same problem for me. I cloned the latest master, 1 core at 22-25% when i launch Spotify. I had to reload the shell (alt-r, f2) to fix the problem. I'm on 3.16. If i disable pixel-saver and launch Spotify, CPU stay at 0%. Thanks.

Owner

deadalnix commented Aug 6, 2015

This is supposed to be fixed in master, have you tried it ?

michaudg commented Aug 6, 2015

Yes, i just cloned the project. Just tell me how i could help, I would do my best.

Owner

deadalnix commented Aug 6, 2015

Well, there is something that is looping. First you need to find out where your distro is dumping gnome shell's logs. On my system, it is in the syslog, but it is going to depend on your distro.

Then, if you look at the source code, you'll find various LOG method with a commented line in them. Uncomment that line. This will make pixel saver dump a bunch of things in gnome shell's log.

Once you get that working, repro the bug. 100% CPU is a sign of something going into infinite loop. You should see some log entry repeat itself ad infinitum. If so, report it and that will tell what is using the CPU. If not, add more log into the shell and find it.

Once we know what is consuming your CPU, we can figure out how to fix it :)

michaudg commented Aug 6, 2015

I uncommented all log() function in all .js files. Used "sudo journalctl -b /usr/bin/gnome-session" to see the logs. I launched Spotify and it seems that there is no errors :(

aoû 06 08:50:54 arch gnome-session[458]: Gjs-Message: JS LOG: [pixel-saver]: Override title Spotify
aoû 06 08:50:54 arch gnome-session[458]: Gjs-Message: JS LOG: [pixel-saver]: onWindowAdded: Spotify Premium - Linux Preview
aoû 06 08:50:54 arch gnome-session[458]: Gjs-Message: JS LOG: [pixel-saver]: setHideTitlebar: Spotify Premium - Linux Preview: true
aoû 06 08:50:54 arch gnome-session[458]: Gjs-Message: JS LOG: [pixel-saver]: xprop -id 0x220001e
aoû 06 08:50:54 arch gnome-session[458]: Gjs-Message: JS LOG: [pixel-saver]: Can't find original state for Spotify Premium - Linux Preview with id 0x220001e
aoû 06 08:50:54 arch gnome-session[458]: Gjs-Message: JS LOG: [pixel-saver]: xprop -id 0x220001e -f _GTK_HIDE_TITLEBAR_WHEN_MAXIMIZED 32c -set _GTK_HIDE_TITLEBAR_WHEN_MAXIMIZED 0x1

Owner

deadalnix commented Aug 6, 2015

Ok, so first thing first: when you get to the 100% CPU situation, try to use htop or similar tool to check that gnome-shell process is the one using all that CPU.

As you don't seem to have a log of the error in your repro, you need to add more logs. What you can do is look for various call to Mainloop.idle_add and add a log before each of them. One of them is most likely where you get the 100% CPU.

michaudg commented Aug 7, 2015

The bug is in this loop : https://github.com/deadalnix/pixel-saver/blob/master/pixel-saver%40deadalnix.me/decoration.js#L214

I added log("spotify bug"); at line 215 and when i start Spotify, the log is filled with "spotify bug" message.

hamiller commented Aug 7, 2015

can confirm line 215 does unfinite loop

michaudg commented Aug 7, 2015

When Spotify starts, i can see in process manager that there is 3 processes named Spotify and 6 named SpotifyHelper. I will try to find a way to debug it in the extension.

Owner

deadalnix commented Aug 7, 2015

Could you print the value of retry ? There should be at most 3 retry on that one, so I'd like to understand why it is indefinitely looping instead.

michaudg commented Aug 7, 2015

the value of retry is 0

michaudg commented Aug 7, 2015

i put log(retry); before onWindowAdded(), i will try to put it after...

Look at this line. If I understand it correctly, retry is set to 0 when it is not undefined.

michaudg commented Aug 7, 2015

before or after onWindowAdded(), retry is still at 0

Owner

deadalnix commented Aug 7, 2015

🐼

Okayyyy...

Owner

deadalnix commented Aug 7, 2015

Reversed the test, this should fix the issue. Could guys test with the new master ?

michaudg commented Aug 7, 2015

it works! yay!

hamiller commented Aug 7, 2015

@dffischer awesome! I've looked at it multiple times but haven't seen that 👍

And I never even experienced the bug myself. I just watch this great extension and thus was notified about your debugging. But I am glad I could help out. Keep up the good work.

Owner

deadalnix commented Aug 7, 2015

Cool, this time it looks like it is fixed for good. Closing.

@deadalnix deadalnix closed this Aug 7, 2015

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment