dghubble reported a new issue against the project: `atomic-wg` that you are following: `` systemd-journald is missing logs on fresh droplets. journalctl shows nothing for any unit.
``` $ journalctl No journal files were found. -- No entries -- ```
That's not right. There should at least be some system logs there. Check any unit and find no entries.
It seems like restarting `systemd-journald` or rebooting works around the issue, so its present only on fresh droplets. Originally observed on DigitalOcean's `20180424.4` image and doing a rolling upgrade to `28.20180425.0` addressed the issue - but that probably only worked because of the reboot. Since fresh `28.20180425.0` droplets now also have the systemd-journald issue.
``` ● ostree://fedora-atomic:fedora/28/x86_64/atomic-host Version: 28.20180425.0 (2018-04-25 19:14:57) Commit: 94a9d06eef34aa6774c056356d3d2e024e57a0013b6f8048dbae392a84a137ca GPGSignature: Valid signature by 128CF232A9371991C8A65695E08E7E629DB62FB1 ```
https://twitter.com/dghubble/status/993277668828168192 ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
miabbott added a new comment to an issue you are following: `` I booted up an F28AH in Digital Ocean and started to look around.
There's definitely a journal file present, but I'm not sure why the `systemd-journald` service isn't reading it.
``` [root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# ls -latr /var/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7/ total 8192 drwxr-sr-x+ 3 root systemd-journal 46 May 11 14:40 .. drwxr-sr-x+ 2 root systemd-journal 28 May 11 14:40 . -rw-r-----+ 1 root systemd-journal 8388608 May 11 14:42 system.journal
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# file /var/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7/system.journal /var/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7/system.journal: Journal file, online
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# journalctl -n 10 --file=/var/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7/system.journal -- Logs begin at Fri 2018-05-11 14:40:34 UTC, end at Fri 2018-05-11 14:42:03 UTC. -- May 11 14:41:00 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Startup finished in 1.716s (kernel) + 2.671s (initrd) + 23.610s (userspace) = 27.998s. May 11 14:41:00 fedoraatomic-s-1vcpu-1gb-nyc1-01 rpm-ostree[1287]: In idle state; will auto-exit in 60 seconds May 11 14:41:00 fedoraatomic-s-1vcpu-1gb-nyc1-01 rpm-ostree[1287]: Allowing active client :1.21 (uid 0) May 11 14:41:00 fedoraatomic-s-1vcpu-1gb-nyc1-01 rpm-ostree[1287]: client :1.21 (uid 0) added; new total=1 May 11 14:41:00 fedoraatomic-s-1vcpu-1gb-nyc1-01 rpm-ostree[1287]: client :1.21 (uid 0) vanished; remaining=0 May 11 14:41:00 fedoraatomic-s-1vcpu-1gb-nyc1-01 rpm-ostree[1287]: In idle state; will auto-exit in 63 seconds May 11 14:41:05 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/l> May 11 14:41:21 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/syste> May 11 14:42:03 fedoraatomic-s-1vcpu-1gb-nyc1-01 rpm-ostree[1287]: In idle state; will auto-exit in 61 seconds May 11 14:42:03 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=rpm-ostreed comm="systemd" exe="/usr/lib/systemd/sys
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# journalctl -u systemd-journald --file=/var/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7/system.journal -- Logs begin at Fri 2018-05-11 14:40:34 UTC, end at Fri 2018-05-11 14:42:03 UTC. -- May 11 14:40:34 localhost systemd-journald[185]: Journal started May 11 14:40:34 localhost systemd-journald[185]: Runtime journal (/run/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7) is 6.1M, max 49.2M, 43.0M free. May 11 14:40:37 localhost systemd-journald[185]: Journal stopped May 11 14:40:38 localhost.localdomain systemd-journald[612]: Journal started May 11 14:40:38 localhost.localdomain systemd-journald[612]: Runtime journal (/run/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7) is 6.1M, max 49.2M, 43.0M free. May 11 14:40:39 localhost.localdomain systemd-journald[612]: Runtime journal (/run/log/journal/4eddc7982ffd4847a32ecd3f6d3170d7) is 6.1M, max 49.2M, 43.0M free. May 11 14:40:40 localhost.localdomain systemd-journald[612]: Time spent on flushing to /var is 46.350ms for 768 entries. ```
When the `systemd-journald` service is restarted, it creates a new directory under `/var/log/journal`
```
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# systemctl restart systemd-journald
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# journalctl --list-boots 0 619b79e423a8400bbc348657c5c641d9 Fri 2018-05-11 15:07:24 UTC—Fri 2018-05-11 15:07:24 UTC
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# ls -la /var/log/journal/ total 0 drwxr-sr-x+ 4 root systemd-journal 86 May 11 15:07 . drwxr-xr-x. 8 root root 199 May 11 14:40 .. drwxr-sr-x+ 2 root systemd-journal 28 May 11 14:40 4eddc7982ffd4847a32ecd3f6d3170d7 drwxr-sr-x+ 2 root systemd-journal 28 May 11 15:07 821032e961bc6d04ca1012bc5af5ab7c
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# ls -la /var/log/journal/821032e961bc6d04ca1012bc5af5ab7c/ total 8192 drwxr-sr-x+ 2 root systemd-journal 28 May 11 15:07 . drwxr-sr-x+ 4 root systemd-journal 86 May 11 15:07 .. -rw-r-----+ 1 root systemd-journal 8388608 May 11 15:07 system.journal
[root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# journalctl -b -- Logs begin at Fri 2018-05-11 15:07:24 UTC, end at Fri 2018-05-11 15:07:24 UTC. -- May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd-journald[612]: Received SIGTERM from PID 1 (systemd). May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Stopping Journal Service... May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Stopped Journal Service. May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Starting Journal Service... May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd-journald[1655]: Journal started May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd-journald[1655]: System journal (/var/log/journal/821032e961bc6d04ca1012bc5af5ab7c) is 8.0M, max 2.3G, 2.3G free. May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-journald comm="systemd" exe="/usr/lib/system> May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Started Journal Service. May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit: CONFIG_CHANGE audit_enabled=1 old=1 auid=4294967295 ses=4294967295 subj=system_u:system_r:syslogd_t:s0 res=1 May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-journald comm="systemd" exe="/usr/lib/syste> May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Starting Flush Journal to Persistent Storage... May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-journal-flush comm="systemd" exe="/usr/lib/> May 11 15:07:24 fedoraatomic-s-1vcpu-1gb-nyc1-01 systemd[1]: Started Flush Journal to Persistent Storage. ```
I booted the corresponding qcow2 locally on my workstation and did not observe the same issue.
Hmm...this might get us closer to the answer. On the local VM which did not observe the problem, the value of `/etc/machine-id` matches the value of the directory where the journal is stored on disk:
``` # cat /etc/machine-id ecb200d1e3564c7f86ec7d31dc967204
# ls -l /var/log/journal/ total 0 drwxr-sr-x+ 2 root systemd-journal 28 May 11 15:21 ecb200d1e3564c7f86ec7d31dc967204 ```
But on the Digital Ocean droplet, those values are out of sync:
``` [root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# cat /etc/machine-id 821032e961bc6d04ca1012bc5af5ab7c [root@fedoraatomic-s-1vcpu-1gb-nyc1-01 ~]# ls -l /var/log/journal/ total 0 drwxr-sr-x+ 2 root systemd-journal 28 May 11 14:40 4eddc7982ffd4847a32ecd3f6d3170d7 ```
Only after the `systemd-journald` service is restarted, does the matching entry show up.
I'm unable to find any smoking gun in the journal file as to where that early machine-id is coming from, though.
``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
miabbott added a new comment to an issue you are following: `` The Digital Ocean droplets look like they are initializing the machine-id twice, the second time looks like something getting passed in via `cloud-init`. Compare the entries in the journal between the Digital Ocean droplet and the local VM:
Digital Ocean: ``` # journalctl --no-pager --file /var/log/journal/05f14c08dd2f423d9dd490477487bc74/system.journal | grep machine May 11 15:35:45 localhost systemd[1]: Initializing machine ID from KVM UUID. May 11 15:35:48 localhost.localdomain systemd[1]: Initializing machine ID from KVM UUID. May 11 15:35:48 localhost.localdomain systemd[1]: Installed transient /etc/machine-id file. May 11 15:35:49 localhost.localdomain systemd[1]: Starting Commit a transient machine-id on disk... May 11 15:35:49 localhost.localdomain systemd[1]: Started Commit a transient machine-id on disk. May 11 15:35:49 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-machine-id-commit comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' May 11 15:35:49 localhost.localdomain kernel: audit: type=1130 audit(1526052949.238:77): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-machine-id-commit comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' May 11 15:36:01 fedoraatomic-s-1vcpu-1gb-nyc1-01 cloud-init[1235]: Initializing machine ID from D-Bus machine ID. ```
Local VM: ``` # journalctl --no-pager --file /var/log/journal/ecb200d1e3564c7f86ec7d31dc967204/system.journal | grep machine May 11 15:21:23 localhost systemd[1]: Initializing machine ID from KVM UUID. May 11 15:21:27 localhost.localdomain systemd[1]: Initializing machine ID from KVM UUID. May 11 15:21:27 localhost.localdomain systemd[1]: Installed transient /etc/machine-id file. May 11 15:21:28 localhost.localdomain systemd[1]: Starting Commit a transient machine-id on disk... May 11 15:21:28 localhost.localdomain systemd[1]: Started Commit a transient machine-id on disk. May 11 15:21:28 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-machine-id-commit comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' May 11 15:22:52 atomichost-by-dustymabe dbus-daemon[735]: [system] Activating via systemd: service name='org.freedesktop.machine1' unit='dbus-org.freedesktop.machine1.service' requested by ':1.18' (uid=0 pid=1277 comm="machinectl " label="unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023") May 11 15:22:52 atomichost-by-dustymabe dbus-daemon[735]: [system] Successfully activated service 'org.freedesktop.machine1' May 11 15:22:52 atomichost-by-dustymabe audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-machined comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' ```
I think we need to talk to someone on the Digital Ocean side about what they are doing in `cloud-init` to cause this to happen. ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
The issue: `systemd-journald has no logs on fresh DigitalOcean droplets` of project: `atomic-wg` has been assigned to `katrinaeg` by dustymabe.
dustymabe added a new comment to an issue you are following: `` Assigning to @katrinaeg from DO ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
dghubble added a new comment to an issue you are following: `` This is a bit of a pickle because the `fedora-27-x64-atomic` image has disappeared too. I suppose just restarting systemd-journald via cloudinit first boot (i.e. bootcmd). ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
dghubble added a new comment to an issue you are following: `` To followup, bootcmd seems too early to be a workaround.
``` bootcmd: - [systemctl, restart, systemd-journald] ``` ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
dustymabe added a new comment to an issue you are following: ``
To followup, bootcmd seems too early to be a workaround. What I suggested does NOT work. bootcmd:
- [systemctl, restart, systemd-journald]
yeah since that probably happens before cloud-init stuff runs. What about a `runcmd`? You might need to add `--no-block`: `- [systemctl, restart, --no-block, systemd-journald]` ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
ryanpq added a new comment to an issue you are following: `` We have deployed a fix for this issue. Newly created Fedora Atomic droplets on DigitalOcean now have a working systemd-journald with logs at boot. ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
miabbott added a new comment to an issue you are following: ``
We have deployed a fix for this issue. Newly created Fedora Atomic droplets on DigitalOcean now have a working systemd-journald with logs at boot.
Woo! Just confirmed this myself! Thanks DO peeps! ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
dustymabe added a new comment to an issue you are following: `` Thanks @ryanpq ``
To reply, visit the link below or just reply to this email https://pagure.io/atomic-wg/issue/468
The status of the issue: `systemd-journald has no logs on fresh DigitalOcean droplets` of project: `atomic-wg` has been updated to: Closed as Fixed by dustymabe.
atomic@lists.stg.fedoraproject.org
-
Dalton Hubble -
Dusty Mabe
-
Micah Abbott
-
Ryan Quinn