yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #14434
[Bug 1320177] [NEW] setting instance to ERROR when failing resize
Public bug reported:
I failed to resize an instance because of migration issue and the instance was set to ERROR state.
I can see setting an ERROR state if resize failed because of EIO but if we fail resize before we started anything I think we should report the resize failure but not set the instance state to ERROR.
Before resize:
root@orange-vdsf ~(keystone_admin)]# nova list
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| 1913bc40-5b03-4b51-a445-09b656dffa03 | dafna | ACTIVE | - | Running | novanetwork=192.168.32.2 |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
After resize:
root@orange-vdsf ~(keystone_admin)]# nova list
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| 1913bc40-5b03-4b51-a445-09b656dffa03 | dafna | ERROR | - | Running | novanetwork=192.168.32.2 |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
[root@orange-vdsf ~(keystone_admin)]#
[root@orange-vdsf ~(keystone_admin)]# egrep 1913bc40-5b03-4b51-a445-09b656dffa03 /var/log/nova/*
/var/log/nova/nova-api.log:2014-05-16 13:39:20.198 32623 INFO nova.osapi_compute.wsgi.server [req-6aeece09-b623-4db4-a30e-1b5d861f197b c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1885 time: 0.0731599
/var/log/nova/nova-api.log:2014-05-16 13:39:23.065 32623 INFO nova.osapi_compute.wsgi.server [req-563db8a9-35a9-4a21-be4e-28a47791ac5e c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1902 time: 0.0700090
/var/log/nova/nova-api.log:2014-05-16 13:39:51.924 32623 INFO nova.osapi_compute.wsgi.server [req-6be8a929-37d2-470d-9402-0ba669aadb82 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1902 time: 0.0639541
/var/log/nova/nova-api.log:2014-05-16 13:39:55.894 32623 INFO nova.osapi_compute.wsgi.server [req-24130383-ced9-45c7-8838-73b746c353f3 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1902 time: 0.0686622
/var/log/nova/nova-api.log:2014-05-16 13:39:56.217 32623 INFO nova.osapi_compute.wsgi.server [req-581db5f4-b453-4b50-9641-44b14b996060 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "POST /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03/action HTTP/1.1" status: 202 len: 185 time: 0.3043129
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.668 32553 AUDIT nova.compute.manager [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Starting instance...
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Attempting claim: memory 512 MB, disk 1 GB, VCPUs 1
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Total memory: 15888 MB, used: 512.00 MB
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] memory limit: 23832.00 MB, free: 23320.00 MB
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Total disk: 59 GB, used: 0.00 GB
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] disk limit not specified, defaulting to unlimited
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Total CPUs: 4 VCPUs, used: 0.00 VCPUs
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] CPUs limit: 64.00 VCPUs, free: 64.00 VCPUs
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Claim successful
/var/log/nova/nova-compute.log:2014-05-16 13:39:19.252 32553 INFO nova.virt.libvirt.driver [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Creating image
/var/log/nova/nova-compute.log:2014-05-16 13:39:20.300 32553 INFO nova.virt.libvirt.firewall [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Called setup_basic_filtering in nwfilter
/var/log/nova/nova-compute.log:2014-05-16 13:39:20.301 32553 INFO nova.virt.libvirt.firewall [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Ensuring static filters
/var/log/nova/nova-compute.log:2014-05-16 13:39:21.236 32553 INFO nova.virt.libvirt.driver [-] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Instance spawned successfully.
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 ERROR nova.compute.manager [req-581db5f4-b453-4b50-9641-44b14b996060 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Setting instance vm_state to ERROR
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Traceback (most recent call last):
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5538, in _error_out_instance_on_exception
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] yield
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 3440, in resize_instance
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] block_device_info)
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4895, in migrate_disk_and_power_off
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] utils.execute('ssh', dest, 'mkdir', '-p', inst_base)
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/utils.py", line 164, in execute
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] return processutils.execute(*cmd, **kwargs)
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 193, in execute
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] cmd=' '.join(cmd))
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] ProcessExecutionError: Unexpected error while running command.
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Exit code: 255
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Stdout: ''
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Stderr: 'Host key verification failed.\r\n'
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03]
/var/log/nova/nova-compute.log:Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:2014-05-16 13:39:57.017 32553 TRACE oslo.messaging.rpc.dispatcher Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:2014-05-16 13:39:57.019 32553 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n incoming.message))\n', ' File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', ' File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n result = getattr(endpoint, method)(ctxt, **new_args)\n', ' File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped\n payload)\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped\n return f(self, context, *args, **kw)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 280, in decorated_function\n pass\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 266, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 333, in decorated_function\n function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 254, in decorated_function\n break\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 235, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 309, in decorated_function\n e, sys.exc_info())\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 296, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 3440, in resize_instance\n block_device_info)\n', ' File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4895, in migrate_disk_and_power_off\n utils.execute(\'ssh\', dest, \'mkdir\', \'-p\', inst_base)\n', ' File "/usr/lib/python2.7/site-packages/nova/utils.py", line 164, in execute\n return processutils.execute(*cmd, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 193, in execute\n cmd=\' \'.join(cmd))\n', "ProcessExecutionError: Unexpected error while running command.\nCommand: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03\nExit code: 255\nStdout: ''\nStderr: 'Host key verification failed.\\r\\n'\n"]
/var/log/nova/nova-compute.log:2014-05-16 13:40:54.133 32553 WARNING nova.compute.resource_tracker [-] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Instance not resizing, skipping migration.
/var/log/nova/nova-scheduler.log:2014-05-16 13:39:18.563 32599 INFO nova.scheduler.filter_scheduler [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] Attempting to build 1 instance(s) uuids: [u'1913bc40-5b03-4b51-a445-09b656dffa03']
/var/log/nova/nova-scheduler.log:2014-05-16 13:39:18.580 32599 INFO nova.scheduler.filter_scheduler [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] Choosing host WeighedHost [host: orange-vdsf.qa.lab.tlv.redhat.com, weight: 1.0] for instance 1913bc40-5b03-4b51-a445-09b656dffa03
** Affects: nova
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1320177
Title:
setting instance to ERROR when failing resize
Status in OpenStack Compute (Nova):
New
Bug description:
I failed to resize an instance because of migration issue and the instance was set to ERROR state.
I can see setting an ERROR state if resize failed because of EIO but if we fail resize before we started anything I think we should report the resize failure but not set the instance state to ERROR.
Before resize:
root@orange-vdsf ~(keystone_admin)]# nova list
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| 1913bc40-5b03-4b51-a445-09b656dffa03 | dafna | ACTIVE | - | Running | novanetwork=192.168.32.2 |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
After resize:
root@orange-vdsf ~(keystone_admin)]# nova list
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| ID | Name | Status | Task State | Power State | Networks |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
| 1913bc40-5b03-4b51-a445-09b656dffa03 | dafna | ERROR | - | Running | novanetwork=192.168.32.2 |
+--------------------------------------+-------+--------+------------+-------------+--------------------------+
[root@orange-vdsf ~(keystone_admin)]#
[root@orange-vdsf ~(keystone_admin)]# egrep 1913bc40-5b03-4b51-a445-09b656dffa03 /var/log/nova/*
/var/log/nova/nova-api.log:2014-05-16 13:39:20.198 32623 INFO nova.osapi_compute.wsgi.server [req-6aeece09-b623-4db4-a30e-1b5d861f197b c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1885 time: 0.0731599
/var/log/nova/nova-api.log:2014-05-16 13:39:23.065 32623 INFO nova.osapi_compute.wsgi.server [req-563db8a9-35a9-4a21-be4e-28a47791ac5e c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1902 time: 0.0700090
/var/log/nova/nova-api.log:2014-05-16 13:39:51.924 32623 INFO nova.osapi_compute.wsgi.server [req-6be8a929-37d2-470d-9402-0ba669aadb82 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1902 time: 0.0639541
/var/log/nova/nova-api.log:2014-05-16 13:39:55.894 32623 INFO nova.osapi_compute.wsgi.server [req-24130383-ced9-45c7-8838-73b746c353f3 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "GET /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03 HTTP/1.1" status: 200 len: 1902 time: 0.0686622
/var/log/nova/nova-api.log:2014-05-16 13:39:56.217 32623 INFO nova.osapi_compute.wsgi.server [req-581db5f4-b453-4b50-9641-44b14b996060 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] 10.35.160.73 "POST /v2/4ad766166539403189f2caca1ba306aa/servers/1913bc40-5b03-4b51-a445-09b656dffa03/action HTTP/1.1" status: 202 len: 185 time: 0.3043129
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.668 32553 AUDIT nova.compute.manager [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Starting instance...
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Attempting claim: memory 512 MB, disk 1 GB, VCPUs 1
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Total memory: 15888 MB, used: 512.00 MB
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] memory limit: 23832.00 MB, free: 23320.00 MB
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.751 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Total disk: 59 GB, used: 0.00 GB
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] disk limit not specified, defaulting to unlimited
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Total CPUs: 4 VCPUs, used: 0.00 VCPUs
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] CPUs limit: 64.00 VCPUs, free: 64.00 VCPUs
/var/log/nova/nova-compute.log:2014-05-16 13:39:18.752 32553 AUDIT nova.compute.claims [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Claim successful
/var/log/nova/nova-compute.log:2014-05-16 13:39:19.252 32553 INFO nova.virt.libvirt.driver [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Creating image
/var/log/nova/nova-compute.log:2014-05-16 13:39:20.300 32553 INFO nova.virt.libvirt.firewall [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Called setup_basic_filtering in nwfilter
/var/log/nova/nova-compute.log:2014-05-16 13:39:20.301 32553 INFO nova.virt.libvirt.firewall [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Ensuring static filters
/var/log/nova/nova-compute.log:2014-05-16 13:39:21.236 32553 INFO nova.virt.libvirt.driver [-] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Instance spawned successfully.
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 ERROR nova.compute.manager [req-581db5f4-b453-4b50-9641-44b14b996060 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Setting instance vm_state to ERROR
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Traceback (most recent call last):
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5538, in _error_out_instance_on_exception
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] yield
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 3440, in resize_instance
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] block_device_info)
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4895, in migrate_disk_and_power_off
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] utils.execute('ssh', dest, 'mkdir', '-p', inst_base)
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/utils.py", line 164, in execute
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] return processutils.execute(*cmd, **kwargs)
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 193, in execute
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] cmd=' '.join(cmd))
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] ProcessExecutionError: Unexpected error while running command.
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Exit code: 255
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Stdout: ''
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Stderr: 'Host key verification failed.\r\n'
/var/log/nova/nova-compute.log:2014-05-16 13:39:56.770 32553 TRACE nova.compute.manager [instance: 1913bc40-5b03-4b51-a445-09b656dffa03]
/var/log/nova/nova-compute.log:Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:2014-05-16 13:39:57.017 32553 TRACE oslo.messaging.rpc.dispatcher Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:Command: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03
/var/log/nova/nova-compute.log:2014-05-16 13:39:57.019 32553 ERROR oslo.messaging._drivers.common [-] ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n incoming.message))\n', ' File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', ' File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n result = getattr(endpoint, method)(ctxt, **new_args)\n', ' File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped\n payload)\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped\n return f(self, context, *args, **kw)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 280, in decorated_function\n pass\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 266, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 333, in decorated_function\n function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 254, in decorated_function\n break\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 235, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 309, in decorated_function\n e, sys.exc_info())\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 296, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 3440, in resize_instance\n block_device_info)\n', ' File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4895, in migrate_disk_and_power_off\n utils.execute(\'ssh\', dest, \'mkdir\', \'-p\', inst_base)\n', ' File "/usr/lib/python2.7/site-packages/nova/utils.py", line 164, in execute\n return processutils.execute(*cmd, **kwargs)\n', ' File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 193, in execute\n cmd=\' \'.join(cmd))\n', "ProcessExecutionError: Unexpected error while running command.\nCommand: ssh 10.35.104.16 mkdir -p /var/lib/nova/instances/1913bc40-5b03-4b51-a445-09b656dffa03\nExit code: 255\nStdout: ''\nStderr: 'Host key verification failed.\\r\\n'\n"]
/var/log/nova/nova-compute.log:2014-05-16 13:40:54.133 32553 WARNING nova.compute.resource_tracker [-] [instance: 1913bc40-5b03-4b51-a445-09b656dffa03] Instance not resizing, skipping migration.
/var/log/nova/nova-scheduler.log:2014-05-16 13:39:18.563 32599 INFO nova.scheduler.filter_scheduler [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] Attempting to build 1 instance(s) uuids: [u'1913bc40-5b03-4b51-a445-09b656dffa03']
/var/log/nova/nova-scheduler.log:2014-05-16 13:39:18.580 32599 INFO nova.scheduler.filter_scheduler [req-41d02e07-ff88-4abd-a035-fdecf0671a67 c9062d562d9f41e4a1fdce36a4f176f6 4ad766166539403189f2caca1ba306aa] Choosing host WeighedHost [host: orange-vdsf.qa.lab.tlv.redhat.com, weight: 1.0] for instance 1913bc40-5b03-4b51-a445-09b656dffa03
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1320177/+subscriptions
Follow ups
References
