Bug 499711

Summary: Policy install failure causing svirt error
Product: [Fedora] Fedora Reporter: Paul Moore <paul.moore>
Component: selinux-policy-targetedAssignee: Daniel Walsh <dwalsh>
Status: CLOSED RAWHIDE QA Contact: Ben Levenson <benl>
Severity: medium Docs Contact:
Priority: medium    
Version: rawhideCC: aron.griffis, berrange, clalance, crobinso, dwalsh, eparis, hbrock, itamar, markmc, quintela, sdsmall, veillard, virt-maint
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2009-05-11 12:18:18 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 480594    
Attachments:
Description Flags
/var/log/libvirt/qemu/f11p-vm1.log
none
$HOME/.virt-manager/virt-manager.log
none
See comment #31 none

Description Paul Moore 2009-05-07 18:52:25 UTC
Description of problem:
When trying to create a new F10 guest using virt-manager according to the instructions on the Fedora wiki I get the following error: "Unable to complete install: 'internal error Domain bobjr-vm1 didn't show up'".

Version-Release number of selected component (if applicable):
qemu-system-x86-0.10-16.fc11.x86_64
python-virtinst-0.400.3-8.fc11.noarch
libvirt-0.6.2-6.fc11.x86_64
virt-manager-0.7.0-4.fc11.x86_64
kernel-2.6.29.2-126.fc11.x86_64

How reproducible:
Everytime

Steps to Reproduce:
1. Create a F10 guest using virt-manager with a local F10 ISO image, KVM, NAT'd networking and no audio device
  
Actual results:
The python stack trace is below:
Traceback (most recent call last):
  File "/usr/share/virt-manager/virtManager/create.py", line 1495, in do_install
    dom = guest.start_install(False, meter = meter)
  File "/usr/lib/python2.6/site-packages/virtinst/Guest.py", line 541, in start_install
    return self._do_install(consolecb, meter, removeOld, wait)
  File "/usr/lib/python2.6/site-packages/virtinst/Guest.py", line 633, in _do_install
    self.domain = self.conn.createLinux(install_xml, 0)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 974, in createLinux
    if ret is None:raise libvirtError('virDomainCreateLinux() failed', conn=self)
libvirtError: internal error Domain bobjr-vm1 didn't show up'

Expected results:
Successful guest creation.

Additional info:
System is a HP ProLiant DL185G5 with AMD hardware virtualization support

Comment 1 Paul Moore 2009-05-07 19:06:48 UTC
I am seeing similar problems when using virt-install, see below:

# qemu-img create -f raw /var/lib/libvirt/images/bobjr-vm1.img 8G
Formatting '/var/lib/libvirt/images/bobjr-vm1.img', fmt=raw, size=8388608 kB
# virt-install -n bobjr-vm1 -r 512 --os-type=linux --os-variant=fedora10 --hvm --accelerate -c /mnt/Fedora-10-x86_64-DVD.iso -f /var/lib/libvirt/images/bobjr-vm1.img  --vnc

Starting install...
internal error Domain bobjr-vm1 didn't show up

Domain installation may not have been
 successful.  If it was, you can restart your domain
 by running 'virsh start bobjr-vm1'; otherwise, please
 restart your installation.
ERROR    internal error Domain bobjr-vm1 didn't show up
Traceback (most recent call last):
  File "/usr/sbin/virt-install", line 780, in <module>
    main()
  File "/usr/sbin/virt-install", line 678, in main
    start_time, guest.start_install)
  File "/usr/sbin/virt-install", line 733, in do_install
    dom = install_func(conscb, progresscb, wait=(not wait))
  File "/usr/lib/python2.6/site-packages/virtinst/Guest.py", line 541, in start_install
    return self._do_install(consolecb, meter, removeOld, wait)
  File "/usr/lib/python2.6/site-packages/virtinst/Guest.py", line 633, in _do_install
    self.domain = self.conn.createLinux(install_xml, 0)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 974, in createLinux
    if ret is None:raise libvirtError('virDomainCreateLinux() failed', conn=self)
libvirtError: internal error Domain bobjr-vm1 didn't show up

# virsh start bobjr-vm1
error: failed to get domain 'bobjr-vm1'
error: Domain not found

Comment 2 Aron Griffis 2009-05-07 19:16:06 UTC
I'm seeing the same thing, running on today's rawhide, updated from a fresh fedora10 installation.

Comment 3 Cole Robinson 2009-05-07 19:18:16 UTC
Can anyone post the contents of /var/log/libvirt/qemu/<vmname>.log?

Comment 4 Aron Griffis 2009-05-07 19:28:21 UTC
Created attachment 342925 [details]
/var/log/libvirt/qemu/f11p-vm1.log

Comment 5 Paul Moore 2009-05-07 21:11:27 UTC
A few additional notes from testing ... the problem appears to be related to SELinux as putting the system in permissive mode resolves the VM creation problem.  However, if I try putting the system in enforcing mode after VM creation I'm unable to start the guest instance (similar failures as those posted above).

# rpm -qa | grep selinux
selinux-policy-targeted-3.6.12-28.fc11.noarch
libselinux-python-2.0.80-1.fc11.x86_64
libselinux-2.0.80-1.fc11.x86_64
selinux-policy-3.6.12-28.fc11.noarch
libselinux-utils-2.0.80-1.fc11.x86_64

Comment 6 Mark McLoughlin 2009-05-07 21:20:47 UTC
Error is:

libvir: Security Labeling error : SELinuxSetSecurityLabel: unable to set security context 'system_u:system_r:svirt_t:s0:c152,c660': Invalid argument.
libvir: QEMU error : internal error Failed to set security label

Comment 7 Daniel Walsh 2009-05-08 12:04:55 UTC
Dan is this the problem with the device being Null?

Comment 8 Daniel Berrangé 2009-05-08 12:10:51 UTC
I don't think so - from the virt-install output in comment #1, I think this is hitting on the first boot attempt, when the CD path will still be non-NULL.

I notice the CD media is this path:

/mnt/Fedora-10-x86_64-DVD.iso


My money is on /mnt being a filesystem that doesn't support extended attributes.

Paul, you could paste the output '/proc/mounts', so we can see what it is

Comment 9 Aron Griffis 2009-05-08 12:53:07 UTC
(In reply to comment #8)
> My money is on /mnt being a filesystem that doesn't support extended
> attributes.

but if you look at the log I attached in comment 4, you can see that I hit this bug in two cases: one installing from the network with --location, two installing from an iso image stored in /root/Download with --cdrom

Comment 10 Paul Moore 2009-05-08 13:06:33 UTC
(In reply to comment #8)
> 
> ...
>
> My money is on /mnt being a filesystem that doesn't support extended
> attributes.
> 
> Paul, you could paste the output '/proc/mounts', so we can see what it is  

How much money?  ;)

The /mnt directory lives in the / filesystem and is ext3 so there should be no problem with xattrs.  I also did a full filesystem relabel to try and resolve the issue yesterday with no success.

# cat /proc/mounts
rootfs / rootfs rw 0 0
/dev/root / ext3 rw,relatime,errors=continue,user_xattr,acl,data=ordered 0 0
/dev /dev tmpfs rw,relatime,mode=755 0 0
/proc /proc proc rw,relatime 0 0
/sys /sys sysfs rw,relatime 0 0
none /selinux selinuxfs rw,relatime 0 0
/proc/bus/usb /proc/bus/usb usbfs rw,relatime 0 0
devpts /dev/pts devpts rw,relatime,gid=5,mode=620,ptmxmode=000 0 0
/dev/cciss/c0d0p1 /boot ext3 rw,relatime,errors=continue,user_xattr,acl,data=ordered 0 0
tmpfs /dev/shm tmpfs rw,rootcontext=system_u:object_r:device_t:s0,relatime 0 0
none /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0
# ls -Z /
drwxr-xr-x. root root system_u:object_r:bin_t:s0       bin
drwxr-xr-x. root root system_u:object_r:boot_t:s0      boot
drwxr-xr-x. root root system_u:object_r:device_t:s0    dev
drwxr-xr-x. root root system_u:object_r:etc_t:s0       etc
drwxr-xr-x. root root system_u:object_r:home_root_t:s0 home
drwxr-xr-x. root root system_u:object_r:lib_t:s0       lib
drwxr-xr-x. root root system_u:object_r:lib_t:s0       lib64
drwx------. root root system_u:object_r:lost_found_t:s0 lost+found
drwxr-xr-x. root root system_u:object_r:mnt_t:s0       media
drwxr-xr-x. root root system_u:object_r:mnt_t:s0       mnt
drwxr-xr-x. root root system_u:object_r:usr_t:s0       opt
dr-xr-xr-x. root root system_u:object_r:proc_t:s0      proc
drwxr-x---. root root system_u:object_r:admin_home_t:s0 root
drwxr-xr-x. root root system_u:object_r:bin_t:s0       sbin
drwxr-xr-x. root root system_u:object_r:security_t:s0  selinux
drwxr-xr-x. root root system_u:object_r:var_t:s0       srv
drwxr-xr-x. root root system_u:object_r:sysfs_t:s0     sys
drwxrwxrwt. root root system_u:object_r:tmp_t:s0       tmp
drwxr-xr-x. root root system_u:object_r:usr_t:s0       usr
drwxr-xr-x. root root system_u:object_r:var_t:s0       var
# ls -Z /mnt
-rw-r--r--. root root system_u:object_r:default_t:s0   Fedora-10-x86_64-DVD.iso
# restorecon -r /mnt
# ls -Z /mnt
-rw-r--r--. root root system_u:object_r:default_t:s0   Fedora-10-x86_64-DVD.iso
# ls -Zd /mnt
drwxr-xr-x. root root system_u:object_r:mnt_t:s0       /mnt

Comment 11 Daniel Berrangé 2009-05-08 13:14:55 UTC
Ok, lets try looking at /root/.virtinst/virt-install.log after it fails - can you attach this file (or $HOME/.virt-manager/virt-manager.log if using virt-manager)

Comment 12 Paul Moore 2009-05-08 13:54:21 UTC
Created attachment 343084 [details]
$HOME/.virt-manager/virt-manager.log

Log from failed guest creation using virt-manager

Comment 13 Daniel Berrangé 2009-05-08 14:05:05 UTC
Oh hang on, this error message is nothing todo with file labelling at all. It occurs when setting the exec() context.

    if (setexeccon(secdef->label) == -1) {
        virSecurityReportError(conn, VIR_ERR_ERROR,
                               _("%s: unable to set security context "
                               "'\%s\': %s."), __func__, secdef->label,
                               virStrerror(errno, ebuf, sizeof ebuf));
        if (security_getenforce() == 1)
                return -1;
    }

Any ideas about this Dan ?

Comment 14 Daniel Walsh 2009-05-08 14:38:30 UTC
No idea, seems like a valid context to me.

Any avc available Paul?

Was libvirt running as virtd_t?

Comment 15 Daniel Walsh 2009-05-08 14:40:04 UTC
If I runcon to shell with this command I get 

allow unconfined_t svirt_t:process transition;

But libvirtd should have been able to transition here.

ps -eZ | grep libvirt

Comment 16 Aron Griffis 2009-05-08 14:49:06 UTC
If you guys do your own testing with selinux enabled but you're not seeing this problem, then I guess it's specific to the method both Paul and I used to get to rawhide.  We both installed f10 yesterday then updated to rawhide from there.  (It's hard for us to start on something more recent due to bug 499408)

Here is the exact sequence I used:

sed -i '/^enabled/s/0/1/' /etc/yum.repos.d/*updates*.repo
yum -y upgrade
sed -i '/^enabled/s/1/0/' /etc/yum.repos.d/*.repo
sed -i '/^enabled/s/0/1/' /etc/yum.repos.d/*raw*.repo
yum -y remove preupgrade
yum -y update
yum -y install PackageKit

I think Paul's sequence was a little simpler, but yum couldn't figure out how to update until I removed preupgrade (which also uninstalls PackageKit) and re-installed it afterward.

Comment 17 Daniel Berrangé 2009-05-08 14:55:28 UTC
You mention you did a full relabel earlier in this ticket, so I assume that would have sorted any labelling issues following the upgrade.

Can you check what context libvirtd is running under with:

# ps -eZ | grep libvirtd

Comment 18 Aron Griffis 2009-05-08 15:06:39 UTC
I did not do the relabel as Paul did (I'm not so selinux-savvy), but here is the output I see:

$ ps -eZ | grep libvirtd
system_u:system_r:virtd_t:s0     2062 ?        00:00:01 libvirtd

Comment 19 Daniel Walsh 2009-05-08 15:11:11 UTC
The problem is that virtd_t is not ranged

ps -eZ | grep virtd
system_u:system_r:virtd_t:s0-s0:c0.c1023 3591 ? 00:00:00 libvirtd


If you execute service virtd_t restart what does the libvirtd run as?

What policy do you have installed

# rpm -Uhv selinux-policy

Comment 20 Daniel Walsh 2009-05-08 15:12:06 UTC
Make that service libvirtd restart

Comment 21 Aron Griffis 2009-05-08 15:19:46 UTC
# rpm -qa | grep selinux-policy
selinux-policy-3.6.12-28.fc11.noarch
selinux-policy-targeted-3.6.12-28.fc11.noarch

# service libvirtd restart
Stopping libvirtd daemon:                                  [  OK  ]
Starting libvirtd daemon:                                  [  OK  ]

# ps -eZ | grep virtd
unconfined_u:system_r:virtd_t:s0 5267 ?        00:00:00 libvirtd

Comment 22 Daniel Walsh 2009-05-08 15:28:31 UTC
Now I have no clue what that is happening.

Could you try 

# load_policy
# service libvirtd restart

And see if it comes up ranged.

What does 

# id -Z show
# semanage login -l
# semanage user -l

Comment 23 Aron Griffis 2009-05-08 16:05:10 UTC
--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ load_policy

--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ service libvirtd restart
Stopping libvirtd daemon: [  OK  ]
Starting libvirtd daemon: [  OK  ]

--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ ps -eZ | grep virtd
unconfined_u:system_r:virtd_t:s0 5428 ?        00:00:00 libvirtd

--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ id -Z show
id: cannot print security context when user specified

--- 1 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ id -Z
unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023

--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ semanage login -l

Login Name      SELinux User     MLS/MCS Range            

__default__     unconfined_u     s0                       
root            unconfined_u     s0-s0:c0.c1023           
system_u        system_u         s0-s0:c0.c1023           

--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ------------------------------
$ semanage user -l

                Labeling   MLS/       MLS/                          
SELinux User    Prefix     MCS Level  MCS Range        SELinux Roles

guest_u         user       s0         s0               guest_r
root            user       s0         s0-s0:c0.c1023   staff_r sysadm_r system_r unconfined_r
staff_u         user       s0         s0-s0:c0.c1023   staff_r sysadm_r system_r
sysadm_u        user       s0         s0-s0:c0.c1023   sysadm_r
system_u        user       s0         s0-s0:c0.c1023   system_r
unconfined_u    user       s0         s0-s0:c0.c1023   system_r unconfined_r
user_u          user       s0         s0               user_r
xguest_u        user       s0         s0               xguest_r

Comment 24 Aron Griffis 2009-05-08 16:06:28 UTC
sorry, my prompt autosizes to the terminal so it's 80-columns wide and bugzilla unhelpfully wraps it.

Comment 25 Stephen Smalley 2009-05-08 16:42:58 UTC
Sometimes a policy update will fail during the invocation of semodule from %post, and this will unfortunately not unwind the transaction.  Try a yum reinstall selinux-policy-targeted and watch the output to see if you get any errors from semodule/libsemanage.

Comment 26 Stephen Smalley 2009-05-08 16:54:27 UTC
Also, can we get the output of:
/sbin/ausearch -i -m SELINUX_ERR,AVC -ts today

Comment 27 Aron Griffis 2009-05-08 17:05:49 UTC
--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ----------
$ /sbin/ausearch -i -m SELINUX_ERR,AVC -ts today
----
type=SYSCALL msg=audit(05/08/2009 11:14:38.970:298) : arch=x86_64 syscall=open success=yes exit=23 a0=7f2e1cc806a0 a1=0 a2=7f2e1cc806b2 a3=0 items=0 ppid=1 pid=1546 auid=unset uid=dbus gid=dbus euid=dbus suid=dbus fsuid=dbus egid=dbus sgid=dbus fsgid=dbus tty=(none) ses=4294967295 comm=dbus-daemon exe=/bin/dbus-daemon subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 key=(null) 
type=AVC msg=audit(05/08/2009 11:14:38.970:298) : avc:  denied  { read } for  pid=1546 comm=dbus-daemon name=cmdline dev=proc ino=23279 scontext=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:virtd_t:s0 tclass=file 
type=AVC msg=audit(05/08/2009 11:14:38.970:298) : avc:  denied  { search } for  pid=1546 comm=dbus-daemon name=5267 dev=proc ino=23278 scontext=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:virtd_t:s0 tclass=dir 
----
type=SYSCALL msg=audit(05/08/2009 11:56:06.338:318) : arch=x86_64 syscall=open success=yes exit=23 a0=7f2e1cc875b0 a1=0 a2=7f2e1cc875c2 a3=0 items=0 ppid=1 pid=1546 auid=unset uid=dbus gid=dbus euid=dbus suid=dbus fsuid=dbus egid=dbus sgid=dbus fsgid=dbus tty=(none) ses=4294967295 comm=dbus-daemon exe=/bin/dbus-daemon subj=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 key=(null) 
type=AVC msg=audit(05/08/2009 11:56:06.338:318) : avc:  denied  { read } for  pid=1546 comm=dbus-daemon name=cmdline dev=proc ino=25105 scontext=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:virtd_t:s0 tclass=file 
type=AVC msg=audit(05/08/2009 11:56:06.338:318) : avc:  denied  { search } for  pid=1546 comm=dbus-daemon name=5428 dev=proc ino=25104 scontext=system_u:system_r:system_dbusd_t:s0-s0:c0.c1023 tcontext=unconfined_u:system_r:virtd_t:s0 tclass=dir 

--- 0 root@oliver [Fedora release 10.93 x86_64] ~ ----------
$ yum reinstall selinux-policy-targeted
Setting up Reinstall Process
rawhide                                                                                                            | 3.8 kB     00:00     
Not using downloaded repomd.xml because it is older than what we have:
  Current   : Thu May  7 09:12:54 2009
  Downloaded: Wed May  6 09:21:17 2009
rawhide-debuginfo                                                                                                  | 2.7 kB     00:00     
rawhide-source                                                                                                     | 2.7 kB     00:00     
rawhide-source/primary_db                                                                                          | 2.4 MB     00:04     
Resolving Dependencies
--> Running transaction check
---> Package selinux-policy-targeted.noarch 0:3.6.12-28.fc11 set to be erased
---> Package selinux-policy-targeted.noarch 0:3.6.12-28.fc11 set to be updated
--> Finished Dependency Resolution

Dependencies Resolved

=======================================================================
 Package                   Arch     Version         Repository    Size
=======================================================================
Installing:
 selinux-policy-targeted   noarch   3.6.12-28.fc11  rawhide      2.2 M
Removing:
 selinux-policy-targeted   noarch   3.6.12-28.fc11  installed    2.3 M

Transaction Summary
=======================================================================
Install      1 Package(s)         
Update       0 Package(s)         
Remove       1 Package(s)         

Total download size: 2.2 M
Is this ok [y/N]: y
Downloading Packages:
selinux-policy-targeted-3.6.12-28.fc11.noarch.rpm   | 2.2 MB     00:02     
Running rpm_check_debug
Running Transaction Test
Finished Transaction Test
Transaction Test Succeeded
Running Transaction
  Erasing        : selinux-policy-targeted                                                                                            1/2 
  Installing     : selinux-policy-targeted                                                                                            1/2 
libsepol.scope_copy_callback: unconfined: Duplicate declaration in module: type/attribute unconfined_devpts_t
libsemanage.semanage_link_sandbox: Link packages failed
semodule:  Failed!

Removed:
  selinux-policy-targeted.noarch 0:3.6.12-28.fc11                                                                                         

Installed:
  selinux-policy-targeted.noarch 0:3.6.12-28.fc11                                                                                         

Complete!

Comment 28 Stephen Smalley 2009-05-08 17:17:56 UTC
Ok, that confirms that semodule is failing to install the new policy, so you are still running the prior policy despite what rpm says.  The error is:
libsepol.scope_copy_callback: unconfined: Duplicate declaration in module:
type/attribute unconfined_devpts_t
libsemanage.semanage_link_sandbox: Link packages failed
semodule:  Failed!

Try this:
yum remove selinux-policy-targeted
mv /etc/selinux/targeted/modules /etc/selinux/targeted/modules.old
yum install selinux-policy-targeted

Comment 29 Aron Griffis 2009-05-08 17:33:58 UTC
That worked, thanks for getting to the bottom of it!

So is this a problem that needs some further resolution?  I'd guess it will hit
anybody that does a yum upgrade from f10 to f11.

This is my last update to this bug prior to the weekend, need to head out early.
I'll follow up on Monday.

Comment 30 Stephen Smalley 2009-05-08 18:00:45 UTC
When you get back, if you could tar up the /etc/selinux/targeted/modules.old directory and attach it, that would help with replicating the error.

Comment 31 Paul Moore 2009-05-08 20:07:52 UTC
Sorry I missed the discussion this afternoon but I'm attaching a tarball of my "modules.old" directory created as described by Stephen in comment #28.

Comment 32 Paul Moore 2009-05-08 20:09:46 UTC
Created attachment 343162 [details]
See comment #31

Comment 33 Mark McLoughlin 2009-05-11 11:34:46 UTC
Moving to selinux-policy-targeted

Comment 34 Daniel Walsh 2009-05-11 12:18:18 UTC
The problem is in the logic of selinux-policy post install.

SELinux policy in F11 is splitting out unconfined.pp into two packages, unconfined.pp and unconfineduser.pp.  THis will allow you to have an unconfined user with all other domains confined, by removing the unconfined.pp.  You can also remove the unconfineduser.pp TO have "Strict" policy.  No unconfined domains.

The post install should not install the unoconfined.pp or unconfineduser.pp if the admin has removed them

So the rules of the post install on upgrades

unconfined.pp unocnfineduser.pp -  Upgrade
     I             I               Upgrade both
     0             I               Upgrade unconfineduser.pp
     0             0               Upgrade neither
     1             0               If Previous version < 3.0.1 (F10)
                                      Upgrarde both
                                   Else 
                                      Upgrade unconfined.pp

Both get installed on fresh installs

Fixed in selinux-policy-3.6.12-33.fc11.noarch