Bug 1461989 - Cannot create virtual machines in KVM, systemd-machined.service entered failed state [NEEDINFO]
Cannot create virtual machines in KVM, systemd-machined.service entered faile...
Status: NEW
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: systemd (Show other bugs)
7.3
x86_64 Linux
high Severity urgent
: rc
: ---
Assigned To: systemd-maint
qe-baseos-daemons
:
Depends On:
Blocks: 1420851
  Show dependency treegraph
 
Reported: 2017-06-15 16:36 EDT by Robert McSwain
Modified: 2017-09-06 05:44 EDT (History)
12 users (show)

See Also:
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: ---
msekleta: needinfo? (zhechen)


Attachments (Terms of Use)

  None (edit)
Description Robert McSwain 2017-06-15 16:36:49 EDT
Description of problem:
ERROR    Activation of org.freedesktop.machine1 timed out
While doing some troubleshooting, I came across some information that indicated that the systemd-machine service needed to be restarted.  When I attempt to restart that service I get:
journalctl -xe
-- 
-- Unit NetworkManager-dispatcher.service has finished starting up.
-- 
-- The start-up result is done.
Jun 13 12:46:52 rh7dev01.domain.com nm-dispatcher[30563]: req:1 'down' [vnet0]: new request (4 scripts)
Jun 13 12:46:52 rh7dev01.domain.com nm-dispatcher[30563]: req:1 'down' [vnet0]: start running ordered scripts...
Jun 13 12:47:15 rh7dev01.domain.com sshd[30606]: Connection closed by 10.28.59.175 [preauth]
Jun 13 12:50:01 rh7dev01.domain.com systemd[1]: Started Session 9741 of user root.
-- Subject: Unit session-9741.scope has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit session-9741.scope has finished starting up.
-- 
-- The start-up result is done.
Jun 13 12:50:01 rh7dev01.domain.com CROND[30777]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 13 12:50:01 rh7dev01.domain.com systemd[1]: Starting Session 9741 of user root.
-- Subject: Unit session-9741.scope has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit session-9741.scope has begun starting up.
Jun 13 12:50:15 rh7dev01.domain.com sshd[30802]: Connection closed by 10.28.59.175 [preauth]
Jun 13 12:52:40 rh7dev01.domain.com polkitd[30459]: Registered Authentication Agent for unix-process:31109:312248526 (system bus name :1.27516 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en
Jun 13 12:52:40 rh7dev01.domain.com systemd[1]: Starting Virtual Machine and Container Registration Service...
-- Subject: Unit systemd-machined.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit systemd-machined.service has begun starting up.
Jun 13 12:52:40 rh7dev01.domain.com systemd[31126]: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-machined: Invalid argument
-- Subject: Process /usr/lib/systemd/systemd-machined could not be executed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The process /usr/lib/systemd/systemd-machined could not be executed and failed.
-- 
-- The error number returned by this process is 22.
Jun 13 12:52:40 rh7dev01.domain.com systemd[1]: systemd-machined.service: main process exited, code=exited, status=226/NAMESPACE
Jun 13 12:52:40 rh7dev01.domain.com systemd[1]: Failed to start Virtual Machine and Container Registration Service.
-- Subject: Unit systemd-machined.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit systemd-machined.service has failed.
-- 
-- The result is failed.
Jun 13 12:52:40 rh7dev01.domain.com systemd[1]: Unit systemd-machined.service entered failed state.
Jun 13 12:52:40 rh7dev01.domain.com systemd[1]: systemd-machined.service failed.
Jun 13 12:52:40 rh7dev01.domain.com polkitd[30459]: Unregistered Authentication Agent for unix-process:31109:312248526 (system bus name :1.27516, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Jun 13 12:52:48 rh7dev01.domain.com polkitd[30459]: Registered Authentication Agent for unix-process:31141:312249301 (system bus name :1.27517 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en
Jun 13 12:52:48 rh7dev01.domain.com systemd[1]: Starting Virtual Machine and Container Registration Service...
-- Subject: Unit systemd-machined.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit systemd-machined.service has begun starting up.
Jun 13 12:52:48 rh7dev01.domain.com systemd[31158]: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-machined: Invalid argument
-- Subject: Process /usr/lib/systemd/systemd-machined could not be executed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The process /usr/lib/systemd/systemd-machined could not be executed and failed.
-- 
-- The error number returned by this process is 22.
Jun 13 12:52:48 rh7dev01.domain.com systemd[1]: systemd-machined.service: main process exited, code=exited, status=226/NAMESPACE
Jun 13 12:52:48 rh7dev01.domain.com systemd[1]: Failed to start Virtual Machine and Container Registration Service.
-- Subject: Unit systemd-machined.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit systemd-machined.service has failed.
-- 
-- The result is failed.
Jun 13 12:52:48 rh7dev01.domain.com systemd[1]: Unit systemd-machined.service entered failed state.
Jun 13 12:52:48 rh7dev01.domain.com systemd[1]: systemd-machined.service failed.
Jun 13 12:52:48 rh7dev01.domain.com polkitd[30459]: Unregistered Authentication Agent for unix-process:31141:312249301 (system bus name :1.27517, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF-8) (disconnected from bus)
Jun 13 12:53:15 rh7dev01.domain.com sshd[31188]: Connection closed by 10.28.59.175 [preauth]


Version-Release number of selected component (if applicable):
RHEL 7.3
kernel-3.10.0-514.10.2.el7.x86_64
systemd-219-30.el7_3.9.x86_64

How reproducible:
Unknown, as no changes have been made recently

How resolvable:
Bugzilla 1381666 had a similar issue, so investigating the local systemd-machined.service file shows:

# cat /lib/systemd/system/systemd-machined.service
...
[Service]
ExecStart=/usr/lib/systemd/systemd-machined
BusName=org.freedesktop.machine1
CapabilityBoundingSet=CAP_KILL CAP_SYS_PTRACE CAP_SYS_ADMIN CAP_SETGID CAP_SYS_CHROOT CAP_DAC_READ_SEARCH
WatchdogSec=3min
PrivateTmp=yes
PrivateDevices=yes
PrivateNetwork=yes
ProtectSystem=full
ProtectHome=yes

Commenting out PrivateDevices=yes allows the service to start and VMs can be made


Actual results:
KVM not allowing for VMs to be made, systemd-machined fails to start.

Expected results:
KVM allows for VMs to be made, systemd-machined starts without issue.
Comment 2 Michal Sekletar 2017-06-18 12:56:53 EDT
Does customer know what change they applied to the system before they encountered the error?

At the first glance this looks like selinux-policy bug. Does selinux-policy downgrade alleviate  the issue?
Comment 3 Robert McSwain 2017-06-23 15:53:40 EDT
Michal, could you confirm exactly which selinux-policy version he'd want to be running. Per the customer, he's only odne regular system updates and hasn't made other changes beyond that.
Comment 4 Lukas Vrabec 2017-06-30 04:13:12 EDT
Hi Robert, 

Personally, I think this is more selinux-policy issue then bug systemd. Are you able to reproduce it? If yes please do following: 

Switch to permissive mode
# setenforce 0  

Reproduce the scenario. 

And then attach output of:
# ausearch -m AVC,USER_AVC,SELINUX_ERR -ts today


We think there is some SELinux denial when systemd-machined is trying to communicate via DBUS. 


Thanks,
Lukas.
Comment 5 Michal Sekletar 2017-07-03 03:45:37 EDT
Since the issue seems to be selinux-policy problem I am reassigning the bug to respective component.
Comment 8 Robert McSwain 2017-07-05 20:37:49 EDT
I've not been able to reproduce this but the customer was able to provide the following output regarding their selinux output: 

# ausearch -m AVC,USER_AVC,SELINUX_ERR -ts today
----
time->Wed Jul  5 12:44:27 2017
type=USER_AVC msg=audit(1499283867.150:339776): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='avc:  received setenforce notice (enforcing=0)  exe="/usr/lib/systemd/systemd" sauid=0 hostname=? addr=? terminal=?'
Comment 9 chen zhen 2017-08-03 05:21:08 EDT
the issue has appeared in my environment and my selinux config is Disabled.

version:
kernel-3.10.0-514.16.1.el7.x86_64
systemd-219-30.el7_3.9.x86_64

[root@cloud~]# getenforce 
Disabled


[root@cloud~]#  cat /lib/systemd/system/systemd-machined.service
 

[Unit]
Description=Virtual Machine and Container Registration Service
Documentation=man:systemd-machined.service(8)
Documentation=http://www.freedesktop.org/wiki/Software/systemd/machined
Wants=machine.slice
After=machine.slice

[Service]
ExecStart=/usr/lib/systemd/systemd-machined
BusName=org.freedesktop.machine1
CapabilityBoundingSet=CAP_KILL CAP_SYS_PTRACE CAP_SYS_ADMIN CAP_SETGID CAP_SYS_CHROOT CAP_DAC_READ_SEARCH
WatchdogSec=3min
PrivateTmp=yes
PrivateDevices=yes
PrivateNetwork=yes
ProtectSystem=full
ProtectHome=yes
Comment 10 Lukas Vrabec 2017-09-05 08:07:27 EDT
Michal, 

Please see comment#9, SELinux is disabled and issue appeared. Could you look on it?
Comment 11 Michal Sekletar 2017-09-06 05:44:23 EDT
Can you provide journal from the machine where you encountered the issue with disabled SELinux? Is there anything interesting in audit.log?

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