Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1619994

Summary: Shutdown doesn't always record the audit SYSTEM_SHUTDOWN message
Product: Red Hat Enterprise Linux 7 Reporter: Renaud Métrich <rmetrich>
Component: systemdAssignee: systemd-maint
Status: CLOSED WONTFIX QA Contact: qe-baseos-daemons
Severity: medium Docs Contact:
Priority: medium    
Version: 7.9CC: dchong, dtardon, jaykim, kwalker, pandrade, pdwyer, vagrawal
Target Milestone: rcKeywords: Reopened, Triaged
Target Release: ---Flags: pm-rhel: mirror+
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: 2022-05-18 12:28:43 UTC 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 Renaud Métrich 2018-08-22 06:39:45 UTC
Description of problem:

On shutdown, boot and runlevel change, an audit SYSTEM_SHUTDOWN/SYSTEM_BOOT/SYSTEM_RUNLEVEL message should be printed in the /var/log/audit/audit.log file.
It appears that SYSTEM_SHUTDOWN is sometimes not written to the log, which may be a concern for some customers requiring this information.

The audit message is generated by the "systemd-update-utmp.service" unit which runs at boot and at shutdown:

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
# systemctl cat systemd-update-utmp.service
[...]
ExecStart=/usr/lib/systemd/systemd-update-utmp reboot
ExecStop=/usr/lib/systemd/systemd-update-utmp shutdown
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

This unit has special dependencies so that ExecStart (generating the SYSTEM_BOOT audit message) runs just after boot and ExecStop (generating the SYSTEM_SHUTDOWN audit message) runs just before shutdown/reboot occurs.

It appears that another special unit named "systemd-update-utmp-runlevel.service", which is responsible for generating "SYSTEM_RUNLEVEL" audit messages) has a dependency on "systemd-update-utmp.service" unit:

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
# systemctl cat systemd-update-utmp-runlevel.service
[...]
Requisite=systemd-update-utmp.service
[...]
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Due to this dependency, there is a conflict happening at shutdown which makes systemd delete one of the unit, and sometimes "systemd-update-utmp.service" is deleted, as shown in the shutdown logs below:

When issue happens (see '<--- HERE'):
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
[   90.315863] systemd[1]: Trying to enqueue job reboot.target/start/replace-irreversibly
[   90.316171] systemd[1]: Looking at job systemd-update-utmp.service/verify-active conflicted_by=no
[   90.316174] systemd[1]: Looking at job systemd-update-utmp.service/stop conflicted_by=no
[   90.316178] systemd[1]: Fixing conflicting jobs systemd-update-utmp.service/verify-active,systemd-update-utmp.service/stop by deleting job systemd-update-utmp.service/stop   <--- HERE
[   90.316185] systemd[1]: Fixing conflicting jobs systemd-reboot.service/stop,systemd-reboot.service/start by deleting job systemd-reboot.service/stop
[   90.316188] systemd[1]: Deleting job shutdown.target/stop as dependency of job systemd-reboot.service/stop
[   90.316191] systemd[1]: Deleting job systemd-update-utmp-runlevel.service/start as dependency of job shutdown.target/stop
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

When issue doesn't happen:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
[  166.642977] systemd[1]: Trying to enqueue job reboot.target/start/replace-irreversibly
[  166.643413] systemd[1]: Fixing conflicting jobs shutdown.target/stop,shutdown.target/start by deleting job shutdown.target/stop
[  166.643418] systemd[1]: Deleting job systemd-update-utmp-runlevel.service/start as dependency of job shutdown.target/stop
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------


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

systemd-219


How reproducible:

Very often


Steps to Reproduce:
1. Reboot in loop from the outside

  $ while sleep 30; do ssh root@vm-shutdown7 reboot; done

2. Check audit log content

  # ausearch -m SYSTEM_BOOT -m SYSTEM_SHUTDOWN


Actual results:

You may have 2 "SYSTEM_BOOT" messages in a row.


Expected results:

"SYSTEM_BOOT" message, then "SYSTEM_SHUTDOWN" message, then again "SYSTEM_BOOT" message, ...


Additional info:

It is unclear to me why the "Requisite=systemd-update-utmp.service" dependency has been added to the unit.
It seems that removing it from "systemd-update-utmp-runlevel.service" solves the issue, without affecting the "systemd-update-utmp-runlevel.service" unit behaviour at all.

Also, I wasn't able to reproduce on Fedora 28 even though the service unit is identical.
On Fedora 28, it seems there is no conflicting jobs requiring deletion upon shutdown.

Comment 2 Kyle Walker 2020-02-20 23:37:25 UTC
I am unable to reproduce the same condition on RHEL 8 after multiple attempts. Though a side-by-side comparison with a RHEL 7 system shows that it is reproducible after a few iterations. That being said, when Red Hat shipped 7.7 on Aug 6, 2019 Red Hat Enterprise Linux 7 entered Maintenance Support 1 Phase.

    https://access.redhat.com/support/policy/updates/errata#Maintenance_Support_1_Phase

That means only "Critical and Important Security errata advisories (RHSAs) and Urgent Priority Bug Fix errata advisories (RHBAs) may be released". This BZ does not appear to meet Maintenance Support 1 Phase criteria so is being closed NEXTRELEASE. If this is critical for your environment please open a case in the Red Hat Customer Portal, https://access.redhat.com, provide a thorough business justification and ask that the BZ be re-opened for consideration in the next minor release.

Comment 4 Renaud Métrich 2020-04-14 12:05:55 UTC
I would like to reopen this.

The justification is the admin must have a way to know if the reboot was due to a crash or clean reboot happened.

Digging there, it looks like a solution is to remove the "Requisite" dependency in systemd-update-utmp-runlevel.service:

/etc/systemd/system/systemd-update-utmp-runlevel.service:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
[Unit]
Description=Update UTMP about System Runlevel Changes
Documentation=man:systemd-update-utmp.service(8) man:utmp(5)
DefaultDependencies=no
RequiresMountsFor=/var/log/wtmp
Conflicts=shutdown.target
#Requisite=systemd-update-utmp.service
After=systemd-update-utmp.service
After=runlevel1.target runlevel2.target runlevel3.target runlevel4.target runlevel5.target
Before=shutdown.target

[Service]
Type=oneshot
ExecStart=/usr/lib/systemd/systemd-update-utmp runlevel
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

This prevents the "systemd-update-utmp/verify-active" job to run and create the conflict.

Testing this, after 48 reboots, the service *all* ran successfully:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
# ausearch -m SYSTEM_BOOT | grep -c SYSTEM_BOOT
48
# ausearch -m SYSTEM_SHUTDOWN | grep -c SYSTEM_SHUTDOWN
48
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------


Reproducer:
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
for i in $(seq 1 50); do
  echo "Reboot $i"
  while ! timeout 5 ssh -o ConnectTimeout=5s vm-shutdown7 true; do
    sleep 5
  done
  ssh vm-shutdown7 reboot
  sleep 10
done
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

Comment 5 Vishal Agrawal 2020-07-18 12:40:27 UTC
Hi Team,

I found the same issue while working on case 02691482

Hence attaching the same.

I did not have a assured reproducer, but I was able to hit
the same problem many a times while testing.

[1] when shutdown event was noted.


1127.8.2.el7 ---> 327.el7


# last -x reboot shutdown|head
reboot   system boot  3.10.0-327.el7.x Sat Jul 18 17:31 - 17:31  (00:00)    
shutdown system down  3.10.0-1127.8.2. Sat Jul 18 17:31 - 17:31  (00:00)    

-------------------
[  OK  ] Stopped target System Initialization.
[  OK  ] Stopped target Local Encrypted Volumes.
[  OK  ] Stopped Read and set NIS domainname from /etc/sysconfig/network.
         Stopping Update UTMP about System Boot/Shutdown...
         Stopping Load/Save Random Seed...
[  OK  ] Stopped Apply Kernel Variables.
[  OK  ] Stopped Setup Virtual Console.
[  OK  ] Stopped Load/Save Random Seed.
[  OK  ] Stopped Update UTMP about System Boot/Shutdown.                       <=====---------------------<-----
         Stopping Security Auditing Service...
-------------------

As you can see above the service is stopped and hence 'shutdown' event was logged

[2] When shutdown event did *NOT* get logged


1127.8.2.el7 ---> 1062.1.2.el7

# last -x reboot shutdown|head
reboot   system boot  3.10.0-1062.1.2. Sat Jul 18 17:37 - 17:37  (00:00)    
reboot   system boot  3.10.0-1127.8.2. Sat Jul 18 17:36 - 17:37  (00:01)    

We do not see shutdown entry here

---------------
[  OK  ] Stopped target System Initialization.
[  OK  ] Stopped target Swap.
         Deactivating swap /dev/disk/by-uuid...0-4879-4e19-be36-1f4e3b112f90...
         Stopping Security Auditing Service...
[  OK  ] Stopped Setup Virtual Console.
[  OK  ] Stopped Read and set NIS domainname from /etc/sysconfig/network.
         Stopping Load/Save Random Seed...
[  OK  ] Stopped Apply Kernel Variables.
[  OK  ] Stopped target Local Encrypted Volumes.
---------------

NOTE:
======

-> Do not think that this is issue within kernel versions.

-> I used 'reboot' command only during both the times.

Comment 8 Chris Williams 2020-11-11 21:47:31 UTC
Red Hat Enterprise Linux 7 shipped it's final minor release on September 29th, 2020. 7.9 was the last minor releases scheduled for RHEL 7.
From intial triage it does not appear the remaining Bugzillas meet the inclusion criteria for Maintenance Phase 2 and will now be closed. 

From the RHEL life cycle page:
https://access.redhat.com/support/policy/updates/errata#Maintenance_Support_2_Phase
"During Maintenance Support 2 Phase for Red Hat Enterprise Linux version 7,Red Hat defined Critical and Important impact Security Advisories (RHSAs) and selected (at Red Hat discretion) Urgent Priority Bug Fix Advisories (RHBAs) may be released as they become available."

If this BZ was closed in error and meets the above criteria please re-open it flag for 7.9.z, provide suitable business and technical justifications, and follow the process for Accelerated Fixes:
https://source.redhat.com/groups/public/pnt-cxno/pnt_customer_experience_and_operations_wiki/support_delivery_accelerated_fix_release_handbook  

Feature Requests can re-opened and moved to RHEL 8 if the desired functionality is not already present in the product. 

Please reach out to the applicable Product Experience Engineer[0] if you have any questions or concerns.  

[0] https://bugzilla.redhat.com/page.cgi?id=agile_component_mapping.html&product=Red+Hat+Enterprise+Linux+7