GNOME Bugzilla – Bug 770717
log() should print the current extension, if applicable
Last modified: 2016-10-11 13:26:39 UTC
It would useful mainly for extension developers. They could easily see their logs in the journal by grepping for their extension uuid, for instance.
Created attachment 334609 [details] [review] Proposed patch
Review of attachment 334609 [details] [review]: ::: js/misc/extensionUtils.js @@ +25,3 @@ + let stack = (new Error()).stack.split('\n'); + let extensionStackLine; + I think the changes in this file should be a separate commit, since strictly speaking, they aren't just about logging. ::: js/ui/environment.js @@ +69,3 @@ + try { + let extension = imports.misc.extensionUtils.getCurrentExtension(); + args = '[' + extension.uuid + '] ' + args; i think a better approach would be to change the logging function to use Shell.Global.log_structured instead of window.log then pass the uuid as a separate metadata item so it's query-able by journalctl
(In reply to Ray Strode [halfline] from comment #2) > Review of attachment 334609 [details] [review] [review]: > > ::: js/misc/extensionUtils.js > @@ +25,3 @@ > + let stack = (new Error()).stack.split('\n'); > + let extensionStackLine; > + > > I think the changes in this file should be a separate commit, since strictly > speaking, they aren't just about logging. Indeed. > ::: js/ui/environment.js > @@ +69,3 @@ > + try { > + let extension = > imports.misc.extensionUtils.getCurrentExtension(); > + args = '[' + extension.uuid + '] ' + args; > > i think a better approach would be to change the logging function to use > Shell.Global.log_structured instead of window.log then pass the uuid as a > separate metadata item so it's query-able by journalctl That would be a great addition. We could even think on a priority field for log(): (warning, error, debug, etc). However, three things come on my mind: 1) Systems that don't have systemd: The implementation is just a printf(message). We lose the metadata anyway. 2) Cases where gnome-shell is started 'by hand': We don't get the output in the same console as we started gnome-shell. We have to open another terminal and run journalctl from there. 3) Social aspect: It's "easier" for users to run something like 'tail -f <file> | grep sth' than using journalctl to filter for metadata. What do you think?
(In reply to Jonh Wendell from comment #3) > However, three things come on my mind: > > 1) Systems that don't have systemd: The implementation is just a > printf(message). We lose the metadata anyway. > > 2) Cases where gnome-shell is started 'by hand': We don't get the output in > the same console as we started gnome-shell. We have to open another terminal > and run journalctl from there. > > 3) Social aspect: It's "easier" for users to run something like 'tail -f > <file> | grep sth' than using journalctl to filter for metadata. > > What do you think? So, all three things would be fixed if we used the native glib logging apis. Unfortunately, we can't at the moment because of this problem: https://mail.gnome.org/archives/desktop-devel-list/2016-August/msg00002.html Do you want/have time to tackle the solution proposed on that thread? --Ray
Now that we have g_log_variant() available, I have some questions... 1) Are we going to reimplement window.log() method on top of GLib.log_variant()? 1.1) And, in the context of this bug, pass the extension as a field if the caller is an extension? 2) Can we depend on GLib 2.50 already?
(In reply to Jonh Wendell from comment #5) > Now that we have g_log_variant() available, I have some questions... > > 1) Are we going to reimplement window.log() method on top of > GLib.log_variant()? Well, ideally, we'd get the convenience wrapper, GLib.log_structured(), I mentioned in the thread added to gjs first, and then use that instead of GLib.log_variant() directly. Of course what i put in the thread was just untested pseudocode, to illustrate the idea, but it's probably close to right. > 1.1) And, in the context of this bug, pass the extension as a field if the > caller is an extension? makes sense to me. > 2) Can we depend on GLib 2.50 already? IMO, depending on latest glib is fine for core modules like gjs and gnome-shell. One hiccup is hard code freeze is monday, so this may have to wait a bit, unless we all really scramble. But if we do miss the train, I don't think it's that urgent anyway (unless you disagree?)
Created attachment 335786 [details] [review] extensionUtils: Allow getCurrentExtension() to be called from anyone Currently it's assumed only an extension can call this method. However it can be useful if any part of the shell want to know if it was invoked by an extension.
Created attachment 335787 [details] [review] log(): Reimplement on top of GLib.log_structured This allows us to pass metadata fields besides the message to log. So, if the log() call is made from an extension, pass the extension name and UUID to the logger. This is useful for extension developers to debug their code as well as to instruct their users to send debug info to them by running something like this: journalctl GNOME_SHELL_EXTENSION_UUID=<extension@uuid>
btw, if this gets in, can we drop shell_global_log_structured()?
Review of attachment 335786 [details] [review]: looks right to me ::: js/misc/extensionUtils.js @@ +26,3 @@ + let extensionStackLine; + + // Search for an occurrence of an extension stack frame maybe say (we skip i = 0, since that's the stack frame of this function) @@ +35,2 @@ if (!extensionStackLine) throw new Error('Could not find current extension'); might better to return null instead of throw if the expectation is now that it can be called from anywhere?
Review of attachment 335787 [details] [review]: thanks, looks close. Of course we can't land this until a gjs release ::: js/ui/environment.js @@ +74,3 @@ + } + + GLib.log_structured(null, GLib.LogLevelFlags.LEVEL_MESSAGE, fields); this should probably pass "GnomeShell" or something like that as the log domain (or maybe it should use the extension name as the domain ?) @@ +83,3 @@ window.global = Shell.Global.get(); + window.log = _makeLoggingFunc(); i don't think you need this _makeLoggingFunc() wrapper anymore. I think you can just do somethilng like window.log = _loggingFunc; then drop the outer _makeLoggingFunc above and name the anonymous function above to _logginFunc (or whatever)
(In reply to Ray Strode [halfline] from comment #10) > Review of attachment 335786 [details] [review] [review]: > > looks right to me > > ::: js/misc/extensionUtils.js > @@ +26,3 @@ > + let extensionStackLine; > + > + // Search for an occurrence of an extension stack frame > > maybe say (we skip i = 0, since that's the stack frame of this function) > > @@ +35,2 @@ > if (!extensionStackLine) > throw new Error('Could not find current extension'); > > might better to return null instead of throw if the expectation is now that > it can be called from anywhere? Thought like this too; theoretically it might break some extension relying on this exception... although I cannot see how that would happen...
(In reply to Ray Strode [halfline] from comment #11) > Review of attachment 335787 [details] [review] [review]: > > thanks, looks close. Of course we can't land this until a gjs release > > ::: js/ui/environment.js > @@ +74,3 @@ > + } > + > + GLib.log_structured(null, GLib.LogLevelFlags.LEVEL_MESSAGE, fields); > > this should probably pass "GnomeShell" or something like that as the log > domain (or maybe it should use the extension name as the domain ?) Liked it. "GNOME Shell" by default; Extension name if present. > @@ +83,3 @@ > window.global = Shell.Global.get(); > > + window.log = _makeLoggingFunc(); > > i don't think you need this _makeLoggingFunc() wrapper anymore. > I think you can just do somethilng like > > window.log = _loggingFunc; > > then drop the outer _makeLoggingFunc above and name the anonymous function > above to _logginFunc (or whatever) Hmm, I tried that but got lots of errors; shell crashing on the startup... Will try again with more attention.
Created attachment 336846 [details] [review] log(): Reimplement on top of GLib.log_structured This allows us to pass metadata fields besides the message to log. So, if the log() call is made from an extension, pass the extension name and UUID to the logger. This is useful for extension developers to debug their code as well as to instruct their users to send debug info to them by running something like this: journalctl GNOME_SHELL_EXTENSION_UUID=<extension@uuid>
Created attachment 336847 [details] [review] extensionUtils: Allow getCurrentExtension() to be called from anyone Currently it's assumed only an extension can call this method. However it can be useful if any part of the shell want to know if it was invoked by an extension.
Review of attachment 336846 [details] [review]: ++
Review of attachment 336847 [details] [review]: ++
thanks for all the hard work and yak shaving on this!
Just a small reminder that gnome-shell hasn't branched yet - I plan to do that after rolling the 3.22.1 release next week. It's probably best to wait for that, so that we don't need to bump the gjs requirement in a micro version.
yea, we were actually having a discussion about this on #gnome-shell !
Attachment 336846 [details] pushed as 70526a8 - log(): Reimplement on top of GLib.log_structured Attachment 336847 [details] pushed as c405081 - extensionUtils: Allow getCurrentExtension() to be called from anyone