Bug 972743

Summary: CRITICAL exception in nova/compute.log
Product: Red Hat OpenStack Reporter: Daniel Paikov <dpaikov>
Component: openstack-novaAssignee: Michal Privoznik <mprivozn>
Status: CLOSED WORKSFORME QA Contact: Ami Jeain <ajeain>
Severity: medium Docs Contact:
Priority: medium    
Version: 3.0CC: dpaikov, hateya, ndipanov, yeylon, ykaul
Target Milestone: rc   
Target Release: 3.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-06-11 12:03:15 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
nova logs none

Description Daniel Paikov 2013-06-10 14:04:25 UTC
Created attachment 759213 [details]
nova logs

The following exception appears after first run of a newly installed allinone setup:

2013-06-10 16:10:21.762 15571 CRITICAL nova [-] 'NoneType' object has no attribute 'numOfDomains'
2013-06-10 16:10:21.762 15571 TRACE nova Traceback (most recent call last):
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/bin/nova-compute", line 85, in <module>
2013-06-10 16:10:21.762 15571 TRACE nova     service.wait()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/service.py", line 696, in wait
2013-06-10 16:10:21.762 15571 TRACE nova     _launcher.wait()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/service.py", line 209, in wait
2013-06-10 16:10:21.762 15571 TRACE nova     super(ServiceLauncher, self).wait()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/service.py", line 179, in wait
2013-06-10 16:10:21.762 15571 TRACE nova     service.wait()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/eventlet/greenthread.py", line 166, in wait
2013-06-10 16:10:21.762 15571 TRACE nova     return self._exit_event.wait()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/eventlet/event.py", line 116, in wait
2013-06-10 16:10:21.762 15571 TRACE nova     return hubs.get_hub().switch()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/eventlet/hubs/hub.py", line 177, in switch
2013-06-10 16:10:21.762 15571 TRACE nova     return self.greenlet.switch()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/eventlet/greenthread.py", line 192, in main
2013-06-10 16:10:21.762 15571 TRACE nova     result = function(*args, **kwargs)
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/service.py", line 147, in run_server
2013-06-10 16:10:21.762 15571 TRACE nova     server.start()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/service.py", line 436, in start
2013-06-10 16:10:21.762 15571 TRACE nova     self.manager.init_host()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 597, in init_host
2013-06-10 16:10:21.762 15571 TRACE nova     self._destroy_evacuated_instances(context)
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 434, in _destroy_evacuated_instances
2013-06-10 16:10:21.762 15571 TRACE nova     local_instances = self._get_instances_on_driver(context)
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 397, in _get_instances_on_driver
2013-06-10 16:10:21.762 15571 TRACE nova     driver_uuids = self.driver.list_instance_uuids()
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 681, in list_instance_uuids
2013-06-10 16:10:21.762 15571 TRACE nova     for name in self.list_instances()]
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 663, in list_instances
2013-06-10 16:10:21.762 15571 TRACE nova     for domain_id in self.list_instance_ids():
2013-06-10 16:10:21.762 15571 TRACE nova   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 657, in list_instance_ids
2013-06-10 16:10:21.762 15571 TRACE nova     if self._conn.numOfDomains() == 0:
2013-06-10 16:10:21.762 15571 TRACE nova AttributeError: 'NoneType' object has no attribute 'numOfDomains'

Comment 1 Michal Privoznik 2013-06-10 15:33:37 UTC
I think this is the root cause (file compute.log in attachment 1 [details]):

2013-06-10 16:10:21.694 15571 ERROR nova.virt.libvirt.driver [-] Connection to libvirt failed: Failed to connect socket to '/var/run/libvirt/libvirt-sock': Permission denied
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver Traceback (most recent call last):
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 627, in _connect
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver     return libvirt.openAuth(uri, auth, 0)
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver     if ret is None:raise libvirtError('virConnectOpenAuth() failed')
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver libvirtError: Failed to connect socket to '/var/run/libvirt/libvirt-sock': Permission denied
2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver 
2013-06-10 16:10:21.699 15571 WARNING nova.virt.libvirt.driver [-] URI qemu:///system does not support events
2013-06-10 16:10:21.699 15571 ERROR nova.virt.libvirt.driver [-] Nova requires libvirt version 0.9.6 or greater.
2013-06-10 16:10:21.759 15571 ERROR nova.virt.libvirt.driver [-] Connection to libvirt failed: Failed to connect socket to '/var/run/libvirt/libvirt-sock': Permission denied
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver Traceback (most recent call last):
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 627, in _connect
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver     return libvirt.openAuth(uri, auth, 0)
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver     if ret is None:raise libvirtError('virConnectOpenAuth() failed')
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver libvirtError: Failed to connect socket to '/var/run/libvirt/libvirt-sock': Permission denied
2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver 

However, from the log I can't tell why libvirt client is not able to connect. Daniel, can you please try to gather libvirtd and libvirt client logs? http://wiki.libvirt.org/page/DebugLogs with exception of not setting log_filters but commenting the variable out so we get a full debug logs, please.

Comment 2 Daniel Paikov 2013-06-11 12:03:15 UTC
(In reply to Michal Privoznik from comment #1)
> I think this is the root cause (file compute.log in attachment 1 [details]):
> 
> 2013-06-10 16:10:21.694 15571 ERROR nova.virt.libvirt.driver [-] Connection
> to libvirt failed: Failed to connect socket to
> '/var/run/libvirt/libvirt-sock': Permission denied
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver Traceback (most
> recent call last):
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver   File
> "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 627, in
> _connect
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver     return
> libvirt.openAuth(uri, auth, 0)
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver   File
> "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver     if ret is
> None:raise libvirtError('virConnectOpenAuth() failed')
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver libvirtError:
> Failed to connect socket to '/var/run/libvirt/libvirt-sock': Permission
> denied
> 2013-06-10 16:10:21.694 15571 TRACE nova.virt.libvirt.driver 
> 2013-06-10 16:10:21.699 15571 WARNING nova.virt.libvirt.driver [-] URI
> qemu:///system does not support events
> 2013-06-10 16:10:21.699 15571 ERROR nova.virt.libvirt.driver [-] Nova
> requires libvirt version 0.9.6 or greater.
> 2013-06-10 16:10:21.759 15571 ERROR nova.virt.libvirt.driver [-] Connection
> to libvirt failed: Failed to connect socket to
> '/var/run/libvirt/libvirt-sock': Permission denied
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver Traceback (most
> recent call last):
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver   File
> "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 627, in
> _connect
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver     return
> libvirt.openAuth(uri, auth, 0)
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver   File
> "/usr/lib64/python2.6/site-packages/libvirt.py", line 102, in openAuth
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver     if ret is
> None:raise libvirtError('virConnectOpenAuth() failed')
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver libvirtError:
> Failed to connect socket to '/var/run/libvirt/libvirt-sock': Permission
> denied
> 2013-06-10 16:10:21.759 15571 TRACE nova.virt.libvirt.driver 
> 
> However, from the log I can't tell why libvirt client is not able to
> connect. Daniel, can you please try to gather libvirtd and libvirt client
> logs? http://wiki.libvirt.org/page/DebugLogs with exception of not setting
> log_filters but commenting the variable out so we get a full debug logs,
> please.

This issue stopped reproducing since I reinstalled my host. Closing the bug for now.