What were you trying to do that didn't work?
Very often, when restorecond service start (service delivered by policycoreutils-restorecond package), the following message is seen:
# systemctl status restorecond [...] Jan 05 14:20:29 vm-rhel9 systemd[1]: Starting Restorecon maintaining path file context... Jan 05 14:20:29 vm-rhel9 systemd[1]: restorecond.service: Can't open PID file /run/restorecond.pid (yet?) after start: Operation not permitted Jan 05 14:20:29 vm-rhel9 systemd[1]: Started Restorecon maintaining path file context.
This message is confusing and also wrong: there is no EPERM here (as seen with stracing), because in fact /run/restorecond.pid doesn't exist yet, it should return ENOENT if any message is really needed here (I believe this message should just not show up at all).
The root cause for seeing this is restorecond forked to become a daemon but didn't write its PID file yet.
What is the impact of this issue to you?
Annoyance
Please provide the package NVR for which the bug is seen:
systemd-252-55.el9_7.7
How reproducible is this bug?
Very often.
Always with reproducer below.
Steps to reproduce
- Stop restorecond service
# systemctl stop restorecond
- Install/configure systemtap
# yum -y install systemtap yum-utils # stap-prep # debuginfo-install policycoreutils-restorecond
- Execute systemtap script below to delay restorecond between its fork and PID file creation
# stap -v -g -e 'probe process("/usr/sbin/restorecond").statement("*@restorecond.c:217") { mdelay(500); }' - In another terminal start the service while stracing systemd
# strace -ttTvyy -s 256 -o systemd.strace -p 1 & # systemctl start restorecond
Expected results
Service starts without printing "Can't open PID file ..." message.
Actual results
[...] 1 14:20:29.618691 openat(80</run>, "restorecond.pid", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No such file or directory) <0.000006> 1 14:20:29.618708 close(80</run>) = 0 <0.000002> 1 14:20:29.618723 gettid() = 1 <0.000002> 1 14:20:29.618735 sendmsg(24<UNIX:[16659->14312]>, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="PRIORITY=6\nSYSLOG_FACILITY=3\nTID=1\nCODE_FILE=src/core/service.c\nCODE_LINE=992\nCODE_FUNC=service_load_pid_file\nUNIT=restorecond.service\nINVOCATION_ID=18e3ef03768f4b6eadb165cc3cf210d2\nSYSLOG_IDENTIFIER=systemd\n", iov_len=208}, {iov_base="MESSAGE=", iov_len=8}, {iov_base="restorecond.service: Can't open PID file /run/restorecond.pid (yet?) after start: Operation not permitted", iov_len=105}, {iov_base="\n", iov_len=1}], msg_iovlen=4, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 322 <0.000010>
- is cloned by
-
RHEL-142541 restorecond fails to start in timeout from time to time
-
- New
-
- links to