Bug 1003488

Summary: VM with SPICE console fails to start due to : Spice-Warning **: reds.c:3247:reds_init_ssl: Could not use private key file
Product: Red Hat Enterprise Linux 6 Reporter: Gadi Ickowicz <gickowic>
Component: libvirtAssignee: Michal Privoznik <mprivozn>
Status: CLOSED DUPLICATE QA Contact: Virtualization Bugs <virt-bugs>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.5CC: acathrow, cfergeau, dallan, dblechte, dyuan, eblake, gickowic, mkenneth, nlevinki, shyu, uril, whuang, ydu, zhwang
Target Milestone: rcKeywords: TestBlocker
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-09-06 21:59:34 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
vdsm, libvirt and qemu logs
none
hadash vm's qemu log none

Description Gadi Ickowicz 2013-09-02 07:45:09 UTC
Created attachment 792732 [details]
vdsm, libvirt and qemu logs

Description of problem:
Unable to start vm with spice console on rhel 6.5 host with SPICE console. VM launch fails with the following error in vdsm log:

Thread-24717::DEBUG::2013-09-02 10:06:51,444::libvirtconnection::101::libvirtconnection::(wrapper) Unknown libvirterror: ecode: 1 edom: 10 level: 2 message: internal error process exited while connecting to monito
r: ((null):7849): Spice-Warning **: reds.c:3247:reds_init_ssl: Could not use private key file
failed to initialize spice server
Thread-24717::DEBUG::2013-09-02 10:06:51,445::vm::2036::vm.Vm::(_startUnderlyingVm) vmId=`098ede7f-7607-43a1-8932-9b7efca619f7`::_ongoingCreations released
Thread-24717::ERROR::2013-09-02 10:06:51,445::vm::2062::vm.Vm::(_startUnderlyingVm) vmId=`098ede7f-7607-43a1-8932-9b7efca619f7`::The vm start process failed
Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 2022, in _startUnderlyingVm
    self._run()
  File "/usr/share/vdsm/vm.py", line 2917, in _run
    self._connection.createXML(domxml, flags),
  File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 76, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 2662, in createXML
    if ret is None:raise libvirtError('virDomainCreateXML() failed', conn=self)
libvirtError: internal error process exited while connecting to monitor: ((null):7849): Spice-Warning **: reds.c:3247:reds_init_ssl: Could not use private key file
failed to initialize spice server


Version-Release number of selected component (if applicable):
spice-server-0.12.4-2.el6.x86_64
libvirt-0.10.2-22.el6.x86_64
vdsm-4.12.0-72.git287bb7e.el6ev.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Create vm with SPICE console and start it on the host


Actual results:
vm fails to start

Expected results:
vm should start

Additional info:
vdsm, libvirt and qemu logs attached

Comment 3 Christophe Fergeau 2013-09-02 09:36:00 UTC
Looking at the code, I think it's failing when trying to use 
/etc/pki/vdsm/libvirt-spice/server-key.pem, does this file exist on the vdsm node, and is it valid?

Comment 4 Uri Lublin 2013-09-02 09:40:50 UTC
Seems like you were missing the server-key.pem file, which is needed by spice-server.
According to the attached logs it should be in the following directory:
 /etc/pki/vdsm/libvirt-spice

Please make sure this file exists on your server, and retry.

Comment 5 Gadi Ickowicz 2013-09-02 10:44:48 UTC
(In reply to Uri Lublin from comment #4)
> Seems like you were missing the server-key.pem file, which is needed by
> spice-server.
> According to the attached logs it should be in the following directory:
>  /etc/pki/vdsm/libvirt-spice
> 
> Please make sure this file exists on your server, and retry.


the file exists but it still fails to launch vms with spice console

[root@aqua-vds5 vdsm]# ll /etc/pki/vdsm/libvirt-spice/
total 76
-rw-r--r--. 1 root root 1472 Aug 28 15:45 ca-cert.pem
-rw-r--r--. 1 root root 1472 Aug 25 12:23 ca-cert.pem.20130826175502
-rw-r--r--. 1 root root 1448 Aug 26 17:55 ca-cert.pem.20130826184735
-rw-r--r--. 1 root root 1472 Aug 26 18:47 ca-cert.pem.20130827142032
-rw-r--r--. 1 root root 1489 Aug 27 14:20 ca-cert.pem.20130828154510
-rw-r--r--. 1 root root 1594 Sep  1 16:39 server-cert.pem
-rw-r--r--. 1 root root 1594 Aug 25 12:23 server-cert.pem.20130826175502
-rw-r--r--. 1 root root 1533 Aug 26 17:55 server-cert.pem.20130826184735
-rw-r--r--. 1 root root 1594 Aug 26 18:47 server-cert.pem.20130827142032
-rw-r--r--. 1 root root 1610 Aug 27 14:20 server-cert.pem.20130827142242
-rw-r--r--. 1 root root 1610 Aug 27 14:22 server-cert.pem.20130828154510
-rw-r--r--. 1 root root 1594 Aug 28 15:45 server-cert.pem.20130901163953
-r--r-----. 1 vdsm kvm  1679 Sep  1 16:39 server-key.pem
-r--r-----. 1 vdsm kvm  1679 Aug 25 12:23 server-key.pem.20130826175503
-r--r-----. 1 vdsm kvm  1679 Aug 26 17:55 server-key.pem.20130826184735
-r--r-----. 1 vdsm kvm  1679 Aug 26 18:47 server-key.pem.20130827142032
-r--r-----. 1 vdsm kvm  1679 Aug 27 14:20 server-key.pem.20130827142242
-r--r-----. 1 vdsm kvm  1675 Aug 27 14:22 server-key.pem.20130828154511
-r--r-----. 1 vdsm kvm  1675 Aug 28 15:45 server-key.pem.20130901163953

Comment 6 Christophe Fergeau 2013-09-02 13:44:07 UTC
(In reply to Gadi Ickowicz from comment #5)
> the file exists but it still fails to launch vms with spice console

Do you know which user/group qemu is running with in vdsm? It needs to be as user 'vdsm' or to be running as a user present in the 'kvm' group to be able to read this file.

Comment 7 Uri Lublin 2013-09-02 14:03:28 UTC
It works for me when running the VM from the command line.
I run it on the same server that was the problem occurred (Thanks Gadi).
It works both as user "root" and as user "vdsm".

I don't know why from RHEV-M it does not.

I think I only changed 3 things (all not related to spice), which require pre-run operations:
1. the image used (also I'm using IDE, but it fails from RHEV-M with IDE too)
2. user network
3. -monitor stdio

Command line:
/usr/libexec/qemu-kvm -name uritest1 -S -M rhel6.4.0 -cpu host -enable-kvm -m 1024  -realtime mlock=off -smp 1,sockets=1,cores=1,threads=1  -uuid 0f5dfe2d-8bef-43a7-bd1d-17121b711121  -smbios type=1,manufacturer=RedHat,product=RHEVHypervisor,version=6Server-6.5.0.0.el6,serial=d017c20d-06dc-4406-8e4e-f05ccc5669c4,uuid=0f5dfe2d-8bef-43a7-bd1d-17121b711121  -nodefconfig -nodefaults  -monitor stdio -rtc base=2013-09-02T11:30:25,driftfix=slew  -no-shutdown  -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x4 -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x5  -drive if=none,media=cdrom,id=drive-ide0-1-0,readonly=on,format=raw,serial= -device ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0  -drive file=/tmp/uri/uri_img.raw,if=none,id=drive-ide0-0-0,format=raw,serial=3f98a5de-7eab-4084-ba90-a870d5957075,cache=none,werror=stop,rerror=stop,aio=native -device ide-drive,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0  -net nic -net user  -chardev socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/0f5dfe2d-8bef-43a7-bd1d-17121b711121.com.redhat.rhevm.vdsm,server,nowait  -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.rhevm.vdsm -chardev socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/0f5dfe2d-8bef-43a7-bd1d-17121b711121.org.qemu.guest_agent.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,id=channel1,name=org.qemu.guest_agent.0  -chardev spicevmc,id=charchannel2,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=3,chardev=charchannel2,id=channel2,name=com.redhat.spice.0 -spice port=5900,tls-port=5901,addr=0,x509-dir=/etc/pki/vdsm/libvirt-spice,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=smartcard,tls-channel=usbredir,seamless-migration=on  -k en-us  -vga qxl -global qxl-vga.ram_size=67108864 -global qxl-vga.vram_size=67108864

Comment 8 Uri Lublin 2013-09-03 09:04:09 UTC
I checked the difference between RHEL-6.4.z where it works and RHEL-6.5 where it does not, with regards to spice-server, qemu-kvm-rhev, libvirt and vdsm packages.

RHEL-6.4.z:
spice-server-0.12.0-12.el6.x86_64
qemu-kvm-rhev-0.12.1.2-2.355.el6_4.3.x86_64
libvirt-0.10.2-18.el6_4.9.x86_64
vdsm-4.12.0-72.git287bb7e.el6ev.x86_64

RHEL-6.5:
spice-server-0.12.4-2.el6.x86_64
qemu-kvm-rhev-0.12.1.2-2.398.el6.x86_64
libvirt-0.10.2-22.el6.x86_64
vdsm-4.12.0-72.git287bb7e.el6ev.x86_64

The vdsm packages were the same version.

I updated packages one by one according to the order above, and it failed only after updating libvirt, from -0.10.2-18.el6_4.9 to -0.10.2-22.el6  (-23 fails too).

Moving to libvirt component.

Comment 9 Martin Kletzander 2013-09-03 12:25:58 UTC
I can't reproduce the issue on 6.5 with libvirt-0.10.2-23.el6.x86_64

@Gadi: Please attach /var/log/libvirt/qemu/hadash.log as well.  Also, could you check the permissions for the whole path to /etc/pki/vdsm/libvirt-spice/ (also for the directories?

@Uril: Can you check whether the qemu-kvm commandline libvirt is running has changed between those two releases?  If possible, could you try bisecting through libvirt versions (I can provide all the rpms if necessary)?  That would make it a lot easier for us to find the problem.

Comment 10 Uri Lublin 2013-09-03 12:42:46 UTC
Martin, did you try to reproduce using RHEV-M ?

As mentioned in comment #7, I could not reproduce the problem when running qemu-kvm command-line from bash (a command line which is almost the same as the one logged).

Comment 11 Martin Kletzander 2013-09-03 12:49:31 UTC
Not RHEV-M per se, but using vdsm-configured libvirt with own certificates.  I have an instance of ovirt running on fedoras only.  Do you have a place where I could try few things?  Are you on IRC? I can't seem to find you.

Comment 12 Gadi Ickowicz 2013-09-03 13:19:50 UTC
Created attachment 793194 [details]
hadash vm's qemu log

Comment 13 Uri Lublin 2013-09-03 13:29:11 UTC
(In reply to Martin Kletzander from comment #11)
> Do you have a place where I could try few things?

I asked Gadi to help you with that.
I can also help if needed.

Comment 16 Shanzhi Yu 2013-09-05 10:31:12 UTC
I can reproduce the issue on 6.5 with libvirt-0.10.2-23.el6.x86_64
For details please refer to BG https://bugzilla.redhat.com/show_bug.cgi?id=997350#c15

Comment 18 Eric Blake 2013-09-06 21:59:34 UTC
Everything I'm seeing about this (introduced in -22, and 'permissions denied' error is related to group settings) says this is a dup of bug 964359.  I'm going ahead and closing it now; but please reopen it if repeating the testing of comment #16 sees a problem when using the 0.10.2-24 build.

*** This bug has been marked as a duplicate of bug 964359 ***