"Generate Support Log" no longer works

[ferdnyc]

Describe the bug

It turns out that the method we use for switching debug logging on and off (by detecting a GSettings change and changing the definition of globalThis.debug()) no longer works with GNOME 46 gjs. Even if the setting value is changed, the code won't alter its logging unless the GSConnect backend is reloaded (by running kill -HUP on the daemon.js process).

I've tried rewriting globalThis.debug as a static function that checks the value of a boolean globalThis._debugEnabled each time it's called, and having the GSettings watcher update the value of that variable instead, but it made no difference.

Presumably it has something to do with compiled code and/or multithreading, such that the other bits of the codebase aren't picking up on runtime changes to the global function definition / variable value. But it looks like we'll have to find a new way to implement on-the-fly debug enabling/disabling.

Something like this would probably work, but it would slow the code down horribly whether or not debugging is enabled:

const _debugFunc = function (error, prefix = null) {
    const enabled = settings.get_boolean("debug");
    if (!enabled)
        return;

    // ...
}

globalThis.debug = _debugFunc;

cc: @andyholmes

Steps to reproduce

No response

Expected behavior

No response

GSConnect version

57

Installed from

other source

GNOME Shell version

46

Linux distribution/release

Fedora 40

Paired device(s)

No response

KDE Connect app version

No response

Plugin(s)

No response

Support log

No response

Screenshots

No response

Notes

No response

[andyholmes]

I'm not sure why this would stop working, to be honest. dconf uses a memory mapped file to share settings across processes, but as far as I can tell no changes are being propagated to the daemon at all.

Maybe something got nudged during the ESM transition? I don't think so though.

[ferdnyc]

dconf uses a memory mapped file to share settings across processes

My thinking was that the issue isn't that the dconf value doesn't get propagated, but rather that the resulting redefinition of globalThis.debug isn't propagating to already-compiled and -running code. Which might theoretically be an unintended consequence of the switch to ESM modules. Possible?

(I suppose that's easy enough to test, actually, by adding some logging to the changed:: event handler for the setting. I'll give that a spin.)

...I'm also trying to figure out how to best deal with this in the Wiki. Best I can come up with so far is just telling people to run this command in a terminal, once after activating "Generate Support Log" and a second time after ending it:

for p in $(pidof gjs); do grep daemon.js /proc/${p}/cmdline && kill -HUP ${p}; done

(That's the most compact version of a one-liner I could come up with that will definitely HUP only daemon.js.)

I wonder if it would work to run that command ourselves from the Preferences app, using Gio.Subprocess? I assume those subprocesses don't normally run in a shell, so I suppose we'd have to do something closer to this:

const daemon_restart = new Gio.Subprocess({
    argv: [
        '/bin/bash', '-c',
        'for p in $(pidof gjs); do grep daemon.js /proc/${p}/cmdline && kill -HUP ${p}; done'
    ],
    flags: (Gio.SubprocessFlags.STDOUT_SILENCE |
            Gio.SubprocessFlags.STDERR_SILENCE),
});

..."Ewwww."

(Edit: Or we could just use Gio.File to (metaphorically) 'touch' the daemon.js source file, since it looks like its automatic self-reloading on code changes is still working fine.)

[andyholmes]

My thinking was that the issue isn't that the dconf value doesn't get propagated, but rather that the resulting redefinition of globalThis.debug isn't propagating to already-compiled and -running code.

There's no real concept of compiled code, from the perspective of a JavaScript process. The engine is free to interpret directly, JIT-compile in progressive stages and start over. For the programmer it's just a run-time only language.

(I suppose that's easy enough to test, actually, by adding some logging to the changed:: event handler for the setting. I'll give that a spin.)

I gave that a shot and was getting no signal emissions. I looked to see if someone had set the GSettings to delay-apply mode, but found nothing that should affect it.

[ferdnyc]

I gave that a shot and was getting no signal emissions.

Grumpf. Same. I even tried experimentally changing the name of the setting to 'support-log', just in case there was something weird about the word 'debug' (I'm flailing now, clearly), and... nothing!

If I run a gsettings ... monitor¹ on the value, I can SEE it change as soon as "Generate Support Log" is started or ended, but the daemon never gets word either way. What the heck?

1. (And I checked the code — gsettings monitor USES the changed::foo signal to monitor the value of 'foo'!)

[andyholmes]

Maybe the object is being collected, and assigning it with const isn't holding a reference? That seems weird though.

[ferdnyc]

I did think about that. The one difference between the changed::debug settings signal and every other signal we register for is that the debug signal isn't being held inside a GObject at all, it's just sitting in the service/init.js module. Perhaps we need to have it held by the GSConnect device manager?

[ferdnyc]

I'mma add a debugging property to GSConnectManager, and have that connect the signal and handle redefining globalThis.debug() when it changes. Let's see how that goes.

[ferdnyc]

(Heck, it means we'll also be able to toggle on debugging via DBus, so win/win.)

[ferdnyc]

SUCCESS! \o/