Bug 2230348

Summary: reboot of the system, rsyslog will not record the reboot log in messages which compared with the previous rhel7
Product: Red Hat Enterprise Linux 8 Reporter: yruo
Component: rsyslogAssignee: Attila Lakatos <alakatos>
Status: NEW --- QA Contact: BaseOS QE Security Team <qe-baseos-security>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 8.6CC: rsroka
Target Milestone: rcKeywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description yruo 2023-08-09 11:02:13 UTC
Description of problem:
 Graceful reboot system, rsyslog will not record the reboot log in messages which compared with the previous rhel7

Version-Release number of selected component (if applicable):
RHEL8

How reproducible:
N/A

Steps to Reproduce:
1. in RHEL8 run "systemctl reboot" to reboot system.
Then /var/log/messages haven't record system process normal stop procedure info and only record system startup info.  it is difficult for us to detect whether the system is a graceful shutdown/reboot or not.
~~~
Jul 31 01:48:22 testserver rsyslogd[1908]: [origin software="rsyslogd" swVersion="8.2102.0-13.el8" x-pid="1908" x-info="https://www.rsyslog.com"] start
Jul 31 01:48:22 testserver systemd[1]: Started System Logging Service.
Jul 31 01:48:22 testserver rsyslogd[1908]: imjournal: journal files changed, reloading...  [v8.2102.0-13.el8 try https://www.rsyslog.com/e/0 ]
Jul 31 01:49:08 testserver kernel: Command line: BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-193.13.2.el8_2.x86_64
~~~

2. In RHEl7 "systemctl reboot" to reboot system. /var/log/messages will record system process normal stop procedure info and record system startup info. it is easy for us to detect the system is a graceful shutdown/reboot.
~~~
Aug  9 16:16:48 rhel7 systemd: Stopped Dump dmesg to /var/log/dmesg.
Aug  9 16:16:48 rhel7 systemd: Stopped target RPC Port Mapper.
Aug  9 16:16:48 rhel7 systemd: Stopped target Timers.
Aug  9 16:16:48 rhel7 systemd: Stopping RPC bind service...
Aug  9 16:16:48 rhel7 systemd: Stopped target Multi-User System.
Aug  9 16:16:48 rhel7 systemd: Stopping OpenSSH server daemon...
Aug  9 16:16:48 rhel7 systemd: Stopped Resets System Activity Logs.
Aug  9 16:16:48 rhel7 systemd: Stopping Command Scheduler...
Aug  9 16:16:48 rhel7 systemd: Unmounting RPC Pipe File System...
Aug  9 16:16:48 rhel7 systemd: Stopping Authorization Manager...
Aug  9 16:16:48 rhel7 systemd: Stopped Daily Cleanup of Temporary Directories.
Aug  9 16:16:48 rhel7 systemd: Stopping LSB: Starts the Spacewalk Daemon...
Aug  9 16:16:48 rhel7 systemd: Removed slice system-selinux\x2dpolicy\x2dmigrate\x2dlocal\x2dchanges.slice.
Aug  9 16:16:48 rhel7 systemd: Stopping Enable periodic update of entitlement certificates....
Aug  9 16:16:48 rhel7 systemd: Stopping irqbalance daemon...
...
Aug  9 16:17:19 rhel7 kernel: Linux version 3.10.0-1160.95.1.el7.x86_64 (mockbuild.eng.bos.redhat.com) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-44) (GCC) ) #1 SMP Fri Jun 23 08:44:55 EDT 2023
~~~

Actual results:
In RHEL8, no graceful shutdown/reboot info in messages

Expected results:
messages record graceful shutdown/reboot info such as the previous rhel7 

Additional info:
However, In RHEL8 we can use below workaround to fix it
Configuring the journal to be permanently saved in a file, the messages log can normally record the shutdown/reboot info. 
~~~
# mkdir -p /var/log/journal
# systemctl restart systemd-journald.service
# systemctl reboot
~~~
Then from message, we know it is a graceful shutdown/reboot
~~~
Jul 31 01:30:23 testserver systemd-logind[974]: System is rebooting.
…
Jul 31 01:30:23 testserver sssd[nss][963]: Shutting down
…
Jul 31 01:30:23 testserver NetworkManager[987]: <info>  [1690781423.5682] caught SIGTERM, shutting down normally.
…
Jul 31 01:30:24 testserver systemd[1]: Shutting down.
~~~

Comment 1 Attila Lakatos 2023-08-09 13:21:56 UTC
Hello,

Rsyslog is not responsible for managing content of the journal. By default, rsyslog reads logs from journal and outputs them to diverse destinations, such as /var/log/messages.

Could you compare the output of /var/log/messages with the output of 'journalctl' on both rhel7 and rhel8?
If there is a difference between the two outputs then it's definitely a bug. Otherwise, it needs to be solved somewhere else.

Thank you,
Attila

Comment 2 yruo 2023-08-14 11:36:16 UTC
Hello Attila,
  Thanks for your help on this BUG.

  Right now, it looks like RHEL8 rsyslog haven’t record logs from journal and outputs them to /var/log/messages during reboot/shutdown.  RHEL7 is normal.

>Could you compare the output of /var/log/messages with the output of 'journalctl' on both rhel8?
>>In RHEL8 /var/log/messages cannot record graceful shutdown/reboot

Aug 14 05:30:01 testserver systemd[1]: sysstat-collect.service: Succeeded.
Aug 14 05:30:01 testserver systemd[1]: Started system activity accounting tool.
Aug 14 05:40:01 testserver systemd[1]: Starting system activity accounting tool...
Aug 14 05:40:01 testserver systemd[1]: sysstat-collect.service: Succeeded.
Aug 14 05:40:01 testserver systemd[1]: Started system activity accounting tool.
Aug 14 05:50:01 testserver systemd[1]: Starting system activity accounting tool...
Aug 14 05:50:01 testserver systemd[1]: sysstat-collect.service: Succeeded.
Aug 14 05:50:01 testserver systemd[1]: Started system activity accounting tool.    <———— initial reboot
Aug 14 05:58:54 testserver kernel: Command line: BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-193.13.2.el8_2.x86_64

>> journal log also cannot show graceful shutdown/reboot log since journal normally only record log in /run/log/journal and will dispeared once reboot
# journalctl 
-- Logs begin at Mon 2023-08-14 05:58:54 EDT, end at Mon 2023-08-14 07:29:01 EDT. --
8月 14 05:58:54 testserver kernel: Linux version 4.18.0-193.13.2.el8_2.x86_64 (mockbuild.eng.bos.redhat.com) (gcc version 8.3.1 20191121 (>
8月 14 05:58:54 testserver kernel: Command line: BOOT_IMAGE=(hd0,msdos1)/vmlinuz-4.18.0-193.13.2.el8_2.x86_64 root=/dev/mapper/rhel_vm250--84-root ro cras>


In RHEL8:
 -if We let journal log save to disk,  then /var/log/messages can record the log which from journal log(save to local such as /var/log/journal
~~~
# mkdir -p /var/log/journal
# systemctl restart systemd-journald.service
# systemctl reboot
~~~
Then from /var/log/message, we know it is a graceful shutdown/reboot
~~~
Jul 31 01:30:23 testserver systemd-logind[974]: System is rebooting.
…
Jul 31 01:30:23 testserver sssd[nss][963]: Shutting down
…
Jul 31 01:30:23 testserver NetworkManager[987]: <info>  [1690781423.5682] caught SIGTERM, shutting down normally.
…
Jul 31 01:30:24 testserver systemd[1]: Shutting down.
~~~
 -if we let journal log keep default setting(save in ring-buffer in /run/log/journal),then /var/log/messages can record the log during the system reboot/shutdown, then rsyslog can not

Comment 3 Attila Lakatos 2023-08-15 08:04:47 UTC
Hi,

On a clean VM, I can not see a difference in the /var/log/messages file. I've tried RHEL7, RHEL8, RHEL9 as well with the default configurations. I could take a deeper look on the problem if we had a reproducer, however:
If you want to ensure that journal data should be stored persistently, and don't want to create the appropriate folders manually every time after boot, then I suggest to use the Storage="persistent" journald configuration option in /etc/systemd/journald.conf.

From the journald.conf manual page:
Storage=Controls where to store journal data.If "persistent", data will be stored preferably on disk, i.e. below the /var/log/journal hierarchy (which is created if needed), with a fallback to /run/log/journal (which is created if needed), during early boot and if the disk is not writable. The "auto" is similar to "persistent" but the directory /var/log/journal is not created if needed, so that its existence controls where log data goes. Defaults to "auto".