Bug 964006 - cloud-init hostname service failing on initial boot
Summary: cloud-init hostname service failing on initial boot
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: selinux-policy
Version: 19
Hardware: Unspecified
OS: Unspecified
urgent
urgent
Target Milestone: ---
Assignee: Miroslav Grepl
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: AcceptedBlocker AcceptedFreezeException
Keywords:
Depends On:
Blocks: F19Blocker, F19FinalBlocker F19-accepted, F19FinalFreezeException
TreeView+ depends on / blocked
 
Reported: 2013-05-17 03:01 UTC by Matthew Miller
Modified: 2016-04-29 03:35 UTC (History)
18 users (show)

(edit)
Clone Of:
(edit)
Last Closed: 2013-06-23 06:26:53 UTC


Attachments (Terms of Use)
cloud-init log from f19 tc boot (66.01 KB, text/plain)
2013-05-21 17:00 UTC, Matthew Miller
no flags Details
Initial cloud-init policy (1.11 KB, text/plain)
2013-05-29 07:48 UTC, Miroslav Grepl
no flags Details
Updated rules (1.75 KB, text/plain)
2013-05-30 13:16 UTC, Miroslav Grepl
no flags Details
file context spec (162 bytes, text/plain)
2013-05-30 13:16 UTC, Miroslav Grepl
no flags Details
audit.log, after reboot with proposed selinux module (41.49 KB, text/plain)
2013-05-31 13:34 UTC, Matthew Miller
no flags Details
mycloude.te (1.82 KB, text/plain)
2013-06-03 18:31 UTC, Miroslav Grepl
no flags Details
mycloud.fc (362 bytes, text/plain)
2013-06-03 18:32 UTC, Miroslav Grepl
no flags Details
output of ausearch -m avc,user_avc (24.12 KB, text/plain)
2013-06-07 17:37 UTC, Matthew Miller
no flags Details

Description Matthew Miller 2013-05-17 03:01:36 UTC
cloud-init apparently has some service to set the hostname, and apparently this runs on every boot. It's failing (see below) which delays login. I'm not actually providing any hostname metadata or anything about hostname in my userscript; shouldn't it just silently move on?

May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Failed to set the hostname to localhost.localdomain (localhost.localdomain)
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[WARNING]: Running set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.pyc'>) failed
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Running set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.pyc'>) failed
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x21945d0>)
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Read 83 bytes from /etc/hosts
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Read 83 bytes from /etc/hosts
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] cc_update_hostname.py[DEBUG]: Updating hostname to localhost.localdomain (localhost.localdomain)
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Running command ['hostname'] with allowed return codes [0] (shell=False, capture=True)
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] __init__.py[DEBUG]: Attempting to update hostname to localhost.localdomain in 1 files
May 17 02:40:28 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'localhost.localdomain'] with allowed return codes [0] (shell=False, capture=True)
May 17 02:40:53 localhost cloud-init[433]: [CLOUDINIT] util.py[WARNING]: Failed to write hostname localhost.localdomain to /var/lib/cloud/data/previous-hostname
May 17 02:40:53 localhost cloud-init[433]: [CLOUDINIT] util.py[DEBUG]: Failed to write hostname localhost.localdomain to /var/lib/cloud/data/previous-hostname
May 17 02:40:53 localhost cloud-init[433]: [CLOUDINIT] helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x2194590>)
May 17 02:40:53 localhost cloud-init[433]: [CLOUDINIT] cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts

Comment 1 Matthew Miller 2013-05-17 18:21:52 UTC
I should add that I am using a fake EC2 metadata service and I haven't actually implemented the hostname bit. I'll fix that... I assume that's the problem, but cloud-init should be robust against that.

(Notably, this wasn't a problem with F18.)

Comment 2 Matthew Miller 2013-05-21 16:58:48 UTC
This is failing in EC2 as well. I'll attach a log file.

Comment 3 Matthew Miller 2013-05-21 17:00:10 UTC
Created attachment 751325 [details]
cloud-init log from f19 tc boot

This is the log from boot. Consequence is a minute delay at boot; possibly worse.

Comment 4 Matthew Miller 2013-05-21 17:19:02 UTC
Excerpt from log file:


May 21 16:53:02 localhost [CLOUDINIT] helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/i-a8ba4cc4/sem/config_set_hostname'>)
May 21 16:53:02 localhost [CLOUDINIT] cc_set_hostname.py[DEBUG]: Setting the hostname to ip-10-147-161-247.ec2.internal (ip-10-147-161-247)
May 21 16:53:02 localhost [CLOUDINIT] util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'ip-10-147-161-247.ec2.internal'] with allowed return codes [0] (shell=False, capture=True)
May 21 16:53:27 localhost [CLOUDINIT] util.py[WARNING]: Failed to set the hostname to ip-10-147-161-247.ec2.internal (ip-10-147-161-247)
May 21 16:53:27 localhost [CLOUDINIT] util.py[DEBUG]: Failed to set the hostname to ip-10-147-161-247.ec2.internal (ip-10-147-161-247)


Note the 25-second pause. Running `hostnamectl set-hostname up-10-147-161-247.ec2.internal` as root from the booted system works fine.

Next in the log:

May 21 16:53:27 localhost [CLOUDINIT] util.py[DEBUG]: Running command ['hostname'] with allowed return codes [0] (shell=False, capture=True)
May 21 16:53:27 localhost [CLOUDINIT] __init__.py[DEBUG]: Attempting to update hostname to ip-10-147-161-247.ec2.internal in 1 files
May 21 16:53:27 localhost [CLOUDINIT] util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'ip-10-147-161-247.ec2.internal'] with allowed return codes [0] (shell=False, capture=True)
May 21 16:53:52 localhost [CLOUDINIT] util.py[WARNING]: Failed to write hostname ip-10-147-161-247.ec2.internal to /var/lib/cloud/data/previous-hostname
May 21 16:53:52 localhost [CLOUDINIT] util.py[DEBUG]: Failed to write hostname ip-10-147-161-247.ec2.internal to /var/lib/cloud/data/previous-hostname

Comment 5 Matthew Miller 2013-05-21 18:17:35 UTC
Maybe we just need to add "hostnamed.service" to the Wants line in cloud-init.service? It looks from the logs that that service is coming up _after_.

(Will try this locally...)

Comment 6 Matthew Miller 2013-05-21 18:22:33 UTC
Errr. systemd-hostnamed.service, of course.

Comment 7 Matthew Miller 2013-05-21 18:44:07 UTC
Nope. That doesn't seem to help.

Comment 8 Juerg Haefliger 2013-05-24 07:27:02 UTC
Per the documentation, systemd-hostnamed.service should come up by itself when it's needed. You can test that by stopping it and then running 'hostnamectl set-hostname foo' which will automatically start the service again.

Looking at the timing of events at boot, this seems to happen, i.e., cloud-init calls hostnamectl which brings up the service but it fails for some reason. I instrumented cloud-init and found the following:

May 24 07:09:30 juergh-193-3-019213-001 [CLOUDINIT] __init__.py[DEBUG]: Attempting to update hostname to juergh-193-3-019213-001.localdomain in 1 files
May 24 07:09:30 juergh-193-3-019213-001 [CLOUDINIT] util.py[DEBUG]: Running command ['hostnamectl', 'set-hostname', 'juergh-193-3-019213-001.localdomain'] with allowed return codes [0] (shell=False, capture=True)
May 24 07:09:55 juergh-193-3-019213-001 [CLOUDINIT] util.py[DEBUG]: stdout =
May 24 07:09:55 juergh-193-3-019213-001 [CLOUDINIT] util.py[DEBUG]: stderr = Failed to issue method call: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or 
the network connection was broken.
May 24 07:09:55 juergh-193-3-019213-001 [CLOUDINIT] util.py[DEBUG]: rc = 1
May 24 07:09:55 juergh-193-3-019213-001 [CLOUDINIT] util.py[WARNING]: Failed to write hostname juergh-193-3-019213-001.localdomain to /var/lib/cloud/data/previous-hostname
May 24 07:09:55 juergh-193-3-019213-001 [CLOUDINIT] util.py[DEBUG]: Failed to write hostname juergh-193-3-019213-001.localdomain to /var/lib/cloud/data/previous-hostname

Comment 9 Juerg Haefliger 2013-05-24 07:46:38 UTC
I also hacked cloud-init to explicitly start the hostname service and then wait 10 seconds prior to setting the hostname. Still fails.

Comment 10 Juerg Haefliger 2013-05-24 07:46:59 UTC
Disabling selinux fixes the issue. Could this be related to:  https://bugzilla.redhat.com/show_bug.cgi?id=914992

Comment 11 Matthew Miller 2013-05-24 13:19:51 UTC
Ahaha!

I had ruled that out because I booted with selinux=0 and it didn't work
either.

But apparently, cloud-init completely fails in that situation too.

So, I changed to writing "SELINUX=permissive" to /etc/sysconfig/selinux, and
that didn't work either, but on further inspection, on boot SELinux is still
in enforcing mode, ignoring that config file. (Changed it to
"SELINUX=disabled" doesn't work either.)

Sooo, I booted with enforcing=0 on the kernel command line, and now it
works.

I think maybe I need a vacation. :)

(I think probably `Requires systemd-hostnamed.service` in the systemd config is
a good idea too.)

Comment 12 Miroslav Grepl 2013-05-27 15:18:52 UTC
Any AVC msgs?

Comment 13 Matthew Miller 2013-05-27 23:45:33 UTC
Must be this:

/var/log/audit/audit.log:type=USER_AVC msg=audit(1369645724.117:16):
pid=199 uid=81 auid=4294967295 ses=4294967295
subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied
{ send_msg } for msgtype=method_return dest=:1.2 spid=520 tpid=519
scontext=system_u:system_r:systemd_hostnamed_t:s0
tcontext=system_u:system_r:initrc_t:s0 tclass=dbus
exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'
/var/log/audit/audit.log:type=USER_AVC msg=audit(1369645749.524:17):
pid=199 uid=81 auid=4294967295 ses=4294967295
subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 msg='avc:  denied
{ send_msg } for msgtype=method_return dest=:1.4 spid=520 tpid=522
scontext=system_u:system_r:systemd_hostnamed_t:s0
tcontext=system_u:system_r:initrc_t:s0 tclass=dbus
exe="/usr/bin/dbus-daemon" sauid=81 hostname=? addr=? terminal=?'

Comment 14 Miroslav Grepl 2013-05-28 08:14:29 UTC
Yes.

# ps -eZ |grep initrc

Comment 15 Matthew Miller 2013-05-28 19:36:31 UTC
At what point do you need that?

Once the system is actually up, there's no output. But while it's trying,

# ps -eZ |grep initrc
system_u:system_r:initrc_t:s0     434 ?        00:00:00 cloud-init
system_u:system_r:initrc_t:s0     510 ?        00:00:00 hostnamectl

Comment 16 Miroslav Grepl 2013-05-29 07:11:56 UTC
Ok, we need to add a policy for cloud-init and allow systemd_hostnamed_t to dbus chat with this new policy.

Comment 17 Miroslav Grepl 2013-05-29 07:48:37 UTC
Created attachment 754223 [details]
Initial cloud-init policy

Please download mycloud.te and run

# make -f /usr/share/selinux/devel/Makefile mycloud.pp
# semodule -i mycloud.pp
# chcon -t cloud_init_exec_t /usr/bin/cloud-init
# chcon -R -t cloud_var_lib_t /var/lib/cloud
# chcon -t cloud_log_t /var/log/cloud*

re-test it and

# ausearch -m avc -ts recent

Comment 18 Matthew Miller 2013-05-29 13:26:11 UTC
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.192:11): avc:  denied  { read } for  pid=189 comm="cloud-init" name="instance" dev="vda1" ino=2590 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=lnk_file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.192:12): avc:  denied  { getattr } for  pid=189 comm="cloud-init" path="/var/lib/cloud/instances/i-AAAAAAAA/cloud-config.txt" dev="vda1" ino=2603 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.192:13): avc:  denied  { read } for  pid=189 comm="cloud-init" name="cloud-config.txt" dev="vda1" ino=2603 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.192:14): avc:  denied  { open } for  pid=189 comm="cloud-init" path="/var/lib/cloud/instances/i-AAAAAAAA/cloud-config.txt" dev="vda1" ino=2603 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.315:15): avc:  denied  { setattr } for  pid=189 comm="cloud-init" name="cloud" dev="vda1" ino=18992 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.316:16): avc:  denied  { search } for  pid=189 comm="cloud-init" name="files" dev="vda1" ino=19240 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=dir
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.316:17): avc:  denied  { read } for  pid=189 comm="cloud-init" name="file_contexts.subs_dist" dev="vda1" ino=19245 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.316:18): avc:  denied  { open } for  pid=189 comm="cloud-init" path="/etc/selinux/targeted/contexts/files/file_contexts.subs_dist" dev="vda1" ino=19245 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.316:19): avc:  denied  { getattr } for  pid=189 comm="cloud-init" path="/etc/selinux/targeted/contexts/files/file_contexts.subs_dist" dev="vda1" ino=19245 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.321:20): avc:  denied  { write } for  pid=189 comm="cloud-init" name="context" dev="selinuxfs" ino=5 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.321:21): avc:  denied  { check_context } for  pid=189 comm="cloud-init" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.328:22): avc:  denied  { open } for  pid=189 comm="cloud-init" path="/var/log/cloud-init.log" dev="vda1" ino=2577 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_log_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.328:23): avc:  denied  { setattr } for  pid=189 comm="cloud-init" name="cloud-init.log" dev="vda1" ino=2577 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_log_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.330:24): avc:  denied  { unlink } for  pid=189 comm="cloud-init" name="boot-finished" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.330:25): avc:  denied  { write } for  pid=189 comm="cloud-init" name="cloud" dev="vda1" ino=18992 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.330:26): avc:  denied  { remove_name } for  pid=189 comm="cloud-init" name="instance" dev="vda1" ino=2590 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed May 29 13:12:09 2013
type=AVC msg=audit(1369833129.330:27): avc:  denied  { unlink } for  pid=189 comm="cloud-init" name="instance" dev="vda1" ino=2590 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=lnk_file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.215:33): arch=c000003e syscall=2 success=yes exit=4 a0=f01e00 a1=0 a2=1b6 a3=732e736e61656c6f items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.215:33): avc:  denied  { open } for  pid=434 comm="cloud-init" path="/etc/selinux/targeted/contexts/files/file_contexts.subs_dist" dev="vda1" ino=19245 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=file
type=AVC msg=audit(1369833132.215:33): avc:  denied  { read } for  pid=434 comm="cloud-init" name="file_contexts.subs_dist" dev="vda1" ino=19245 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=file
type=AVC msg=audit(1369833132.215:33): avc:  denied  { search } for  pid=434 comm="cloud-init" name="files" dev="vda1" ino=19240 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=dir
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.215:34): arch=c000003e syscall=5 success=yes exit=0 a0=4 a1=7fffabac3880 a2=7fffabac3880 a3=0 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.215:34): avc:  denied  { getattr } for  pid=434 comm="cloud-init" path="/etc/selinux/targeted/contexts/files/file_contexts.subs_dist" dev="vda1" ino=19245 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:file_context_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.217:35): arch=c000003e syscall=1 success=yes exit=31 a0=4 a1=13b3280 a2=1f a3=fe items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.217:35): avc:  denied  { check_context } for  pid=434 comm="cloud-init" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=security
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.223:36): arch=c000003e syscall=2 success=yes exit=4 a0=11a8a60 a1=441 a2=1b6 a3=3 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.223:36): avc:  denied  { open } for  pid=434 comm="cloud-init" path="/var/log/cloud-init.log" dev="vda1" ino=2577 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_log_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.224:37): arch=c000003e syscall=90 success=yes exit=0 a0=1140d80 a1=1a4 a2=7ff5ab729fa8 a3=0 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.224:37): avc:  denied  { setattr } for  pid=434 comm="cloud-init" name="cloud-init.log" dev="vda1" ino=2577 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_log_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.853:38): arch=c000003e syscall=88 success=yes exit=0 a0=14fa680 a1=e41400 a2=7ff5ab729fa8 a3=41414141414141 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.853:38): avc:  denied  { create } for  pid=434 comm="cloud-init" name="instance" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=lnk_file
type=AVC msg=audit(1369833132.853:38): avc:  denied  { add_name } for  pid=434 comm="cloud-init" name="instance" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.853:39): arch=c000003e syscall=2 success=yes exit=4 a0=7fffabac3eb0 a1=2 a2=7fffabac3ec7 a3=f items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.853:39): avc:  denied  { write } for  pid=434 comm="cloud-init" name="context" dev="selinuxfs" ino=5 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:security_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.861:40): arch=c000003e syscall=2 success=yes exit=4 a0=107cc70 a1=0 a2=1b6 a3=1 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.861:40): avc:  denied  { open } for  pid=434 comm="cloud-init" path="/var/lib/cloud/instances/i-AAAAAAAA/datasource" dev="vda1" ino=2595 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
type=AVC msg=audit(1369833132.861:40): avc:  denied  { read } for  pid=434 comm="cloud-init" name="datasource" dev="vda1" ino=2595 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.861:41): arch=c000003e syscall=5 success=yes exit=0 a0=4 a1=7fffabac67e0 a2=7fffabac67e0 a3=1 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.861:41): avc:  denied  { getattr } for  pid=434 comm="cloud-init" path="/var/lib/cloud/instances/i-AAAAAAAA/datasource" dev="vda1" ino=2595 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.862:42): arch=c000003e syscall=2 success=yes exit=4 a0=13f5d10 a1=241 a2=1b6 a3=3 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.862:42): avc:  denied  { write } for  pid=434 comm="cloud-init" name="datasource" dev="vda1" ino=2595 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.863:43): arch=c000003e syscall=90 success=yes exit=0 a0=14023c0 a1=1a4 a2=7ff5ab729fa8 a3=2f41414141414141 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.863:43): avc:  denied  { setattr } for  pid=434 comm="cloud-init" name="datasource" dev="vda1" ino=2595 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.890:44): arch=c000003e syscall=4 success=yes exit=0 a0=14a4250 a1=7fffabac5a20 a2=7fffabac5a20 a3=6769666e6f632d64 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.890:44): avc:  denied  { read } for  pid=434 comm="cloud-init" name="instance" dev="vda1" ino=2590 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=lnk_file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.894:45): arch=c000003e syscall=2 success=yes exit=4 a0=1130890 a1=241 a2=1b6 a3=3 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.894:45): avc:  denied  { dac_override } for  pid=434 comm="cloud-init" capability=1  scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:system_r:cloud_init_t:s0 tclass=capability
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.894:46): arch=c000003e syscall=6 success=yes exit=0 a0=14faa30 a1=7fffabac5ee0 a2=7fffabac5ee0 a3=0 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.894:46): avc:  denied  { getattr } for  pid=434 comm="cloud-init" path="/var/lib/cloud/instance" dev="vda1" ino=2590 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=lnk_file
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.906:47): arch=c000003e syscall=257 success=yes exit=4 a0=ffffffffffffff9c a1=13f54f0 a2=90800 a3=0 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.906:47): avc:  denied  { read } for  pid=434 comm="cloud-init" name="handlers" dev="vda1" ino=2580 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.996:48): arch=c000003e syscall=269 success=yes exit=0 a0=ffffffffffffff9c a1=4be22a a2=2 a3=7fff88b09440 items=0 ppid=481 pid=482 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="growpart" exe="/usr/bin/bash" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.996:48): avc:  denied  { write } for  pid=482 comm="growpart" name="tmp" dev="vda1" ino=15654 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=dir
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.997:49): arch=c000003e syscall=137 success=yes exit=0 a0=4be22a a1=7fff88b09690 a2=fffffffffff47404 a3=7fff88b09500 items=0 ppid=481 pid=482 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="growpart" exe="/usr/bin/bash" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.997:49): avc:  denied  { getattr } for  pid=482 comm="growpart" name="/" dev="vda1" ino=2 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:fs_t:s0 tclass=filesystem
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.997:50): arch=c000003e syscall=2 success=yes exit=3 a0=103dfc0 a1=2c1 a2=180 a3=0 items=0 ppid=481 pid=482 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="growpart" exe="/usr/bin/bash" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.997:50): avc:  denied  { write open } for  pid=482 comm="growpart" path="/tmp/sh-thd-1369822935" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=file
type=AVC msg=audit(1369833132.997:50): avc:  denied  { create } for  pid=482 comm="growpart" name="sh-thd-1369822935" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=file
type=AVC msg=audit(1369833132.997:50): avc:  denied  { add_name } for  pid=482 comm="growpart" name="sh-thd-1369822935" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=dir
----
time->Wed May 29 13:12:12 2013
type=SYSCALL msg=audit(1369833132.998:51): arch=c000003e syscall=87 success=yes exit=0 a0=103dfc0 a1=0 a2=180 a3=7fff88b09570 items=0 ppid=481 pid=482 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="growpart" exe="/usr/bin/bash" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833132.998:51): avc:  denied  { unlink } for  pid=482 comm="growpart" name="sh-thd-1369822935" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=file
type=AVC msg=audit(1369833132.998:51): avc:  denied  { remove_name } for  pid=482 comm="growpart" name="sh-thd-1369822935" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=dir
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.001:52): arch=c000003e syscall=4 success=yes exit=0 a0=f2d610 a1=7fffabac61c0 a2=7fffabac61c0 a3=0 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.001:52): avc:  denied  { getattr } for  pid=434 comm="cloud-init" path="/dev/vda1" dev="devtmpfs" ino=1433 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:fixed_disk_device_t:s0 tclass=blk_file
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.004:53): arch=c000003e syscall=2 success=yes exit=3 a0=14012f0 a1=0 a2=1ff a3=0 items=0 ppid=1 pid=434 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.004:53): avc:  denied  { open } for  pid=434 comm="cloud-init" path="/dev/vda1" dev="devtmpfs" ino=1433 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:fixed_disk_device_t:s0 tclass=blk_file
type=AVC msg=audit(1369833133.004:53): avc:  denied  { read } for  pid=434 comm="cloud-init" name="vda1" dev="devtmpfs" ino=1433 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:fixed_disk_device_t:s0 tclass=blk_file
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.038:54): arch=c000003e syscall=83 success=yes exit=0 a0=1ef5050 a1=1c0 a2=b a3=7fffb4d57850 items=0 ppid=488 pid=489 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="mktemp" exe="/usr/bin/mktemp" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.038:54): avc:  denied  { create } for  pid=489 comm="mktemp" name="growpart.lPyXNl" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=dir
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.073:55): arch=c000003e syscall=257 success=yes exit=3 a0=ffffffffffffff9c a1=7ed0c0 a2=30900 a3=0 items=0 ppid=483 pid=502 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="rm" exe="/usr/bin/rm" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.073:55): avc:  denied  { read } for  pid=502 comm="rm" name="growpart.lPyXNl" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=dir
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.073:56): arch=c000003e syscall=263 success=yes exit=0 a0=ffffffffffffff9c a1=7ed0c0 a2=200 a3=7fffe0822320 items=0 ppid=483 pid=502 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="rm" exe="/usr/bin/rm" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.073:56): avc:  denied  { rmdir } for  pid=502 comm="rm" name="growpart.lPyXNl" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:tmp_t:s0 tclass=dir
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.101:57): arch=c000003e syscall=59 success=yes exit=0 a0=13d2710 a1=15a5be0 a2=7fffabac76c8 a3=0 items=0 ppid=434 pid=504 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="hostname" exe="/usr/bin/hostname" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.101:57): avc:  denied  { execute_no_trans } for  pid=504 comm="cloud-init" path="/usr/bin/hostname" dev="vda1" ino=7661 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:hostname_exec_t:s0 tclass=file
type=AVC msg=audit(1369833133.101:57): avc:  denied  { read open } for  pid=504 comm="cloud-init" path="/usr/bin/hostname" dev="vda1" ino=7661 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:hostname_exec_t:s0 tclass=file
type=AVC msg=audit(1369833133.101:57): avc:  denied  { execute } for  pid=504 comm="cloud-init" name="hostname" dev="vda1" ino=7661 scontext=system_u:system_r:cloud_init_t:s0 tcontext=unconfined_u:object_r:hostname_exec_t:s0 tclass=file
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.112:58): arch=c000003e syscall=42 success=yes exit=0 a0=3 a1=7fff0fd2c2f0 a2=21 a3=7fff0fd2c0a0 items=0 ppid=434 pid=505 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="hostnamectl" exe="/usr/bin/hostnamectl" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.112:58): avc:  denied  { connectto } for  pid=505 comm="hostnamectl" path="/run/dbus/system_bus_socket" scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 tclass=unix_stream_socket
type=AVC msg=audit(1369833133.112:58): avc:  denied  { write } for  pid=505 comm="hostnamectl" name="system_bus_socket" dev="tmpfs" ino=10789 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:system_dbusd_var_run_t:s0 tclass=sock_file
type=AVC msg=audit(1369833133.112:58): avc:  denied  { search } for  pid=505 comm="hostnamectl" name="dbus" dev="tmpfs" ino=10788 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:system_dbusd_var_run_t:s0 tclass=dir
----
time->Wed May 29 13:12:13 2013
type=SYSCALL msg=audit(1369833133.567:62): arch=c000003e syscall=189 success=yes exit=0 a0=1bb31b4 a1=7f0a96d3e3be a2=194e4e0 a3=1f items=0 ppid=1 pid=513 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="cloud-init" exe="/usr/bin/python2.7" subj=system_u:system_r:cloud_init_t:s0 key=(null)
type=AVC msg=audit(1369833133.567:62): avc:  denied  { relabelto } for  pid=513 comm="cloud-init" name="boot-finished" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
type=AVC msg=audit(1369833133.567:62): avc:  denied  { relabelfrom } for  pid=513 comm="cloud-init" name="boot-finished" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:cloud_var_lib_t:s0 tclass=file

Comment 19 Miroslav Grepl 2013-05-29 13:58:02 UTC
type=AVC msg=audit(1369833133.567:62): avc:  denied  { relabelto } for  pid=513 comm="cloud-init" name="boot-finished" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=file
type=AVC msg=audit(1369833133.567:62): avc:  denied  { relabelfrom } for  pid=513 comm="cloud-init" name="boot-finished" dev="vda1" ino=2641 scontext=system_u:system_r:cloud_init_t:s0 tcontext=system_u:object_r:cloud_var_lib_t:s0 tclass=file


Does cloud-init label /var/lib/cloud?

Comment 20 Matthew Miller 2013-05-29 14:55:54 UTC
(In reply to Miroslav Grepl from comment #19)
> Does cloud-init label /var/lib/cloud?

I don't think so? I'm afraid my selinux-fu is beginner-level only.

Comment 21 Matthew Miller 2013-05-29 18:28:25 UTC
$ ls -ldZ /var/lib/cloud
drwxr-xr-x. root root system_u:object_r:var_lib_t:s0   /var/lib/cloud

Comment 22 Garrett Holmstrom 2013-05-29 18:42:06 UTC
cloud-init frequently compares the labels of the files that it writes against the ones matchpathcon expects and runs restorecon on the ones that differ to keep it from breaking other daemons.  For instance, SSH host keys.

I notice that AVC mentions cloud_init_t and cloud_var_lib_t.  If selinux-policy recently gained a module for cloud-init then that module is probably going to need quite a few new file context rules.

Comment 23 Miroslav Grepl 2013-05-30 06:46:01 UTC
(In reply to Garrett Holmstrom from comment #22)
> cloud-init frequently compares the labels of the files that it writes
> against the ones matchpathcon expects and runs restorecon on the ones that
> differ to keep it from breaking other daemons.  For instance, SSH host keys.

Ok, then it makes sense.

> 
> I notice that AVC mentions cloud_init_t and cloud_var_lib_t.  If
> selinux-policy recently gained a module for cloud-init then that module is
> probably going to need quite a few new file context rules.

Comment 24 Matthew Miller 2013-05-30 12:19:34 UTC
Okay, so what else do we need here?

Comment 25 Miroslav Grepl 2013-05-30 12:45:24 UTC
I am going to update the test policy for additional testing. Then we are going to add to Fedora policy.

Comment 26 Miroslav Grepl 2013-05-30 13:08:58 UTC
(In reply to Miroslav Grepl from comment #23)
> (In reply to Garrett Holmstrom from comment #22)
> > cloud-init frequently compares the labels of the files that it writes
> > against the ones matchpathcon expects and runs restorecon on the ones that
> > differ to keep it from breaking other daemons.  For instance, SSH host keys.
> 
> Ok, then it makes sense.

Does it do a script?

Comment 27 Miroslav Grepl 2013-05-30 13:16:27 UTC
Created attachment 754843 [details]
Updated rules

Comment 28 Miroslav Grepl 2013-05-30 13:16:59 UTC
Created attachment 754844 [details]
file context spec

Comment 29 Miroslav Grepl 2013-05-30 13:18:08 UTC
Ok, again download these files and run steps from the comment #17.

Comment 30 Matthew Miller 2013-05-30 16:20:51 UTC
(In reply to Miroslav Grepl from comment #29)
> Ok, again download these files and run steps from the comment #17.

Sorry, but what do I do with the file context spec?

I'm sure that's a key point. :)

Comment 31 Miroslav Grepl 2013-05-31 12:44:21 UTC
Just download mycloud.te and mycloud.fc file

and run

# make -f /usr/share/selinux/devel/Makefile mycloud.pp
# semodule -i mycloud.pp
# restorecon -R -v /usr/bin/cloud-init /var/lib/cloud /var/log/cloud*

re-test it and

# ausearch -m avc -ts recent

Comment 32 Matthew Miller 2013-05-31 13:33:36 UTC
Got it. Bugzilla obscures attachment filenames unless you click on "details" so that didn't help. :)

Note that /var/log/cloud doesn't exist until cloud-init runs, so I got an initial "restorecon:  lstat(/var/log/cloud*) failed:  No such file or directory". I assume that's expected in that case, but if necessary we could pre-create that file.

With the above modules, on reboot I get 

#  ausearch -m avc -ts recent
<no matches>


But the problem is still there. I'm going to attach the whole audit.log.

Comment 33 Matthew Miller 2013-05-31 13:34:34 UTC
Created attachment 755273 [details]
audit.log, after reboot with proposed selinux module

Comment 34 Miroslav Grepl 2013-05-31 14:18:26 UTC
Ok.

allow systemd_hostnamed_t initrc_t:dbus send_msg;

system_u:system_r:initrc_t:s0     510 ?        00:00:00 hostnamectl


How is hostnamectl started in this case?

Comment 35 Matthew Miller 2013-05-31 14:25:41 UTC
(In reply to Miroslav Grepl from comment #34)
> How is hostnamectl started in this case?

Called with subprocess.Popen in python.

We could presumably refactor it to use the systemd-hostnamed api directly but it doesn't right now.

Comment 36 Miroslav Grepl 2013-05-31 14:27:02 UTC
What is a path to a script which runs it?

Comment 37 Matthew Miller 2013-05-31 14:35:27 UTC
(In reply to Miroslav Grepl from comment #36)
> What is a path to a script which runs it?

This is convoluted. It's called from

/usr/lib/python2.7/site-packages/cloudinit/util.py, from /usr/lib/python2.7/site-packages/cloudinit/distros/rhel.py, which is called from /usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.py.

That's a cloud-config module, so it's called from "/usr/bin/cloud-init modules --mode=config", as part of /usr/lib/systemd/system/cloud-config.service

Comment 38 Matthew Miller 2013-06-03 15:06:38 UTC
Anything else I should do or try?

Comment 39 Miroslav Grepl 2013-06-03 15:59:07 UTC
Ah, I missed the previous comment. Let me update the local test policy.

Comment 40 Miroslav Grepl 2013-06-03 18:31:36 UTC
Created attachment 756453 [details]
mycloude.te

Comment 41 Miroslav Grepl 2013-06-03 18:32:21 UTC
Created attachment 756454 [details]
mycloud.fc

Comment 42 Miroslav Grepl 2013-06-03 18:36:43 UTC
Download mycloud.fc and mycloud.te and run

# make -f /usr/share/selinux/devel/Makefile mycloud.pp
# semodule -i mycloud.pp
# restorecon -R -v /usr/bin/cloud-init /var/lib/cloud /var/log/cloud* 
/usr/lib/systemd/system/cloud*

and re-test again.

Comment 43 Matthew Miller 2013-06-06 15:04:27 UTC
Same failure with the new policy, and again no matches to `ausearch -m avc -ts recent`.

Do you want the whole audit log again?

Comment 44 Daniel Walsh 2013-06-06 17:34:19 UTC
semodule -DB

Will turn off dontaudit rules, see if you get any new avc's about your service.

Comment 45 Miroslav Grepl 2013-06-06 17:38:46 UTC
Also pls make sure you run

# ausearch -m avc,user_avc

Comment 46 Matthew Miller 2013-06-07 17:37:05 UTC
Created attachment 758252 [details]
output of ausearch -m avc,user_avc

Here is the log after applying the latest files from above and using "semodule -DB".

Comment 47 Matthew Miller 2013-06-07 17:47:44 UTC
Excerpt:

time->Fri Jun  7 17:32:32 2013
type=SYSCALL msg=audit(1370626352.438:23): arch=c000003e syscall=59 success=yes exit=0 a0=1a0ba00 a1=1a0f810 a2=19f3430 a3=7fffb2586460 items=0 ppid=337 pid=380 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="hostname" exe="/usr/bin/hostname" subj=system_u:system_r:hostname_t:s0 key=(null)
type=AVC msg=audit(1370626352.438:23): avc:  denied  { noatsecure } for  pid=380 comm="hostname" scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:system_r:hostname_t:s0 tclass=process
type=AVC msg=audit(1370626352.438:23): avc:  denied  { siginh } for  pid=380 comm="hostname" scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:system_r:hostname_t:s0 tclass=process
type=AVC msg=audit(1370626352.438:23): avc:  denied  { rlimitinh } for  pid=380 comm="hostname" scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:system_r:hostname_t:s0 tclass=process
type=AVC msg=audit(1370626352.438:23): avc:  denied  { read write } for  pid=380 comm="hostname" path="socket:[11599]" dev="sockfs" ino=11599 scontext=system_u:system_r:hostname_t:s0 tcontext=system_u:system_r:dhcpc_t:s0 tclass=udp_socket
type=AVC msg=audit(1370626352.438:23): avc:  denied  { read write } for  pid=380 comm="hostname" path="socket:[11598]" dev="sockfs" ino=11598 scontext=system_u:system_r:hostname_t:s0 tcontext=system_u:system_r:dhcpc_t:s0 tclass=udp_socket
----
time->Fri Jun  7 17:32:32 2013
type=SYSCALL msg=audit(1370626352.443:24): arch=c000003e syscall=59 success=yes exit=0 a0=1a0b860 a1=1a0f810 a2=19f3430 a3=7fffb2586ea0 items=0 ppid=337 pid=381 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 ses=4294967295 tty=(none) comm="hostname" exe="/usr/bin/hostname" subj=system_u:system_r:hostname_t:s0 key=(null)
type=AVC msg=audit(1370626352.443:24): avc:  denied  { noatsecure } for  pid=381 comm="hostname" scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:system_r:hostname_t:s0 tclass=process
type=AVC msg=audit(1370626352.443:24): avc:  denied  { siginh } for  pid=381 comm="hostname" scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:system_r:hostname_t:s0 tclass=process
type=AVC msg=audit(1370626352.443:24): avc:  denied  { rlimitinh } for  pid=381 comm="hostname" scontext=system_u:system_r:dhcpc_t:s0 tcontext=system_u:system_r:hostname_t:s0 tclass=process
type=AVC msg=audit(1370626352.443:24): avc:  denied  { read write } for  pid=381 comm="hostname" path="socket:[11599]" dev="sockfs" ino=11599 scontext=system_u:system_r:hostname_t:s0 tcontext=system_u:system_r:dhcpc_t:s0 tclass=udp_socket
type=AVC msg=audit(1370626352.443:24): avc:  denied  { read write } for  pid=381 comm="hostname" path="socket:[11598]" dev="sockfs" ino=11598 scontext=system_u:system_r:hostname_t:s0 tcontext=system_u:system_r:dhcpc_t:s0 tclass=udp_socket
----

Comment 48 Daniel Walsh 2013-06-08 10:35:04 UTC
allow systemd_hostnamed_t initrc_t:dbus send_msg;


Which indicates some service was running as initrc_t and was sent a dbus message.

Comment 49 Matthew Miller 2013-06-08 13:21:34 UTC
(In reply to Daniel Walsh from comment #48)
> allow systemd_hostnamed_t initrc_t:dbus send_msg;
> 
> 
> Which indicates some service was running as initrc_t and was sent a dbus
> message.

Yeah -- see comment #34.

Comment 50 Miroslav Grepl 2013-06-10 11:34:59 UTC
Matthew,
how can I reproduce it?

Comment 51 Adam Williamson 2013-06-10 18:55:34 UTC
Discussed at 2013-06-10 blocker review meeting: http://meetbot.fedoraproject.org/fedora-blocker-review/2013-06-10/f19final-blocker-review-4.2013-06-10-16.01.log.txt . We had to do quite a lot of interpretation of this bug in the meeting as no clear blocker rationale was given (bad Matthew!), but we read it as something like 'there's an AVC during startup and startup might be a bit slow, but it works'. On that basis it's rejected as a blocker - the system basically works, it doesn't violate criteria - but accepted as a freeze exception - it looks kind of bad and if it slows things down, is inconvenient.

If our interpretation was incorrect or you disagree with our reasoning, please re-propose as a blocker _with a clear explanation of why_.

Comment 52 Matthew Miller 2013-06-10 20:33:34 UTC
(In reply to Adam Williamson from comment #51)
> Discussed at 2013-06-10 blocker review meeting:
> http://meetbot.fedoraproject.org/fedora-blocker-review/2013-06-10/f19final-
> blocker-review-4.2013-06-10-16.01.log.txt . We had to do quite a lot of
> interpretation of this bug in the meeting as no clear blocker rationale was
> given (bad Matthew!), but we read it as something like 'there's an AVC
> during startup and startup might be a bit slow, but it works'. On that basis
> it's rejected as a blocker - the system basically works, it doesn't violate
> criteria - but accepted as a freeze exception - it looks kind of bad and if
> it slows things down, is inconvenient.
> 
> If our interpretation was incorrect or you disagree with our reasoning,
> please re-propose as a blocker _with a clear explanation of why_.

Sorry. Re-proposing. The AVC actually completely blocks some of the cloud-init functionality, and being slow is a side-effect. That side-effect is _also_ bad, because it's an entire 60 second delay before login is possible, which basically kills the cloud image as useful for autoscaling services (that's both in EC2 and in OpenStack).

Also, since it's an issue with the image, and since we don't yet have a good mechanism for updating the image as a whole, it's not like we can fix this with a zero-day update.

I don't know what release criteria this would go under; I hadn't actually anticipated a problem like this in advance or I would have suggested that something to cover it be added. (So, yeah, I'll take that "bad Matthew" for that too.)

Comment 53 Matthew Miller 2013-06-10 20:36:08 UTC
(In reply to Miroslav Grepl from comment #50)
> Matthew,
> how can I reproduce it?

Boot ami-6f3b5006 (us east, x86_64) in Amazon EC2. That's the F19 beta. Releng is uploading a test candidate for the final release too, but we're waiting on that.

Alternately, look at the images in http://dl.fedoraproject.org/pub/alt/stage/19-TC2/Images/ and boot in OpenStack.

Comment 54 Matthew Miller 2013-06-10 23:03:07 UTC
(In reply to Miroslav Grepl from comment #50)
> Matthew,
> how can I reproduce it?

TC images, available globally:

 │ ami-d7293aa3 : eu-west-1 image for x86_64
 │ ami-ff8a19c5 : ap-southeast-2 image for x86_64
 │ ami-95951e94 : ap-northeast-1 image for x86_64
 │ ami-62b91c7f : sa-east-1 image for x86_64
 │ ami-f7c555c7 : us-west-2 image for x86_64
 │ ami-377e095e : us-east-1 image for x86_64
 │ ami-ebb3fdb9 : ap-southeast-1 image for x86_64

Comment 55 Matthew Miller 2013-06-10 23:43:26 UTC
Hmmm -- those TC2 images in EC2 are failing to even get the key after a minute. I'll investigate tomorrow.

Comment 56 Adam Williamson 2013-06-11 00:37:42 UTC
Given the impact we can just argue that it's serious enough to constitute a breach of the Xen/EC2 criterion (which I was gonna cite, but the wiki seems to be falling over ATM). We'll consider it at the next blocker meeting.

Note, to propose a blocker you set Blocks: (not Depends on:), and to *re-propose* a bug that's been rejected, you have to unset the whiteboard field that indicates the rejection.

Comment 57 Miroslav Grepl 2013-06-11 08:43:20 UTC
Matthew,
could you add outputs of

# ls -Z /usr/lib/systemd/system/cloud-*

and

# ps -efZ |grep initrc


I am trying to reproduce it.

Comment 58 Matthew Miller 2013-06-11 19:40:37 UTC
(In reply to Miroslav Grepl from comment #57)

Not sure if you mean before or after applying the new policy. Here's before:

# ls -Z /usr/lib/systemd/system/cloud-*
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-config.service
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-config.target
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-final.service
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-init-local.service
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-init.service


# ps -efZ |grep initrc
system_u:system_r:initrc_t:s0   root       432     1  1 19:30 ?        00:00:00 /usr/bin/python /usr/bin/cloud-init init
system_u:system_r:initrc_t:s0   root       504   432  0 19:30 ?        00:00:00 hostnamectl set-hostname localhost

After the new policy:

# ls -Z /usr/lib/systemd/system/cloud-*
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-config.service
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-config.target
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-final.service
-rw-r--r--. root root unconfined_u:object_r:cloud_init_unit_file_t:s0 /usr/lib/systemd/system/cloud-init-local.service
-rw-r--r--. root root unconfined_u:object_r:systemd_unit_file_t:s0 /usr/lib/systemd/system/cloud-init.service


# ps -efZ |grep initrc
system_u:system_r:initrc_t:s0   root       430     1  2 19:36 ?        00:00:00 /usr/bin/python /usr/bin/cloud-init init
system_u:system_r:initrc_t:s0   root       501   430  0 19:36 ?        00:00:00 hostnamectl set-hostname localhost


Is the "mycloud.fc" file supposed to have cloud-init-.* or is that meant to be cloud-init.*?

Comment 59 Matthew Miller 2013-06-11 19:42:50 UTC
Also, in case it isn't clear here:

The cloud-init program takes metadata in a variety of formats and performs system-configuration actions based on that. This is up to and including a sort of "rc.local", where a shell script is executed as root and expected to be able to do just about everything to the system.

(If we want to try to constrain that further, which wouldn't necessarily be a terrible idea, that'd be a lot of work.)

Comment 60 Miroslav Grepl 2013-06-12 06:43:59 UTC
Yes, we will run it as unconfined domain. But we need to have own domain. We don't want to dbus chat with initrc_t.

Ok, there is a bug in .fc file. Try to change to

-/usr/lib/systemd/system/cloud-config-.* --  gen_context(system_u:object_r:cloud_init_unit_file_t,s0)
/usr/lib/systemd/system/cloud-init-.* --  -gen_context(system_u:object_r:cloud_init_unit_file_t,s0)

+/usr/lib/systemd/system/cloud-config.* --
gen_context(system_u:object_r:cloud_init_unit_file_t,s0)
+/usr/lib/systemd/system/cloud-init.* --
gen_context(system_u:object_r:cloud_init_unit_file_t,s0)
+/usr/lib/systemd/system/cloud-final.* --
gen_context(system_u:object_r:cloud_init_unit_file_t,s0)

and

# make -f /usr/share/selinux/devel/Makefile mycloud.pp
# semodule -i mycloud.pp
# restorecon -R -v /usr/lib/systemd/system/cloud*

Comment 61 Matthew Miller 2013-06-12 11:44:40 UTC
I'll try that again when I get a chance, although I should note that I tried 

/usr/lib/systemd/system/cloud-.* -- gen_context(system_u:object_r:cloud_init_unit_file_t,s0)

yesterday and it didn't help.

Comment 62 Miroslav Grepl 2013-06-12 12:16:23 UTC
Matthew,
is there a test machine where I could log in?

Comment 63 Matthew Miller 2013-06-17 13:47:46 UTC
(I sent Miroslav information for an EC2 login host via a private email.)

Any progress or further ideas?

Comment 64 Miroslav Grepl 2013-06-17 14:11:13 UTC
I added more fixes for the policy but I am not able to reproduce 

allow systemd_hostnamed_t initrc_t:dbus send_msg;

Comment 65 Matthew Miller 2013-06-17 14:50:25 UTC
Do you have an OpenStack environment you can test in? That would be ideal.

Comment 66 Miroslav Grepl 2013-06-17 14:58:04 UTC
I use the machine which you provide me.

Comment 67 Tim Flink 2013-06-17 17:41:28 UTC
Discussed at the 2013-06-12 blocker review meeting [1]:

Accepted as a blocker for F19 final due to violation of the following F19 final release criterion [2] (in the sense that many of the important use cases are effectively blocked): "The release must boot successfully as Xen DomU with releases providing a functional, supported Xen Dom0 and widely used cloud providers utilizing Xen. This does not include any issues limited to the release functioning as Xen Dom0"

[1] http://meetbot.fedoraproject.org/fedora-blocker-review/2013-06-12/f19final-blocker-review-5.2013-06-12-16.01.txt
[2] http://fedoraproject.org/wiki/Fedora_19_Final_Release_Criteria

Comment 68 Miroslav Grepl 2013-06-18 10:27:48 UTC
Fixes has been added to selinux-policy-3.12.1-53.fc19

Comment 70 Kashyap Chamarthy 2013-06-18 11:33:14 UTC
Whoops, inadvertently I turned it to ASSIGNED. Moved to MODIFIED.

Sorry for the noise.

Comment 71 Matthew Miller 2013-06-18 20:01:18 UTC
(In reply to Miroslav Grepl from comment #68)
> Fixes has been added to selinux-policy-3.12.1-53.fc19

I've confirmed that this works with manual testing. Hope to see it in the next TC or RC so we can test the image as a whole.

Comment 72 Fedora Update System 2013-06-19 19:30:52 UTC
selinux-policy-3.12.1-53.fc19 has been submitted as an update for Fedora 19.
https://admin.fedoraproject.org/updates/selinux-policy-3.12.1-53.fc19

Comment 73 Tim Flink 2013-06-20 17:23:51 UTC
The fix should be in the TC6 cloud images

Comment 74 Fedora Update System 2013-06-20 18:01:48 UTC
Package selinux-policy-3.12.1-54.fc19:
* should fix your issue,
* was pushed to the Fedora 19 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing selinux-policy-3.12.1-54.fc19'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-11355/selinux-policy-3.12.1-54.fc19
then log in and leave karma (feedback).

Comment 75 Adam Williamson 2013-06-21 05:38:45 UTC
Can cloud folks check this fix with TC6? Thanks!

Comment 76 Sandro Mathys 2013-06-21 09:12:37 UTC
Fix in TC6 confirmed.

Hostname is set, cloud-init is happy and there's no SELinux AVC denials at all.

Comment 77 Fedora Update System 2013-06-23 06:26:53 UTC
selinux-policy-3.12.1-54.fc19 has been pushed to the Fedora 19 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 78 gerald 2016-04-29 03:33:57 UTC
Hi 

This is still happening for me 

Selinux version 

[root@salt-test6 ~]# rpm -qa selinux*
selinux-policy-targeted-3.13.1-60.el7.noarch
selinux-policy-3.13.1-60.el7.noarch

Red Hat version 
[root@salt-test6 ~]# cat /etc/redhat-release 
Red Hat Enterprise Linux Server release 7.2 (Maipo)

Note that this is an image from Red Hat 
rhel-guest-image-7.2-20160302.0.x86_64 


[root@salt-test6 log]# tail -n2 cloud-init.log 
Apr 28 22:03:03 localhost cloud-init: 2016-04-28 22:03:03,718 - util.py[WARNING]: Failed to set the hostname to salt-test6.novalocal (salt-test6)
Apr 28 22:03:09 localhost cloud-init: 2016-04-28 22:03:09,961 - util.py[WARNING]: Running module set_hostname (<module 'cloudinit.config.cc_set_hostname' from '/usr/lib/python2.7/site-packages/cloudinit/config/cc_set_hostname.pyc'>) failed

Comment 79 gerald 2016-04-29 03:35:03 UTC
Also cloud config version 

[root@salt-test6 ~]# rpm -qa cloud*
cloud-init-0.7.6-6.el7.x86_64
cloud-utils-growpart-0.27-13.el7.noarch


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