getting journalctl logs for a unit

Question

While I'm debugging a systemd error in my system, I noted the that journalctl -u doesn't do what I expected. For example, I want to see logs about systemd-modules-load unit. Here are two ways I did it, and they yielded different results.

using -u systemd-modules-load

$ journalctl -u systemd-modules-load | tail
Mar 13 15:47:53 dhcp-rhodes-1379.eduroam.cornell.edu systemd[1]: Stopped Load Kernel Modules.
-- Reboot --
Mar 13 15:55:37 localhost.localdomain systemd[1]: Starting Load Kernel Modules...
Mar 13 15:55:37 localhost.localdomain systemd[1]: Started Load Kernel Modules.
Mar 13 15:55:48 localhost.localdomain systemd[1]: Stopped Load Kernel Modules.
-- Reboot --
Mar 13 15:56:09 localhost.localdomain systemd[1]: Started Load Kernel Modules.
Mar 13 15:57:07 localhost.localdomain systemd[1]: Stopped Load Kernel Modules.
-- Reboot --
Mar 13 15:57:24 localhost.localdomain systemd[1]: Started Load Kernel Modules.

grep the raw output of journalctl

$ journalctl | grep modules | tail
Mar 13 15:57:07 localhost.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-modules-load comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 13 15:57:07 localhost.localdomain audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-modules-load comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Mar 13 15:57:19 localhost.localdomain systemd-modules-load[225]: Failed to find module 'vboxdrv'
Mar 13 15:57:19 localhost.localdomain systemd-modules-load[225]: Failed to find module 'vboxnetflt'
Mar 13 15:57:19 localhost.localdomain systemd-modules-load[225]: Failed to find module 'vboxnetadp'
Mar 13 15:57:19 localhost.localdomain systemd-modules-load[225]: Failed to find module 'vboxpci'

I was expecting the output should be somewhat identical. Is there a reason for such a discrepancy?

Answer 1

TL;DR: The missing messages are not actually part of the unit. This command combines the UNIT key you're looking for with a key from the missing messages to show both:

journalctl UNIT=systemd-modules-load.service + SYSLOG_IDENTIFIER=systemd-modules-load

---

Resources:

• a decent journald tutorial
• man journalctl
• man systemd-journald
• man systemd.journal-fields

---

Compare the journal output with JSON formatting (-o json-pretty) to show the full arguments of each entry.

You can see the -u systemd-modules-load.service example includes the UNIT key while the other message does not. Instead, the non-unit message is identified as coming from systemd-modules-load in the SYSLOG_IDENTIFIER key. You can use that as your journalctl filter to find the missing messages.

The issue seems to be a known bug: see issue#5130 (what you're seeing) and issue#2913 (root cause).

---

Actual unit messages

The basic journalctl -a -u systemd-modules-load.service:

Mar 12 16:42:28 hostname systemd[1]: Stopped Load Kernel Modules.

JSON-formatted:

{
    "__CURSOR" : "s=c10ff46a8e1c47ea80f86c6e03d04b6e;i=10a21;b=a1b91c592c11472796f9b5d9a1cc0791;m=17880512f0d;t=54a8ea20efe69;x=6034d0bdef17b6ad",
    "__REALTIME_TIMESTAMP" : "1489351348256361",
    "__MONOTONIC_TIMESTAMP" : "1617060507405",
    "_BOOT_ID" : "a1b91c592c11472796f9b5d9a1cc0791",
    "PRIORITY" : "6",
    "_TRANSPORT" : "journal",
    "_MACHINE_ID" : "fefe0acef37f4ae493da96566024a1a5",
    "_HOSTNAME" : "hostname",
    "_UID" : "0",
    "_CAP_EFFECTIVE" : "3fffffffff",
    "_GID" : "0",
    "SYSLOG_FACILITY" : "3",
    "SYSLOG_IDENTIFIER" : "systemd",
    "_PID" : "1",
    "_COMM" : "systemd",
    "_EXE" : "/usr/lib/systemd/systemd",
    "_CMDLINE" : "/sbin/init \\boot\\vmlinuz-linux",
    "_SYSTEMD_CGROUP" : "/init.scope",
    "_SYSTEMD_UNIT" : "init.scope",
    "_SYSTEMD_SLICE" : "-.slice",
    "CODE_FILE" : "src/core/job.c",
    "CODE_LINE" : "804",
    "CODE_FUNCTION" : "job_log_status_message",
    "RESULT" : "done",
    "MESSAGE_ID" : "9d1aaa27d60140bd96365438aad20286",
    "UNIT" : "systemd-modules-load.service",
    "MESSAGE" : "Stopped Load Kernel Modules.",
    "_SOURCE_REALTIME_TIMESTAMP" : "1489351348256146"
}

---

Non-unit messages

Now take a look at the other message. I used -b to restrict output from the last boot, and grep'd for the systemd-modules-load string:

journalctl -a -b | grep systemd-modules-load

Mar 12 16:43:57 hostname systemd-modules-load[235]: Inserted module 'vboxnetflt'

JSON-formatted:

{
    "__CURSOR" : "s=c10ff46a8e1c47ea80f86c6e03d04b6e;i=10def;b=e780d0b343454deeaa77e821716fbf06;m=4b8f66;t=54a8ea763fe19;x=b44b1bca6d34c4e4",
    "__REALTIME_TIMESTAMP" : "1489351437712921",
    "__MONOTONIC_TIMESTAMP" : "4951910",
    "_BOOT_ID" : "e780d0b343454deeaa77e821716fbf06",
    "PRIORITY" : "6",
    "_MACHINE_ID" : "fefe0acef37f4ae493da96566024a1a5",
    "_HOSTNAME" : "hostname",
    "SYSLOG_FACILITY" : "3",
    "_UID" : "0",
    "_GID" : "0",
    "CODE_FILE" : "src/modules-load/modules-load.c",
    "CODE_LINE" : "111",
    "CODE_FUNCTION" : "load_module",
    "SYSLOG_IDENTIFIER" : "systemd-modules-load",
    "_TRANSPORT" : "journal",
    "_PID" : "235",
    "MESSAGE" : "Inserted module 'vboxnetflt'",
    "_SOURCE_REALTIME_TIMESTAMP" : "1489351437693317"
}