[Openstack] dnsmasq does not start + no xapi interface -- how to solve this problem

Afef MDHAFFAR afef.mdhaffar at gmail.com
Mon Dec 10 20:18:19 UTC 2012


Hi all,

I am facing an boring issue since Friday: nova-network is unable to start
dnsmasq. Therefore the xapi0 interface is not created.
Then, it is impossible to launch VMs. nova-network does not answer requests
and nova-compute returns an RPC timeout.
Please help me to solve this problem
I am using openstack folsom release + XCP + ubuntu 12.04

log file of nova-compute and nova-network are attached to this e-mail.

Thank you,
Afef
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openstack.org/pipermail/openstack/attachments/20121210/d424b9b1/attachment.html>
-------------- next part --------------
root at computeDomU07:~# nova-compute start
2012-12-10 20:06:03 INFO nova.virt.driver [-] Loading compute driver 'xenapi.XenAPIDriver'
2012-12-10 20:06:03 DEBUG nova.openstack.common.lockutils [-] Got semaphore "nova.servicegroup.api.new" for method "__new__"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:03 DEBUG nova.servicegroup.api [-] ServiceGroup driver defined as an instance of db from (pid=23573) __new__ /opt/stack/nova/nova/servicegroup/api.py:49
2012-12-10 20:06:03 DEBUG nova.network.minidns [-] minidns file is |/tmp/tmpWjOWNh/dnstest.txt| from (pid=23573) __init__ /opt/stack/nova/nova/network/minidns.py:44
2012-12-10 20:06:03 DEBUG nova.network.minidns [-] minidns file is |/tmp/tmpsmIgb3/dnstest.txt| from (pid=23573) __init__ /opt/stack/nova/nova/network/minidns.py:44
2012-12-10 20:06:03 DEBUG nova.openstack.common.lockutils [-] Got semaphore "nova.servicegroup.api.new" for method "__new__"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:03 DEBUG nova.openstack.common.lockutils [-] Got semaphore "nova.servicegroup.api.new" for method "__new__"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:03 DEBUG nova.openstack.common.lockutils [-] Got semaphore "nova.servicegroup.api.new" for method "__new__"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:03 DEBUG nova.openstack.common.lockutils [-] Got semaphore "nova.servicegroup.api.new" for method "__new__"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:03 DEBUG nova.service [-] Full set of CONF: from (pid=23573) wait /opt/stack/nova/nova/service.py:173
2012-12-10 20:06:03 DEBUG nova.service [-] bandwidth_poll_interval : 600 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_num_vbd_unplug_retries : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] agent_timeout : 30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] num_networks : 1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] vlan_interface : eth1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] compute_stats_class : nova.compute.stats.Stats from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] compute_topic : compute from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] glance_port : 9292 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] glance_api_servers : ['10.0.1.15:9292'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] flat_interface : eth1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] osapi_compute_listen_port : 8774 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] user_cert_subject : /C=US/ST=California/O=OpenStack/OU=NovaDev/CN=%.16s-%.16s-%s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] dhcp_lease_time : 120 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] quota_ram : 51200 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_sparse_copy : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] osapi_compute_listen : 0.0.0.0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] cache_images : all from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] aws_access_key_id : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:03 DEBUG nova.service [-] send_arp_for_ha : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] backdoor_port : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] max_age : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] network_size : 256 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] host_state_interval : 120 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] virt_mkfs : ['default=mkfs.ext3 -L %(fs_label)s -F %(target)s', 'linux=mkfs.ext3 -L %(fs_label)s -F %(target)s', 'windows=mkfs.ntfs --force --fast --label %(fs_label)s %(target)s'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] enable_new_services : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] my_ip : 10.0.1.30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] quota_security_groups : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] live_migration_retry_count : 30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] password_length : 12 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] quota_injected_files : 5 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] public_interface : eth3 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_torrent_download_stall_cutoff : 600 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] default_schedule_zone : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] quota_injected_file_path_bytes : 255 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] logdir : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] vpn_ip : 10.0.1.30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] glance_protocol : http from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] osapi_compute_extension : ['nova.api.openstack.compute.contrib.standard_extensions'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] allow_resize_to_same_host : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] reclaim_instance_interval : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] wsgi_log_format : %(client_ip)s "%(request_line)s" status: %(status_code)s len: %(body_length)s time: %(wall_seconds).7f from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] rootwrap_config : /etc/nova/rootwrap.conf from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] ipv6_backend : rfc2462 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] notification_driver : [] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] osapi_max_limit : 1000 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] enable_instance_password : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:03 DEBUG nova.service [-] compute_api_class : nova.compute.api.API from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] max_kernel_ramdisk_size : 16777216 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_sr_base_path : /var/run/sr-mount from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] default_access_ip_network_name : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] default_publisher_id : computeDomU07 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] resume_guests_state_on_host_boot : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_torrent_max_last_accessed : 86400 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] ec2_listen : 0.0.0.0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] logfile : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] floating_ip_dns_manager : nova.network.minidns.MiniDNS from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] security_group_handler : nova.network.sg.NullSecurityGroupHandler from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_remap_vbd_dev_prefix : sd from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] injected_network_template : /opt/stack/nova/nova/virt/interfaces.template from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_connection_concurrent : 5 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] snapshot_name_template : snapshot-%s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] resize_confirm_window : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] vncserver_proxyclient_address : 169.254.0.1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] xenapi_connection_username : root from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] metadata_host : 10.0.1.30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] quota_cores : 20 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] quota_driver : nova.quota.DbQuotaDriver from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] debug : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] use_project_ca : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] routing_source_ip : 10.0.1.30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] policy_file : policy.json from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] periodic_fuzzy_delay : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] dnsmasq_config_file :  from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] osapi_compute_link_prefix : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] dmz_cidr : [] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] lock_path : /opt/stack/data/nova from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] rpc_cast_timeout : 30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] state_path : /opt/stack/data/nova from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] until_refresh : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] networks_path : /opt/stack/data/nova/networks from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:03 DEBUG nova.service [-] fixed_ip_disassociate_timeout : 600 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] flat_network_dns : 8.8.4.4 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] config_dir : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] log_config : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] use_stderr : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] fatal_deprecations : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] s3_port : 3333 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] logfile_mode : 0644 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] default_ephemeral_format : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] logging_context_format_string : %(asctime)s %(color)s%(levelname)s %(name)s [%(request_id)s %(user_name)s %(project_name)s%(color)s] %(instance)s%(color)s%(message)s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_seed_chance : 1.0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] metadata_listen_port : 8775 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] reserved_host_disk_mb : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] cinder_endpoint_template : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] isolated_hosts : [] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_name_template : instance-%08x from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_usage_audit_period : month from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] log_dir : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] cert_manager : nova.cert.manager.CertManager from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] quota_metadata_items : 128 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] logging_debug_format_suffix : from (pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] network_host : computeDomU07 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] console_manager : nova.console.manager.ConsoleProxyManager from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] console_topic : console from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] use_join_force : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] rpc_backend : nova.openstack.common.rpc.impl_kombu from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] default_log_levels : ['amqplib=WARN', 'sqlalchemy=WARN', 'boto=WARN', 'suds=INFO', 'keystone=INFO', 'eventlet.wsgi.server=WARN'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] running_deleted_instance_poll_interval : 30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] heal_instance_info_cache_interval : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] zombie_instance_updated_at_window : 172800 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instances_path : /opt/stack/data/nova/instances from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] flat_injected : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] api_rate_limit : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] host : computeDomU07 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_dns_domain :  from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] target_port : 3260 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] non_inheritable_image_properties : ['cache_in_nova', 'bittorrent'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] quota_injected_file_content_bytes : 10240 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] running_deleted_instance_action : log from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] console_host : computeDomU07 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] network_device_mtu : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] key_file : private/cakey.pem from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] floating_range : 4.4.4.0/24 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_remap_vbd_dev : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] default_floating_pool : nova from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] reboot_timeout : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] multi_host : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] glance_num_retries : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] db_backend : sqlalchemy from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] image_cache_manager_interval : 40 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] fixed_range : 10.0.0.0/24 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vpn_start : 1000 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] reservation_expire : 86400 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_images : none from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] crl_file : crl.pem from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] send_arp_for_ha_count : 3 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] monkey_patch : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] rpc_conn_pool_size : 30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] s3_host : 10.0.1.30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_seed_duration : 3600 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] max_nbd_devices : 16 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_connection_url : http://10.0.1.174 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] linuxnet_ovs_integration_bridge : br-int from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] scheduler_topic : scheduler from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] verbose : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] flat_network_bridge : xapi0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] force_dhcp_release : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_ovs_integration_bridge : xapi1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] default_instance_type : m1.small from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] metadata_listen : 0.0.0.0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] firewall_driver : nova.virt.firewall.IptablesFirewallDriver from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vlan_start : 100 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] metadata_workers : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] periodic_interval : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vpn_key_suffix : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_vif_driver : nova.virt.xenapi.vif.XenAPIBridgeDriver from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] gateway : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] null_kernel : nokernel from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] target_host : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] notify_on_any_change : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] force_raw_images : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] quota_key_pairs : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:04 DEBUG nova.service [-] instance_format : [instance: %(uuid)s]  from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] osapi_glance_link_prefix : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] rpc_response_timeout : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] dhcp_domain : novalocal from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] osapi_compute_ext_list : [] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] default_notification_level : INFO from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] publish_errors : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] consoleauth_topic : consoleauth from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] auto_assign_floating_ip : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] novncproxy_base_url : http://10.0.1.30:6080/vnc_auto.html from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] service_down_time : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] logging_exception_prefix : %(color)s%(asctime)s TRACE %(name)s %(instance)s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] enabled_apis : ['ec2', 'osapi_compute', 'metadata'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] volume_api_class : nova.volume.cinder.API from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_connection_password : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:04 DEBUG nova.service [-] report_interval : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] scheduler_manager : nova.scheduler.manager.SchedulerManager from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] agent_resetnetwork_timeout : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_running_timeout : 60 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] monkey_patch_modules : ['nova.api.ec2.cloud:nova.notifier.api.notify_decorator', 'nova.compute.api:nova.notifier.api.notify_decorator'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] rpc_thread_pool_size : 64 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] update_dns_entries : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] ec2_listen_port : 8773 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] ca_file : cacert.pem from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] keys_path : /opt/stack/data/nova/keys from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vpn_image_id : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] disable_process_locking : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] fixed_range_v6 : fd00::/48 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] allowed_rpc_exception_modules : ['nova.openstack.common.exception', 'nova.exception', 'cinder.exception'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] dns_server : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] cert_topic : cert from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] allow_same_net_traffic : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_disable_agent : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] quota_floating_ips : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] fake_call : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_dns_manager : nova.network.minidns.MiniDNS from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] volume_usage_poll_interval : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] glance_host : 10.0.1.30 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xvpvncproxy_base_url : http://10.0.1.30:6081/console from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_agent_path : usr/sbin/xe-update-networking from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] aws_secret_access_key : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:04 DEBUG nova.service [-] use_ipv6 : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_base_url : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] log_format : %(asctime)s %(levelname)8s [%(name)s] %(message)s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] fake_network : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] metadata_port : 8775 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] cinder_catalog_info : volume:cinder:publicURL from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] dhcpbridge_flagfile : /etc/nova/nova.conf from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] use_cow_images : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_vhd_coalesce_poll_interval : 5.0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] dhcpbridge : /opt/stack/nova/bin/nova-dhcpbridge from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_check_host : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] ec2_workers : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] running_deleted_instance_timeout : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] network_manager : nova.network.manager.FlatDHCPManager from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] reserved_host_memory_mb : 512 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] share_dhcp_address : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_listen_port_end : 6891 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] memcached_servers : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] logging_default_format_string : %(asctime)s %(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] timeout_nbd : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] compute_driver : xenapi.XenAPIDriver from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] default_os_type : linux from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] fake_rabbit : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] log_date_format : %Y-%m-%d %H:%M:%S from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] block_device_creation_timeout : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_usage_audit : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vnc_keymap : FLAG SET  from (pid=23573) wait /opt/stack/nova/nova/service.py:180
2012-12-10 20:06:04 DEBUG nova.service [-] rescue_timeout : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] ca_path : /opt/stack/data/nova/CA from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] sr_matching_filter : default-sr:true from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_login_timeout : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vncserver_listen : 127.0.0.1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] use_syslog : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] gateway_v6 : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] osapi_compute_workers : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] osapi_path : /v1.1/ from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] syslog_log_facility : LOG_USER from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] servicegroup_driver : db from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_vhd_coalesce_max_attempts : 5 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] linuxnet_interface_driver : nova.network.linux_net.LinuxBridgeInterfaceDriver from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] bindir : /opt/stack/nova/bin from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] auth_strategy : keystone from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] defer_iptables_apply : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] config_file : ['/etc/nova/nova.conf'] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] agent_version_timeout : 300 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] network_api_class : nova.network.api.API from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] node_availability_zone : nova from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_uuid_format : [instance: %(uuid)s]  from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] db_driver : nova.db from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] create_unique_mac_address_attempts : 5 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] glance_api_insecure : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] pybasedir : /opt/stack/nova from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_max_seeder_processes_per_host : 1 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] xenapi_torrent_listen_port_start : 6881 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] osapi_compute_unique_server_name_scope :  from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] metadata_manager : nova.api.manager.MetadataManager from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] iqn_prefix : iqn.2010-10.org.openstack from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] l3_lib : nova.network.l3.LinuxNetL3 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] isolated_images : [] from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] vnc_enabled : True from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] api_paste_config : /etc/nova/api-paste.ini from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] quota_security_group_rules : 20 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] notify_on_state_change : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] network_driver : nova.network.linux_net from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] quota_instances : 10 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] notify_api_faults : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] project_cert_subject : /C=US/ST=California/O=OpenStack/OU=NovaDev/CN=project-ca-%.16s-%s from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] policy_default_rule : default from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] use_single_default_gateway : False from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] control_exchange : nova from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] cnt_vpn_clients : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] instance_build_timeout : 0 from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] log_file : None from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] compute_manager : nova.compute.manager.ComputeManager from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] network_topic : network from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 DEBUG nova.service [-] conductor : <nova.openstack.common.cfg.GroupAttr object at 0x221ea50> from (pid=23573) wait /opt/stack/nova/nova/service.py:182
2012-12-10 20:06:04 AUDIT nova.service [-] Starting compute node (version 2013.1-LOCALBRANCH:LOCALREVISION)
2012-12-10 20:06:04 INFO nova.compute.manager [req-80f1fe91-9b6d-4520-bd0a-28c20cee41ee None None] Updating host status
2012-12-10 20:06:04 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:05 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:05 DEBUG nova.manager [req-80f1fe91-9b6d-4520-bd0a-28c20cee41ee None None] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:06:05 DEBUG nova.openstack.common.rpc.amqp [req-80f1fe91-9b6d-4520-bd0a-28c20cee41ee None None] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:06:05 DEBUG nova.openstack.common.rpc.amqp [req-80f1fe91-9b6d-4520-bd0a-28c20cee41ee None None] Pool creating new connection from (pid=23573) create /opt/stack/nova/nova/openstack/common/rpc/amqp.py:58
2012-12-10 20:06:05 INFO nova.openstack.common.rpc.common [req-80f1fe91-9b6d-4520-bd0a-28c20cee41ee None None] Connected to AMQP server on 10.0.1.15:5672
2012-12-10 20:06:05 INFO nova.openstack.common.rpc.common [-] Connected to AMQP server on 10.0.1.15:5672
2012-12-10 20:06:05 DEBUG nova.service [-] Creating Consumer connection for Service compute from (pid=23573) start /opt/stack/nova/nova/service.py:410
2012-12-10 20:06:05 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:06 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:07 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:07 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2012-12-10 20:06:07 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:07 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:06:07 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:06:07 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:06:07 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
2012-12-10 20:06:07 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
2012-12-10 20:06:07 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-12-10 20:06:07 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
2012-12-10 20:06:07 DEBUG nova.service [-] Join ServiceGroup membership for this service compute from (pid=23573) start /opt/stack/nova/nova/service.py:430
2012-12-10 20:06:07 DEBUG nova.servicegroup.api [-] Join new ServiceGroup member computeDomU07 to the compute group, service = <nova.service.Service object at 0x1c60d90> from (pid=23573) join /opt/stack/nova/nova/servicegroup/api.py:72
2012-12-10 20:06:07 DEBUG nova.servicegroup.db_driver [-] DB_Driver: join new ServiceGroup member computeDomU07 to the compute group, service = <nova.service.Service object at 0x1c60d90> from (pid=23573) join /opt/stack/nova/nova/servicegroup/db_driver.py:38
2012-12-10 20:06:47 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:47 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:06:47 DEBUG nova.openstack.common.rpc.amqp [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:06:47 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:47 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:47 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:47 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:47 INFO nova.compute.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Updating bandwidth usage cache
2012-12-10 20:06:48 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Skipping ComputeManager._sync_power_states, 10 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:06:48 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:48 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:48 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:49 DEBUG nova.openstack.common.lockutils [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:06:49 AUDIT nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Auditing locally available compute resources
2012-12-10 20:06:49 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:06:50 DEBUG nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:06:50 DEBUG nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:06:50 DEBUG nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:06:50 AUDIT nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Free ram (MB): 15871
2012-12-10 20:06:50 AUDIT nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Free disk (GB): 217
2012-12-10 20:06:50 AUDIT nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Free VCPU information unavailable
2012-12-10 20:06:50 INFO nova.compute.resource_tracker [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Compute_service record updated for computeDomU07 
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Skipping ComputeManager._cleanup_running_deleted_instances, 30 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Skipping ComputeManager._run_image_cache_manager_pass, 40 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:50 DEBUG nova.compute.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:06:50 DEBUG nova.manager [req-d942b5e2-add2-440d-a31a-930003f94fb4 None None] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:19 DEBUG nova.openstack.common.rpc.amqp [-] received {u'_context_roles': [], u'_context_request_id': u'req-035a7e22-d7b5-49c1-9f2d-fbc9cc3f5f0b', u'_context_quota_class': None, u'_context_project_name': None, u'_context_service_catalog': None, u'_context_user_name': None, u'_context_auth_token': '<SANITIZED>', u'args': {}, u'_context_instance_lock_checked': False, u'_context_is_admin': True, u'version': u'2.0', u'_context_project_id': None, u'_context_timestamp': u'2012-12-10T20:07:19.539757', u'_context_read_deleted': u'no', u'_context_user_id': None, u'method': u'publish_service_capabilities', u'_context_remote_address': None} from (pid=23573) _safe_log /opt/stack/nova/nova/openstack/common/rpc/common.py:196
2012-12-10 20:07:19 DEBUG nova.openstack.common.rpc.amqp [-] unpacked context: {'project_name': None, 'user_id': None, 'roles': [], 'timestamp': u'2012-12-10T20:07:19.539757', 'auth_token': '<SANITIZED>', 'remote_address': None, 'quota_class': None, 'is_admin': True, 'service_catalog': None, 'request_id': u'req-035a7e22-d7b5-49c1-9f2d-fbc9cc3f5f0b', 'instance_lock_checked': False, 'project_id': None, 'user_name': None, 'read_deleted': u'no'} from (pid=23573) _safe_log /opt/stack/nova/nova/openstack/common/rpc/common.py:196
2012-12-10 20:07:19 DEBUG nova.manager [req-035a7e22-d7b5-49c1-9f2d-fbc9cc3f5f0b None None] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:07:19 DEBUG nova.openstack.common.rpc.amqp [req-035a7e22-d7b5-49c1-9f2d-fbc9cc3f5f0b None None] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:07:50 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 9 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:50 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:07:50 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:07:50 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2012-12-10 20:07:50 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:07:51 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:07:51 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:07:51 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:07:51 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
2012-12-10 20:07:51 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
2012-12-10 20:07:51 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-12-10 20:07:51 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
2012-12-10 20:07:51 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:51 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 29 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:07:51 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:51 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 39 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:07:51 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:51 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
2012-12-10 20:07:51 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:07:51 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:08:51 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 8 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:51 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:08:52 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:08:52 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2012-12-10 20:08:52 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:08:53 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:08:53 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:08:53 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:08:53 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
2012-12-10 20:08:53 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
2012-12-10 20:08:53 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-12-10 20:08:53 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
2012-12-10 20:08:53 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:53 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 28 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:08:53 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:53 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 38 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:08:53 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:53 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
2012-12-10 20:08:53 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:08:53 INFO nova.compute.manager [-] Updating host status
2012-12-10 20:08:53 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:08:53 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:09:53 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 7 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:53 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:09:54 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:09:54 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2012-12-10 20:09:54 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:09:55 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:09:55 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:09:55 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:09:55 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
2012-12-10 20:09:55 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
2012-12-10 20:09:55 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-12-10 20:09:55 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
2012-12-10 20:09:55 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:55 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 27 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:09:55 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:55 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 37 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:09:55 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:55 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
2012-12-10 20:09:55 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:09:55 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:14 DEBUG nova.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b', u'_context_quota_class': None, u'_context_project_name': u'demo', u'_context_service_catalog': [{u'endpoints': [{u'adminURL': u'http://10.0.1.15:8774/v2/9d5537c291404b9e9bb8450efb49b947', u'region': u'RegionOne', u'id': u'75aa8661bc314bc1b6aa8ee4ba50bdff', u'internalURL': u'http://10.0.1.15:8774/v2/9d5537c291404b9e9bb8450efb49b947', u'publicURL': u'http://10.0.1.15:8774/v2/9d5537c291404b9e9bb8450efb49b947'}], u'endpoints_links': [], u'type': u'compute', u'name': u'nova'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.15:3333', u'region': u'RegionOne', u'id': u'15d60f62d64e4130b6759fa1a5cded63', u'internalURL': u'http://10.0.1.15:3333', u'publicURL': u'http://10.0.1.15:3333'}], u'endpoints_links': [], u'type': u's3', u'name': u's3'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.15:9292', u'region': u'RegionOne', u'id': u'b86e5196a895426f90202fd7f7a82d5f', u'internalURL': u'http://10.0.1.15:9292', u'publicURL': u'http://10.0.1.15:9292'}], u'endpoints_links': [], u'type': u'image', u'name': u'glance'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.15:8776/v1/9d5537c291404b9e9bb8450efb49b947', u'region': u'RegionOne', u'id': u'6ebc1ede36544cffb60f9bfcf3bea67e', u'internalURL': u'http://10.0.1.15:8776/v1/9d5537c291404b9e9bb8450efb49b947', u'publicURL': u'http://10.0.1.15:8776/v1/9d5537c291404b9e9bb8450efb49b947'}], u'endpoints_links': [], u'type': u'volume', u'name': u'cinder'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.15:8773/services/Admin', u'region': u'RegionOne', u'id': u'97e1b772bf2e4c09ac6c29cdaa42478d', u'internalURL': u'http://10.0.1.15:8773/services/Cloud', u'publicURL': u'http://10.0.1.15:8773/services/Cloud'}], u'endpoints_links': [], u'type': u'ec2', u'name': u'ec2'}, {u'endpoints': [{u'adminURL': u'http://10.0.1.15:35357/v2.0', u'region': u'RegionOne', u'id': u'8eade3a77a0b478594c9da5a0974605c', u'internalURL': u'http://10.0.1.15:5000/v2.0', u'publicURL': u'http://10.0.1.15:5000/v2.0'}], u'endpoints_links': [], u'type': u'identity', u'name': u'keystone'}], u'_context_user_name': u'admin', u'_context_auth_token': '<SANITIZED>', u'args': {u'node': u'compute07', u'request_spec': {u'block_device_mapping': [], u'image': {u'status': u'active', u'name': u'cirros-0.3.0-x86_64-uec', u'deleted': False, u'container_format': u'ami', u'created_at': u'2012-12-07T11:45:48.000000', u'disk_format': u'ami', u'updated_at': u'2012-12-07T11:45:50.000000', u'id': u'97df9b34-16fc-45f7-9475-b6468f351b24', u'owner': u'1755af3acc9741298d50940e4ea473f0', u'min_ram': 0, u'checksum': u'2f81976cae15c16ef0010c51e3a6c163', u'min_disk': 0, u'is_public': True, u'deleted_at': None, u'properties': {u'kernel_id': u'77897fa9-5f5d-4bc0-8742-1bb2e4e44190', u'ramdisk_id': u'558feaf3-6159-4267-9e2e-cc92e9b69ba9'}, u'size': 25165824}, u'instance_type': {u'disabled': False, u'root_gb': 0, u'name': u'm1.tiny', u'flavorid': u'1', u'deleted': False, u'created_at': None, u'ephemeral_gb': 0, u'updated_at': None, u'memory_mb': 512, u'vcpus': 1, u'extra_specs': {}, u'swap': 0, u'rxtx_factor': 1.0, u'is_public': True, u'deleted_at': None, u'vcpu_weight': None, u'id': 2}, u'instance_properties': {u'vm_state': u'building', u'availability_zone': None, u'launch_index': 0, u'ephemeral_gb': 0, u'instance_type_id': 2, u'user_data': None, u'vm_mode': None, u'reservation_id': u'r-vzgc0qkj', u'root_device_name': None, u'user_id': u'aaafe2c6381c4278ad4aa7752ea1b794', u'display_description': u'fff', u'key_data': None, u'power_state': 0, u'progress': 0, u'project_id': u'9d5537c291404b9e9bb8450efb49b947', u'config_drive': u'', u'ramdisk_id': u'558feaf3-6159-4267-9e2e-cc92e9b69ba9', u'access_ip_v6': None, u'access_ip_v4': None, u'kernel_id': u'77897fa9-5f5d-4bc0-8742-1bb2e4e44190', u'key_name': None, u'display_name': u'fff', u'config_drive_id': u'', u'root_gb': 0, u'locked': False, u'launch_time': u'2012-12-10T20:10:26Z', u'memory_mb': 512, u'vcpus': 1, u'image_ref': u'97df9b34-16fc-45f7-9475-b6468f351b24', u'architecture': None, u'auto_disk_config': None, u'os_type': None, u'metadata': {}}, u'security_group': [u'default'], u'instance_uuids': [u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782']}, u'requested_networks': None, u'filter_properties': {u'config_options': {}, u'limits': {u'memory_mb': 24574.5}, u'request_spec': {u'block_device_mapping': [], u'image': {u'status': u'active', u'name': u'cirros-0.3.0-x86_64-uec', u'deleted': False, u'container_format': u'ami', u'created_at': u'2012-12-07T11:45:48.000000', u'disk_format': u'ami', u'updated_at': u'2012-12-07T11:45:50.000000', u'id': u'97df9b34-16fc-45f7-9475-b6468f351b24', u'owner': u'1755af3acc9741298d50940e4ea473f0', u'min_ram': 0, u'checksum': u'2f81976cae15c16ef0010c51e3a6c163', u'min_disk': 0, u'is_public': True, u'deleted_at': None, u'properties': {u'kernel_id': u'77897fa9-5f5d-4bc0-8742-1bb2e4e44190', u'ramdisk_id': u'558feaf3-6159-4267-9e2e-cc92e9b69ba9'}, u'size': 25165824}, u'instance_type': {u'disabled': False, u'root_gb': 0, u'name': u'm1.tiny', u'flavorid': u'1', u'deleted': False, u'created_at': None, u'ephemeral_gb': 0, u'updated_at': None, u'memory_mb': 512, u'vcpus': 1, u'extra_specs': {}, u'swap': 0, u'rxtx_factor': 1.0, u'is_public': True, u'deleted_at': None, u'vcpu_weight': None, u'id': 2}, u'instance_properties': {u'vm_state': u'building', u'availability_zone': None, u'launch_index': 0, u'ephemeral_gb': 0, u'instance_type_id': 2, u'user_data': None, u'vm_mode': None, u'reservation_id': u'r-vzgc0qkj', u'root_device_name': None, u'user_id': u'aaafe2c6381c4278ad4aa7752ea1b794', u'display_description': u'fff', u'key_data': None, u'power_state': 0, u'progress': 0, u'project_id': u'9d5537c291404b9e9bb8450efb49b947', u'config_drive': u'', u'ramdisk_id': u'558feaf3-6159-4267-9e2e-cc92e9b69ba9', u'access_ip_v6': None, u'access_ip_v4': None, u'kernel_id': u'77897fa9-5f5d-4bc0-8742-1bb2e4e44190', u'key_name': None, u'display_name': u'fff', u'config_drive_id': u'', u'root_gb': 0, u'locked': False, u'launch_time': u'2012-12-10T20:10:26Z', u'memory_mb': 512, u'vcpus': 1, u'image_ref': u'97df9b34-16fc-45f7-9475-b6468f351b24', u'architecture': None, u'auto_disk_config': None, u'os_type': None, u'metadata': {}}, u'security_group': [u'default'], u'instance_uuids': [u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782']}, u'instance_type': {u'disabled': False, u'root_gb': 0, u'name': u'm1.tiny', u'flavorid': u'1', u'deleted': False, u'created_at': None, u'ephemeral_gb': 0, u'updated_at': None, u'memory_mb': 512, u'vcpus': 1, u'extra_specs': {}, u'swap': 0, u'rxtx_factor': 1.0, u'is_public': True, u'deleted_at': None, u'vcpu_weight': None, u'id': 2}, u'retry': {u'num_attempts': 1, u'hosts': [[u'computeDomU07', u'compute07']]}, u'os_type': None, u'project_id': u'9d5537c291404b9e9bb8450efb49b947', u'scheduler_hints': {}}, u'instance': {u'vm_state': u'building', u'availability_zone': None, u'terminated_at': None, u'ephemeral_gb': 0, u'instance_type_id': 2, u'user_data': None, u'vm_mode': None, u'deleted_at': None, u'reservation_id': u'r-vzgc0qkj', u'id': 53, u'security_groups': [{u'deleted_at': None, u'user_id': u'aaafe2c6381c4278ad4aa7752ea1b794', u'name': u'default', u'deleted': False, u'created_at': u'2012-12-09T17:32:37.000000', u'updated_at': None, u'rules': [], u'project_id': u'9d5537c291404b9e9bb8450efb49b947', u'id': 1, u'description': u'default'}], u'disable_terminate': False, u'user_id': u'aaafe2c6381c4278ad4aa7752ea1b794', u'uuid': u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782', u'default_swap_device': None, u'info_cache': {u'instance_uuid': u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782', u'deleted': False, u'created_at': u'2012-12-10T20:10:26.000000', u'updated_at': None, u'network_info': u'[]', u'deleted_at': None, u'id': 53}, u'hostname': u'fff', u'launched_on': None, u'display_description': u'fff', u'key_data': None, u'kernel_id': u'77897fa9-5f5d-4bc0-8742-1bb2e4e44190', u'power_state': 0, u'default_ephemeral_device': None, u'progress': 0, u'project_id': u'9d5537c291404b9e9bb8450efb49b947', u'launched_at': None, u'scheduled_at': u'2012-12-10T20:10:13.964714', u'node': None, u'ramdisk_id': u'558feaf3-6159-4267-9e2e-cc92e9b69ba9', u'access_ip_v6': None, u'access_ip_v4': None, u'deleted': False, u'key_name': None, u'updated_at': u'2012-12-10T20:10:14.044084', u'host': None, u'extra_specs': {}, u'architecture': None, u'display_name': u'fff', u'system_metadata': [{u'instance_uuid': u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782', u'deleted': False, u'created_at': u'2012-12-10T20:10:26.000000', u'updated_at': None, u'value': u'77897fa9-5f5d-4bc0-8742-1bb2e4e44190', u'key': u'image_kernel_id', u'deleted_at': None, u'id': 157}, {u'instance_uuid': u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782', u'deleted': False, u'created_at': u'2012-12-10T20:10:26.000000', u'updated_at': None, u'value': u'558feaf3-6159-4267-9e2e-cc92e9b69ba9', u'key': u'image_ramdisk_id', u'deleted_at': None, u'id': 158}, {u'instance_uuid': u'1af2cf5c-fcb3-4a1d-ad3b-975477bb9782', u'deleted': False, u'created_at': u'2012-12-10T20:10:26.000000', u'updated_at': None, u'value': u'97df9b34-16fc-45f7-9475-b6468f351b24', u'key': u'image_base_image_ref', u'deleted_at': None, u'id': 159}], u'task_state': u'scheduling', u'shutdown_terminate': False, u'cell_name': None, u'root_gb': 0, u'locked': False, u'name': u'instance-00000035', u'created_at': u'2012-12-10T20:10:26.000000', u'launch_index': 0, u'metadata': [], u'memory_mb': 512, u'instance_type': {u'disabled': False, u'root_gb': 0, u'deleted_at': None, u'name': u'm1.tiny', u'deleted': False, u'created_at': None, u'ephemeral_gb': 0, u'updated_at': None, u'memory_mb': 512, u'vcpus': 1, u'extra_specs': [], u'swap': 0, u'rxtx_factor': 1.0, u'is_public': True, u'flavorid': u'1', u'vcpu_weight': None, u'id': 2}, u'vcpus': 1, u'image_ref': u'97df9b34-16fc-45f7-9475-b6468f351b24', u'root_device_name': None, u'auto_disk_config': None, u'os_type': None, u'config_drive': u''}, u'admin_password': '<SANITIZED>', u'injected_files': [], u'is_first_time': True}, u'_context_instance_lock_checked': False, u'_context_is_admin': True, u'version': u'2.19', u'_context_project_id': u'9d5537c291404b9e9bb8450efb49b947', u'_context_timestamp': u'2012-12-10T20:10:25.786577', u'_context_read_deleted': u'no', u'_context_user_id': u'aaafe2c6381c4278ad4aa7752ea1b794', u'method': u'run_instance', u'_context_remote_address': u'10.0.1.15'} from (pid=23573) _safe_log /opt/stack/nova/nova/openstack/common/rpc/common.py:196
2012-12-10 20:10:14 DEBUG nova.openstack.common.rpc.amqp [-] unpacked context: {'project_name': u'demo', 'user_id': u'aaafe2c6381c4278ad4aa7752ea1b794', 'roles': [u'admin'], 'timestamp': u'2012-12-10T20:10:25.786577', 'auth_token': '<SANITIZED>', 'remote_address': u'10.0.1.15', 'quota_class': None, 'is_admin': True, 'service_catalog': [{u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://10.0.1.15:8774/v2/9d5537c291404b9e9bb8450efb49b947', u'region': u'RegionOne', u'publicURL': u'http://10.0.1.15:8774/v2/9d5537c291404b9e9bb8450efb49b947', u'id': u'75aa8661bc314bc1b6aa8ee4ba50bdff', u'internalURL': u'http://10.0.1.15:8774/v2/9d5537c291404b9e9bb8450efb49b947'}], u'type': u'compute', u'name': u'nova'}, {u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://10.0.1.15:3333', u'region': u'RegionOne', u'publicURL': u'http://10.0.1.15:3333', u'id': u'15d60f62d64e4130b6759fa1a5cded63', u'internalURL': u'http://10.0.1.15:3333'}], u'type': u's3', u'name': u's3'}, {u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://10.0.1.15:9292', u'region': u'RegionOne', u'publicURL': u'http://10.0.1.15:9292', u'id': u'b86e5196a895426f90202fd7f7a82d5f', u'internalURL': u'http://10.0.1.15:9292'}], u'type': u'image', u'name': u'glance'}, {u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://10.0.1.15:8776/v1/9d5537c291404b9e9bb8450efb49b947', u'region': u'RegionOne', u'publicURL': u'http://10.0.1.15:8776/v1/9d5537c291404b9e9bb8450efb49b947', u'id': u'6ebc1ede36544cffb60f9bfcf3bea67e', u'internalURL': u'http://10.0.1.15:8776/v1/9d5537c291404b9e9bb8450efb49b947'}], u'type': u'volume', u'name': u'cinder'}, {u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://10.0.1.15:8773/services/Admin', u'region': u'RegionOne', u'publicURL': u'http://10.0.1.15:8773/services/Cloud', u'id': u'97e1b772bf2e4c09ac6c29cdaa42478d', u'internalURL': u'http://10.0.1.15:8773/services/Cloud'}], u'type': u'ec2', u'name': u'ec2'}, {u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://10.0.1.15:35357/v2.0', u'region': u'RegionOne', u'publicURL': u'http://10.0.1.15:5000/v2.0', u'id': u'8eade3a77a0b478594c9da5a0974605c', u'internalURL': u'http://10.0.1.15:5000/v2.0'}], u'type': u'identity', u'name': u'keystone'}], 'request_id': u'req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b', 'instance_lock_checked': False, 'project_id': u'9d5537c291404b9e9bb8450efb49b947', 'user_name': u'admin', 'read_deleted': u'no'} from (pid=23573) _safe_log /opt/stack/nova/nova/openstack/common/rpc/common.py:196
2012-12-10 20:10:14 DEBUG nova.openstack.common.lockutils [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Got semaphore "1af2cf5c-fcb3-4a1d-ad3b-975477bb9782" for method "do_run_instance"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:10:15 AUDIT nova.compute.manager [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] [instance: 1af2cf5c-fcb3-4a1d-ad3b-975477bb9782] Starting instance...
2012-12-10 20:10:15 DEBUG nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Making asynchronous call on conductor ... from (pid=23573) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:359
2012-12-10 20:10:15 DEBUG nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] MSG_ID is e36c8baad3ac4d86a3a82152c4c54ea5 from (pid=23573) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:362
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:10:55 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:10:55 DEBUG nova.openstack.common.rpc.amqp [-] Pool creating new connection from (pid=23573) create /opt/stack/nova/nova/openstack/common/rpc/amqp.py:58
2012-12-10 20:10:55 INFO nova.openstack.common.rpc.common [-] Connected to AMQP server on 10.0.1.15:5672
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 6 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:55 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:10:55 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:10:55 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2012-12-10 20:10:55 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:10:56 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:10:56 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:10:56 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:10:56 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
2012-12-10 20:10:56 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
2012-12-10 20:10:56 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-12-10 20:10:56 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
2012-12-10 20:10:56 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:56 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 26 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:10:56 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:56 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 36 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:10:56 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:56 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
2012-12-10 20:10:56 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:10:56 INFO nova.compute.manager [-] Updating host status
2012-12-10 20:10:56 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:10:57 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:15 ERROR nova.openstack.common.rpc.common [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Timed out waiting for RPC response: timed out
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common Traceback (most recent call last):
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in ensure
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     return method(*args, **kwargs)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in _consume
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     return self.connection.drain_events(timeout=timeout)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in drain_events
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     return self.transport.drain_events(self.connection, **kwargs)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200, in drain_events
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     return connection.drain_events(**kwargs)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50, in drain_events
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     return self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56, in wait_multi
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104, in _wait_multiple
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     channel, method_sig, args, content = self.read_timeout(timeout)
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86, in read_timeout
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     return self.method_reader.read_method()
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common timeout: timed out
2012-12-10 20:11:15 TRACE nova.openstack.common.rpc.common 
2012-12-10 20:11:15 DEBUG nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Making asynchronous call on conductor ... from (pid=23573) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:359
2012-12-10 20:11:15 DEBUG nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] MSG_ID is 5e8f05bce08543feab9897481bc55f83 from (pid=23573) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:362
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
2012-12-10 20:11:57 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 5 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:57 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:11:58 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
2012-12-10 20:11:58 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2012-12-10 20:11:58 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
2012-12-10 20:11:58 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
2012-12-10 20:11:58 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
2012-12-10 20:11:58 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
2012-12-10 20:11:58 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
2012-12-10 20:11:58 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
2012-12-10 20:11:58 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
2012-12-10 20:11:58 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
2012-12-10 20:11:58 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:58 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 25 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:11:58 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:58 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 35 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
2012-12-10 20:11:58 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:58 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
2012-12-10 20:11:58 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:11:58 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
2012-12-10 20:12:15 ERROR nova.openstack.common.rpc.common [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Timed out waiting for RPC response: timed out
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common Traceback (most recent call last):
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in ensure
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     return method(*args, **kwargs)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in _consume
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     return self.connection.drain_events(timeout=timeout)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in drain_events
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     return self.transport.drain_events(self.connection, **kwargs)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200, in drain_events
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     return connection.drain_events(**kwargs)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50, in drain_events
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     return self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56, in wait_multi
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104, in _wait_multiple
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     channel, method_sig, args, content = self.read_timeout(timeout)
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86, in read_timeout
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     return self.method_reader.read_method()
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common timeout: timed out
2012-12-10 20:12:15 TRACE nova.openstack.common.rpc.common 
ERROR:root:Original exception being dropped: ['Traceback (most recent call last):\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 606, in _run_instance\n    self._start_building(context, instance)\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 836, in _start_building\n    None))\n', '  File "/opt/stack/nova/nova/compute/manager.py", line 350, in _instance_update\n    **kwargs)\n', '  File "/opt/stack/nova/nova/conductor/api.py", line 78, in instance_update\n    updates)\n', '  File "/opt/stack/nova/nova/conductor/rpcapi.py", line 48, in instance_update\n    updates=updates_p))\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call\n    return rpc.call(context, self._get_topic(topic), msg, timeout)\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in call\n    return _get_impl().call(cfg.CONF, context, topic, msg, timeout)\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in call\n    rpc_amqp.get_connection_pool(conf, Connection))\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 376, in call\n    rv = list(rv)\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 337, in __iter__\n    self.done()\n', '  File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__\n    self.gen.next()\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 334, in __iter__\n    self._iterator.next()\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in iterconsume\n    yield self.ensure(_error_callback, _consume)\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in ensure\n    error_callback(e)\n', '  File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in _error_callback\n    raise rpc_common.Timeout()\n', 'Timeout: Timeout while waiting on RPC response.\n']
2012-12-10 20:12:15 DEBUG nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Making asynchronous call on conductor ... from (pid=23573) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:359
DEBUG:nova.openstack.common.rpc.amqp:Making asynchronous call on conductor ...
2012-12-10 20:12:15 DEBUG nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] MSG_ID is 75476f0032244de693f45843a188910c from (pid=23573) multicall /opt/stack/nova/nova/openstack/common/rpc/amqp.py:362
DEBUG:nova.openstack.common.rpc.amqp:MSG_ID is 75476f0032244de693f45843a188910c
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager.publish_service_capabilities from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager.publish_service_capabilities
2012-12-10 20:12:58 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=23573) publish_service_capabilities /opt/stack/nova/nova/manager.py:257
DEBUG:nova.manager:Notifying Schedulers of capabilities ...
2012-12-10 20:12:58 DEBUG nova.openstack.common.rpc.amqp [-] Making asynchronous fanout cast... from (pid=23573) fanout_cast /opt/stack/nova/nova/openstack/common/rpc/amqp.py:392
DEBUG:nova.openstack.common.rpc.amqp:Making asynchronous fanout cast...
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager._heal_instance_info_cache from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._heal_instance_info_cache
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_rescued_instances
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_volume_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_volume_usage
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_bandwidth_usage from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_bandwidth_usage
2012-12-10 20:12:58 DEBUG nova.manager [-] Skipping ComputeManager._sync_power_states, 4 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._sync_power_states, 4 ticks left until next run
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager._instance_usage_audit from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._instance_usage_audit
2012-12-10 20:12:58 DEBUG nova.manager [-] Running periodic task ComputeManager.update_available_resource from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager.update_available_resource
2012-12-10 20:12:58 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 20:12:59 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" for method "update_available_resource"... from (pid=23573) inner /opt/stack/nova/nova/openstack/common/lockutils.py:185
DEBUG:nova.openstack.common.lockutils:Got semaphore "compute_resources" for method "update_available_resource"...
2012-12-10 20:12:59 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
AUDIT:nova.compute.resource_tracker:Auditing locally available compute resources
2012-12-10 20:12:59 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 20:12:59 DEBUG nova.compute.resource_tracker [-] Hypervisor: free ram (MB): 12978 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:322
DEBUG:nova.compute.resource_tracker:Hypervisor: free ram (MB): 12978
2012-12-10 20:12:59 DEBUG nova.compute.resource_tracker [-] Hypervisor: free disk (GB): 184 from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:323
DEBUG:nova.compute.resource_tracker:Hypervisor: free disk (GB): 184
2012-12-10 20:12:59 DEBUG nova.compute.resource_tracker [-] Hypervisor: VCPU information unavailable from (pid=23573) _report_hypervisor_resource_view /opt/stack/nova/nova/compute/resource_tracker.py:330
DEBUG:nova.compute.resource_tracker:Hypervisor: VCPU information unavailable
2012-12-10 20:12:59 AUDIT nova.compute.resource_tracker [-] Free ram (MB): 15871
AUDIT:nova.compute.resource_tracker:Free ram (MB): 15871
2012-12-10 20:12:59 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 217
AUDIT:nova.compute.resource_tracker:Free disk (GB): 217
2012-12-10 20:12:59 AUDIT nova.compute.resource_tracker [-] Free VCPU information unavailable
AUDIT:nova.compute.resource_tracker:Free VCPU information unavailable
2012-12-10 20:13:00 INFO nova.compute.resource_tracker [-] Compute_service record updated for computeDomU07 
INFO:nova.compute.resource_tracker:Compute_service record updated for computeDomU07 
2012-12-10 20:13:00 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rebooting_instances from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_rebooting_instances
2012-12-10 20:13:00 DEBUG nova.manager [-] Skipping ComputeManager._cleanup_running_deleted_instances, 24 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._cleanup_running_deleted_instances, 24 ticks left until next run
2012-12-10 20:13:00 DEBUG nova.manager [-] Running periodic task ComputeManager._check_instance_build_time from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._check_instance_build_time
2012-12-10 20:13:00 DEBUG nova.manager [-] Skipping ComputeManager._run_image_cache_manager_pass, 34 ticks left until next run from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:167
DEBUG:nova.manager:Skipping ComputeManager._run_image_cache_manager_pass, 34 ticks left until next run
2012-12-10 20:13:00 DEBUG nova.manager [-] Running periodic task ComputeManager._reclaim_queued_deletes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._reclaim_queued_deletes
2012-12-10 20:13:00 DEBUG nova.compute.manager [-] CONF.reclaim_instance_interval <= 0, skipping... from (pid=23573) _reclaim_queued_deletes /opt/stack/nova/nova/compute/manager.py:3217
DEBUG:nova.compute.manager:CONF.reclaim_instance_interval <= 0, skipping...
2012-12-10 20:13:00 DEBUG nova.manager [-] Running periodic task ComputeManager._report_driver_status from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._report_driver_status
2012-12-10 20:13:00 INFO nova.compute.manager [-] Updating host status
INFO:nova.compute.manager:Updating host status
2012-12-10 20:13:00 DEBUG nova.virt.xenapi.host [-] Updating host stats from (pid=23573) update_status /opt/stack/nova/nova/virt/xenapi/host.py:150
DEBUG:nova.virt.xenapi.host:Updating host stats
2012-12-10 20:13:00 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_unconfirmed_resizes from (pid=23573) periodic_tasks /opt/stack/nova/nova/manager.py:172
DEBUG:nova.manager:Running periodic task ComputeManager._poll_unconfirmed_resizes
2012-12-10 20:13:15 ERROR nova.openstack.common.rpc.common [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Timed out waiting for RPC response: timed out
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common Traceback (most recent call last):
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in ensure
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return method(*args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in _consume
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.connection.drain_events(timeout=timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in drain_events
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.transport.drain_events(self.connection, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200, in drain_events
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return connection.drain_events(**kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50, in drain_events
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56, in wait_multi
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104, in _wait_multiple
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     channel, method_sig, args, content = self.read_timeout(timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86, in read_timeout
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.method_reader.read_method()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common timeout: timed out
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common 
ERROR:nova.openstack.common.rpc.common:Timed out waiting for RPC response: timed out
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common Traceback (most recent call last):
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 552, in ensure
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return method(*args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 630, in _consume
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.connection.drain_events(timeout=timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 110, in drain_events
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.transport.drain_events(self.connection, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 200, in drain_events
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return connection.drain_events(**kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 50, in drain_events
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.wait_multi(self.channels.values(), timeout=timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 56, in wait_multi
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     chanmap.keys(), allowed_methods, timeout=timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 104, in _wait_multiple
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     channel, method_sig, args, content = self.read_timeout(timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 86, in read_timeout
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     return self.method_reader.read_method()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common   File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/method_framing.py", line 221, in read_method
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common     raise m
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common timeout: timed out
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.common 
2012-12-10 20:13:15 ERROR nova.openstack.common.rpc.amqp [req-a9bd6ee3-85c7-4df1-99cc-ac0821c79e3b admin demo] Exception during message handling
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 277, in _process_data
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/dispatcher.py", line 147, in dispatch
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/exception.py", line 115, in wrapped
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     temp_level, payload)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/exception.py", line 90, in wrapped
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return f(*args, **kw)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 213, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     pass
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 199, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 240, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     kwargs['instance']['uuid'], e, sys.exc_info())
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 228, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 977, in run_instance
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     do_run_instance()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/lockutils.py", line 228, in inner
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     retval = f(*args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 976, in do_run_instance
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     admin_password, is_first_time, node, instance)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 650, in _run_instance
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self._set_instance_error_state(context, instance['uuid'])
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 362, in _set_instance_error_state
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     vm_state=vm_states.ERROR)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 350, in _instance_update
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/conductor/api.py", line 78, in instance_update
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     updates)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/conductor/rpcapi.py", line 48, in instance_update
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     updates=updates_p))
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return rpc.call(context, self._get_topic(topic), msg, timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return _get_impl().call(cfg.CONF, context, topic, msg, timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     rpc_amqp.get_connection_pool(conf, Connection))
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 376, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     rv = list(rv)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 337, in __iter__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.done()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 334, in __iter__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self._iterator.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in iterconsume
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     yield self.ensure(_error_callback, _consume)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in ensure
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     error_callback(e)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in _error_callback
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     raise rpc_common.Timeout()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp Timeout: Timeout while waiting on RPC response.
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp 
ERROR:nova.openstack.common.rpc.amqp:Exception during message handling
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 277, in _process_data
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/dispatcher.py", line 147, in dispatch
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/exception.py", line 115, in wrapped
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     temp_level, payload)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/exception.py", line 90, in wrapped
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return f(*args, **kw)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 213, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     pass
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 199, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 240, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     kwargs['instance']['uuid'], e, sys.exc_info())
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 228, in decorated_function
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 977, in run_instance
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     do_run_instance()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/lockutils.py", line 228, in inner
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     retval = f(*args, **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 976, in do_run_instance
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     admin_password, is_first_time, node, instance)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 650, in _run_instance
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self._set_instance_error_state(context, instance['uuid'])
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 362, in _set_instance_error_state
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     vm_state=vm_states.ERROR)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/compute/manager.py", line 350, in _instance_update
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     **kwargs)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/conductor/api.py", line 78, in instance_update
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     updates)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/conductor/rpcapi.py", line 48, in instance_update
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     updates=updates_p))
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/proxy.py", line 80, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return rpc.call(context, self._get_topic(topic), msg, timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/__init__.py", line 108, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     return _get_impl().call(cfg.CONF, context, topic, msg, timeout)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 754, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     rpc_amqp.get_connection_pool(conf, Connection))
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 376, in call
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     rv = list(rv)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 337, in __iter__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.done()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/amqp.py", line 334, in __iter__
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     self._iterator.next()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 635, in iterconsume
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     yield self.ensure(_error_callback, _consume)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 555, in ensure
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     error_callback(e)
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp   File "/opt/stack/nova/nova/openstack/common/rpc/impl_kombu.py", line 616, in _error_callback
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp     raise rpc_common.Timeout()
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp Timeout: Timeout while waiting on RPC response.
2012-12-10 20:13:15 TRACE nova.openstack.common.rpc.amqp 

-------------- next part --------------
A non-text attachment was scrubbed...
Name: nova-network.log
Type: application/octet-stream
Size: 49347 bytes
Desc: not available
URL: <http://lists.openstack.org/pipermail/openstack/attachments/20121210/d424b9b1/attachment.obj>


More information about the Openstack mailing list