Bug 1761962 - error starting pmlogger; pid file not owned by root
Summary: error starting pmlogger; pid file not owned by root
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: pcp
Version: 32
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Mark Goodwin
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-10-15 17:42 UTC by George R. Goffe
Modified: 2023-12-15 16:50 UTC (History)
10 users (show)

Fixed In Version: pcp-5.1.0 pcp-5.1.0-1.fc31 pcp-5.1.0-1.fc32
Clone Of:
Environment:
Last Closed: 2020-05-03 04:53:55 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description George R. Goffe 2019-10-15 17:42:59 UTC
Description of problem:


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


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:


1030 Jul 29 00:10:32 fc31 systemd[1]: pmlogger.service: New main PID 17915 does not belong to service, and PID file is not owned by root. Refusing.
1031 Jul 29 00:10:32 fc31 systemd[1]: pmlogger.service: New main PID 17915 does not belong to service, and PID file is not owned by root. Refusing.

96 Jul 28 16:56:41 fc31 pmlogger[7973]: Starting pmlogger ...
97 Jul 28 16:56:41 fc31 systemd[1]: pmlogger.service: Can't open PID file /run/pcp/pmlogger.pid (yet?) after start: No such file or directory
98 Jul 28 16:56:54 fc31 systemd[1]: pmlogger.service: Supervising process 13334 which is not our child. We'll most likely not notice when it exits.
99 Jul 28 16:56:54 fc31 systemd[1]: Started Performance Metrics Archive Logger.

Comment 1 Nathan Scott 2019-10-16 05:49:36 UTC
Mark has been looking into systemd-pcp-related failures, reassigning his way.

Comment 2 Mark Goodwin 2019-10-17 13:17:14 UTC
Thanks for the report George. I assume you're running latest in f31 pcp-4.3.4-1.fc31.x86_64.rpm.
This is a known issue with pmlogger and it's systemd configuration, e.g. see BZ 1721223 and related BZs.

The messages are coming from systemd when it's starting the pmlogger service. Since this service is type=forking, systemd is not notified when the pmlogger process has started ('Can't open PID file ...' messages), and then later when pmlogger HAS started and forked and the child has written the pid file, systemd correctly notices. However systemd complains yet again because it's didn't start that process (pmlogger did when it forked).

The messages are benign - the pmlogger service still starts correctly. The solution is to quieten systemd by changing the pmlogger service unit over to type=notify instead of the current type=forking. Then systemd will be notified by pmlogger that the daemon process has started and we will no longer get those messages.

I'll leave this BZ open for now until we've had a chance to update the service configs and updated pmlogger to notify systemd using the sd_notify(3) API.

Comment 3 George R. Goffe 2019-10-17 13:26:38 UTC
Mark,

You're welcome.

As you can see, I filed the report against systemd and Zbigniew was so kind as to forward the report to the other services who were complained about...

My system is a FC32 rawhide... "boldly going where no-one has gone before" as it where. Keeps my mind active... finding all sorts of goofy and sometimes REALLY scary bugs... reporting some too... Learning all the while since I use this system for daily activities... updating whenever updates/upgrades are available. :-)

My pcp is at pcp-4.3.4-3.fc32.x86_64 by the way.

Regards,

George...

Comment 4 Ben Cotton 2020-02-11 17:51:30 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 32 development cycle.
Changing version to 32.

Comment 5 Martin Wolf 2020-02-18 16:02:40 UTC
This problem is also present on my Fedora 31 Server:

pmlogger.service: New main PID 69637 does not belong to service, and PID file is not owned by root. Refusing.
CODE_FILE	src/core/service.c
CODE_FUNC	service_load_pid_file
CODE_LINE	1015
INVOCATION_ID	3b7a39cb02b54aafb29fe5fe52be7d4d
PRIORITY	3
SYSLOG_FACILITY	3
SYSLOG_IDENTIFIER	systemd
UNIT	pmlogger.service
_BOOT_ID	005725ce15494fe981158ac13def8a89
_CAP_EFFECTIVE	3fffffffff
_CMDLINE	/usr/lib/systemd/systemd --switched-root --system --deserialize 29
_COMM	systemd
_EXE	/usr/lib/systemd/systemd
_GID	0
_HOSTNAME	<myhostname>
_MACHINE_ID	1aced3fe4b8c4152ba7e573523bcdf22
_PID	1
_SELINUX_CONTEXT	system_u:system_r:init_t:s0
_SOURCE_REALTIME_TIMESTAMP	1581981013227601
_SYSTEMD_CGROUP	/init.scope
_SYSTEMD_SLICE	-.slice
_SYSTEMD_UNIT	init.scope
_TRANSPORT	journal
_UID	0
__CURSOR	s=59cee3b08f3f4289bf48b41feace805c;i=2e90c;b=005725ce15494fe981158ac13def8a89;m=178c92569c;t=59ecda855b8a8;x=7b1b415d9bd58c47
__MONOTONIC_TIMESTAMP	101142648476
__REALTIME_TIMESTAMP	1581981013227688

Comment 6 Robert Hinson 2020-04-10 17:56:53 UTC
pmlogger.service: New main PID 1438 does not belong to service, and PID file is not owned by root. Refusing.
CODE_FILE	src/core/service.c
CODE_FUNC	service_load_pid_file
CODE_LINE	1002
INVOCATION_ID	f056cfd5a34c462a8666012eb5ed5448
PRIORITY	3
SYSLOG_FACILITY	3
SYSLOG_IDENTIFIER	systemd
UNIT	pmlogger.service
_BOOT_ID	521f3941954b46c29beada274b84954a
_CAP_EFFECTIVE	3fffffffff
_CMDLINE	/usr/lib/systemd/systemd --switched-root --system --deserialize 30
_COMM	systemd
_EXE	/usr/lib/systemd/systemd
_GID	0
_HOSTNAME	fc32server
_MACHINE_ID	a372a7bb09b8439fa92e426c6f0dea69
_PID	1
_SELINUX_CONTEXT	system_u:system_r:init_t:s0
_SOURCE_REALTIME_TIMESTAMP	1586540022035819
_SYSTEMD_CGROUP	/init.scope
_SYSTEMD_SLICE	-.slice
_SYSTEMD_UNIT	init.scope
_TRANSPORT	journal
_UID	0
__CURSOR	s=6b714a8ebfdf4206a5b953ee95e0dbc8;i=7f8;b=521f3941954b46c29beada274b84954a;m=45f8987;t=5a2f3226f759d;x=55c8990abcc70f3a
__MONOTONIC_TIMESTAMP	73369991
__REALTIME_TIMESTAMP	1586540022035869


This is on Fedora 32 64Bit pcp-5.0.3-4.fc32.x86_64

Comment 7 Mark Goodwin 2020-04-23 07:58:07 UTC
In pcp-5.1.0, the pmlogger service unit has been changed to Type=notify,
along with many updates to the pmlogger_daily and pmlogger_check scripts
and QA tests.

Comment 8 Fedora Update System 2020-04-24 05:27:37 UTC
FEDORA-2020-5135a0cdd3 has been submitted as an update to Fedora 32. https://bodhi.fedoraproject.org/updates/FEDORA-2020-5135a0cdd3

Comment 9 Fedora Update System 2020-04-24 05:29:38 UTC
FEDORA-2020-bc7c7d9c84 has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2020-bc7c7d9c84

Comment 10 Fedora Update System 2020-04-25 04:18:59 UTC
FEDORA-2020-bc7c7d9c84 has been pushed to the Fedora 31 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-bc7c7d9c84`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-bc7c7d9c84

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 11 Fedora Update System 2020-04-25 12:20:58 UTC
FEDORA-2020-5135a0cdd3 has been pushed to the Fedora 32 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-5135a0cdd3`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-5135a0cdd3

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 12 Fedora Update System 2020-05-03 04:53:55 UTC
FEDORA-2020-bc7c7d9c84 has been pushed to the Fedora 31 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 13 Fedora Update System 2020-05-03 05:29:38 UTC
FEDORA-2020-5135a0cdd3 has been pushed to the Fedora 32 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.