3
$ journalctl -b
...
Mar 23 18:18:50 alan-laptop pkexec[31408]: pam_unix(polkit-1:session): session opened for user root by (uid=1001)
Mar 23 18:19:47 alan-laptop org.gnome.Shell.desktop[1711]: libinput error: client bug: timer event5 debounce short: offset negative (-3ms)
...

I understand the first line as a log message from PID 31408, which is an instance of the pkexec command.

But I'm 100% sure I don't have an executable called org.gnome.Shell.desktop anywhere. A file does exist with that name, but it's an XDG desktop file.

$ find -xdev -name 'org.gnome.Shell.desktop*' 2>/dev/null
./usr/share/applications/org.gnome.Shell.desktop
$ ls -l ./usr/share/applications/org.gnome.Shell.desktop
-rw-r--r--. 1 root root 8179 Jan 22 10:19 ./usr/share/applications/org.gnome.Shell.desktop

Question

Why doesn't this log message show gnome-shell[1711] instead?

How is this implemented?

Did someone think it would be more useful this way? If so, why?

Environment

Fedora 27

  • systemd-234-10.git5f8984e.fc27.x86_64
  • gnome-session-3.26.1-1.fc27.x86_64
  • Note that you can ask a different question about another Desktop Bus server, for which there is a similar effect but a quite different answer. You've happened to pick a software that is a special case. – JdeBP Mar 24 '18 at 2:33
4

TL;DR: It's GNOME Shell that decided to do that. They run multiple applications (applets) inside the same process, so they decided to use the XDG menu specifications as the "tag" to attach to the messages.

Full explanation below...


So the journal synthesizes the syslog-like message that you see from the internal fields stored with each message. (You can see the internal fields by using the -o verbose format.)

The field that usually carries the program name, a.k.a. the "tag", is stored in the SYSLOG_IDENTIFIER field.

(Other programs make use of the SYSLOG_IDENTIFIER. For instance, logger will by default send the tag from the user who's calling it and you can override it using the -t option.)

There are 3 main ways to log to the journal, either by using the traditional syslog(3) interface, by writing to stdout or stderr from a systemd service, or by using the native journal interface.

GNOME Shell uses the native journal interface, in particular, the sd_journal_stream_fd API. That function takes an identifier as first argument, which is then used as SYSLOG_IDENTIFIER of messages sent through that stream.

The GNOME Shell code that initializes the journald stream can be found in src/shell-app.c, and tracing back the used appid to the caller shows that it is set using g_app_info_get_id.

Looking up g_app_info_get_id, you'll see that the ID is platform-specific, but "on Unix this is the desktop file id from the xdg menu specification", which matches what you're observing.

The code in src/shell-app.c is preceded by a comment that explains the rationale:

/* This sets up the launched application to log to the journal
 * using its own identifier, instead of just "gnome-session".
 */

In other words, GNOME Shell runs multiple applications (through applets), so GNOME Shell developers thought it would be more appropriate to use the XDG menu specifications in the log messages, so you could tell which applet is generating it...


These logging streams may also be inherited by any child processes, such as Xwayland. In this case, the PID following the tag appears to refer to gnome-shell, the process that opened the stream_fd, and not the child process which writes the message to the fd. The log message below shows a crash of the Xwayland server, but the PID 3493 is that of gnome-shell, not Xwayland.

Mar 17 18:08:39 alan-laptop org.gnome.Shell.desktop[3494]: (EE) Caught signal 7 (Bus error). Server aborting

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.