benzea/gnome-shell-extension-redshift

Redshift fails after suspend+wakeup+unlock (or lock+unlock)

genodeftest opened this issue · 15 comments

It seems like there is a race condition in redshift related to GeoClue.

How reproducible:
unclear, not 100%.

Steps to reproduce:

  1. install this gnome-shell-extension from https://copr.fedorainfracloud.org/coprs/mystro256/gnome-redshift/
  2. suspend PC
  3. wakeup PC
  4. unlock GNOME session
  5. repeat steps 2. to 4. until redshift dies

What should happen:
Redshift should not crash or get killed by gnome-shell

What happens:
Redshift gnome-shell extension is gone, screen is bright.

Additional info:
A log file from journalctl listing everything related to gnome-shell:
gnome-shell-redshift.log.txt
. Note that every time it shows fprintd.service being activated I was unlocking the screen.

Version info:
I'm running Fedora 25 with GNOME on wayland.
gtk3-3.22.2-2.fc25.x86_64
gnome-shell-3.22.1-2.fc25.x86_64
gnome-settings-daemon-3.22.1-3.redshift.fc25.x86_64
mutter-3.22.1-8.fc25.x86_64
gjs-1.46.0-1.fc25.x86_64

Uhmm, it looks like the shell extension hasn't been completely unloaded and is running multiple times. I thought that I had fixed that. (The extension is always unloaded when the screen is being locked.)

Other than that, almost seems like the GeoClue2 service might be even dying in this case. Or maybe it is a race condition of redshfit enabling geoclue, geoclue asking the shell for permission and this not completing because you are suspending again.

Uhmm, it looks like the shell extension hasn't been completely unloaded and is running multiple times. I thought that I had fixed that. (The extension is always unloaded when the screen is being locked.)

Hm, unlocking of extensions doesn't work every time. I've been seeing this before I started using your extension so it might be unrelated.

Other than that, almost seems like the GeoClue2 service might be even dying in this case. Or maybe it is a race condition of redshfit enabling geoclue, geoclue asking the shell for permission and this not completing because you are suspending again.

Just to be clear about "…is not completing because you are suspending again": Gnome-shell would have had enough time my that to request asking me for permission and I've already allowed this.

Please let me know if I can contribute more information.

I've tested this again and even with no other extensions enabled redshift failed after the first lock+unlock cycle. So it's probably not caused by other extensions.

There is only one difference between the redshift installation I've installed (from COPR) compared to the git master:
Mine has let id = 'org.gnome.shell.extensions.redshift-gnome'; in extensions.js:209 and git master has let id = 'org.gnome.Maps'; instead. I don't know whether this is of any relevance.

The change isn't relevant (it makes sense, I am just not sure if one can actually include a desktop file in a the extension bundle).

The extension is disabled every time the screen is locked and reenabled when you log back in. And if something is going wrong during the unloading (maybe because of the suspend happening), then maybe a part of the old extension keeps living on. And then you basically end up with the redshit extension running multiple times.

The change isn't relevant (it makes sense, I am just not sure if one can actually include a desktop file in a the extension bundle).

Yeah, but the RPM package can ;)

Is it possible that this issue happens only if the extension is being disabled during https://github.com/benzea/gnome-shell-extension-redshift/blob/master/redshift%40benjamin.sipsolutions.net/extension.js#L342 ?

Workaround: I've set the time source to "last known" and I haven't seen this issue happening again.

And I don't know whether this is related or not, but every time I disable this extension I'm getting an assertion error:

Dez 01 11:19:24 hostname gnome-shell[9258]: JS LOG: redshift: enabling extension
Dez 01 11:19:24 hostname org.gnome.Shell.desktop[9258]: org.gnome.shell.extensions.redshift-gnome
Dez 01 11:19:24 hostname org.gnome.Shell.desktop[9258]: /usr/share/gnome-shell/extensions/redshift@benjamin.sipsolutions.net/schemas
Dez 01 11:19:24 hostname org.gnome.Shell.desktop[9258]: local install[boxed instance proxy GIName:Gio.SettingsSchema jsobj@0x7fed00469880 native@0x556d29fffed0]
Dez 01 11:19:24 hostname gnome-software-service.desktop[9629]: 10:19:24:0983 Gs  no app for changed redshift@benjamin.sipsolutions.net
Dez 01 11:19:25 hostname gnome-shell[9258]: JS LOG: redshift: disabling extension
Dez 01 11:19:25 hostname gnome-shell[9258]: clutter_content_invalidate: assertion 'CLUTTER_IS_CONTENT (content)' failed
Dez 01 11:19:25 hostname gnome-software-service.desktop[9629]: 10:19:25:0975 Gs  no app for changed redshift@benjamin.sipsolutions.net
Dez 01 11:19:26 hostname gnome-shell[9258]: JS LOG: redshift: enabling extension
Dez 01 11:19:26 hostname org.gnome.Shell.desktop[9258]: org.gnome.shell.extensions.redshift-gnome
Dez 01 11:19:26 hostname org.gnome.Shell.desktop[9258]: /usr/share/gnome-shell/extensions/redshift@benjamin.sipsolutions.net/schemas
Dez 01 11:19:26 hostname org.gnome.Shell.desktop[9258]: local install[boxed instance proxy GIName:Gio.SettingsSchema jsobj@0x7fed0041c490 native@0x556d2c8c84f0]
Dez 01 11:19:26 hostname gnome-software-service.desktop[9629]: 10:19:26:0792 Gs  no app for changed redshift@benjamin.sipsolutions.net
Dez 01 11:19:27 hostname gnome-shell[9258]: JS LOG: redshift: disabling extension
Dez 01 11:19:27 hostname gnome-shell[9258]: clutter_content_invalidate: assertion 'CLUTTER_IS_CONTENT (content)' failed

Nah, not there. If anywhere then during creation. The line you linked just creates an object to retrieve the city (for sunrise/sunset time calculation purposes). The code is completely useless since I modified the code to simply always use the last known location.

For the geoclue connection, the relevant code is:
https://github.com/benzea/gnome-shell-extension-redshift/blob/master/redshift@benjamin.sipsolutions.net/extension.js#L197

which tries to handle the case of a being disabled while the connection is being established.

Also relevant is
https://github.com/benzea/gnome-shell-extension-redshift/blob/master/redshift@benjamin.sipsolutions.net/extension.js#L403
as all signal handlers need to be disconnected there (a connected signal handler will usually prevent the objects from being destroyed).

All that said, the "correct" fix is probably to move away from GClue.Simple and use the proper Geoclue client directly. That might go a long way in ensuring everything is cleaned up correctly, as GClue.Simple doesn't seem to do any cleanup by itself.

Really, why is the extension being disabled by the shell all the time in your first log?

Really, why is the extension being disabled by the shell all the time in your first log?

That's pretty weird, yes. Maybe some kind of recovery mechanism in gnome-shell? or a bug? I have no idea how to figure that out…

Seeing a similar problem on my install, only with just locking/unlocking...if you need another test case...

Essentially:

  1. I lock screen with redshift plugin working happily
  2. I unlock screen
  3. redshift plugin (and any other plugins that display icons on the top bar) is gone
  4. (Strangely, and possibly un-related?) trying to open pidgin "new window" (for contacts, etc.) logs me out.

Anything I can pass along that might help?

@johnseekins that is probably a different issue. Please open a new issue after having a look at 'journalctl /usr/bin/gnome-shell' and/or looking glass (alt+f2 then enter "lg" then enter").

@johnseekins, @benzea : I'm seeing the same issue. Nothing useful in journal or looking glass for me.

I just pushed some fixes to improve the GeoClue handling. Please test if you can still reproduce the issue now. If not, please close the bug, if yes, please attach more information (journalctl log)

Assuming the issue is fixed.