"Requested operation is not valid: domain is not running" (REBUILD)

[Wallace Cardoso]

I'm not sure if I can do these steps in practice, but I could perform the following steps in the system, and I got the an error.

DevStack branch=stable/rocky.

1. ./unstack.sh && ./clean.sh && ./stack.sh
2. source openrc admin admin
3. openstack flavor create --ram 21 --disk 0 --vcpus 1 custom
4. openstack server create --flavor custom --image cirros-0.3.5-x85_64-disk --flavor custom test
5. openstack server show test

+-------------------------------------+-----------------------------------------------------------------+
| Field | Value |
+-------------------------------------+-----------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | wallacec-ubuntu |
| OS-EXT-SRV-ATTR:hypervisor_hostname | wallacec-ubuntu |
| OS-EXT-SRV-ATTR:instance_name | instance-00000004 |
| OS-EXT-STS:power_state | Paused |
| OS-EXT-STS:task_state | None |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2019-01-24T23:13:07.000000 |
| OS-SRV-USG:terminated_at | None |
| accessIPv4 | |
| accessIPv6 | |
| addresses | public=2001:db8::d, 192.168.1.228 |
| config_drive | |
| created | 2019-01-24T23:13:01Z |
| flavor | custom (ac9f385c-efaa-4b93-acec-8184beb53ca3) |
| hostId | d99cb6d42c024008ba7f954f95a59d73313aebf95098e30ccb7f10f0 |
| id | e7825018-5fd7-4377-a6c1-cf36c269d849 |
| image | cirros-0.3.5-x86_64-disk (3739ba2a-34ab-4bcd-8fd3-70a186131e54) |
| key_name | None |
| name | test |
| progress | 0 |
| project_id | 6a0880f1c0b946acb71d61af9a92900b |
| properties | |
| security_groups | name='default' |
| status | ACTIVE |
| updated | 2019-01-24T23:13:08Z |
| user_id | 7c9be80e945f4333ad34d11f64643f51 |
| volumes_attached | |
+-------------------------------------+-----------------------------------------------------------------+

6. openstack server rebuild test
7. openstack server list

+--------------------------------------+------+--------+-----------------------------------+--------------------------+--------+
| ID | Name | Status | Networks | Image | Flavor |
+--------------------------------------+------+--------+-----------------------------------+--------------------------+--------+
| e7825018-5fd7-4377-a6c1-cf36c269d849 | test | ERROR | public=2001:db8::d, 192.168.1.228 | cirros-0.3.5-x86_64-disk | custom |
+--------------------------------------+------+--------+-----------------------------------+--------------------------+--------+

Logs:

Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 186, in doit
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m result = proxy_call(self._autowrap, f, *args, **kwargs)
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 144, in proxy_call
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m rv = execute(f, *args, **kwargs)
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 125, in execute
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m six.reraise(c, e, tb)
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 83, in tworker
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m rv = meth(*args, **kwargs)
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m File "/usr/local/lib/python2.7/dist-packages/libvirt.py", line 2454, in shutdown
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m if ret == -1: raise libvirtError ('virDomainShutdown() failed', dom=self)
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00mlibvirtError: Requested operation is not valid: domain is not running
Jan 24 21:15:03 wallacec-ubuntu nova-compute[24652]: ERROR oslo_messaging.rpc.server #033[01;35m#033[00m#033[00m
Jan 24 21:15:04 wallacec-ubuntu dstat.sh[10952]: 24-01 21:15:04| 18 2 78 1 0 0|7065M 29.0M 604M 184M| 0 0 | 0 520k| 0 34.0 |2664 6736 |2.15 2.03 1.96|3.0 0 0| 0 0 |cinder-volume 132574.8% 0 0 |dstat 10953 88k 375B0.5%|java 687M|3571M 244M| 33 361 1 64 1
Jan 24 21:15:05 wallacec-ubuntu neutron-openvswitch-agent[11404]: #033[00;32mDEBUG neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [#033[01;36mNone req-593d6fce-8410-47dc-9b3e-007cb815e113 #033[00;36mNone None#033[00;32m] #033[01;35m#033[00;32mAgent rpc_loop - iteration:7664 started#033[00m #033[00;33m{{(pid=11404) rpc_loop /opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py:2090}}#033[00m#033[00m
Jan 24 21:15:05 wallacec-ubuntu neutron-openvswitch-agent[11404]: #033[00;32mDEBUG neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [#033[01;36mNone req-593d6fce-8410-47dc-9b3e-007cb815e113 #033[00;36mNone None#033[00;32m] #033[01;35m#033[00;32mofctl request version=0x4,msg_type=0x12,msg_len=0x38,xid=0x81a99048,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) result [OFPFlowStatsReply(body=[OFPFlowStats(byte_count=0,cookie=3209422424581828967,duration_nsec=404000000,duration_sec=15338,flags=0,hard_timeout=0,idle_timeout=0,instructions=[],length=56,match=OFPMatch(oxm_fields={}),packet_count=0,priority=0,table_id=23)],flags=0,type=1)]#033[00m #033[00;33m{{(pid=11404) _send_msg /opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py:114}}#033[00m#033[00m
Jan 24 21:15:05 wallacec-ubuntu neutron-openvswitch-agent[11404]: #033[00;32mDEBUG neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [#033[01;36mNone req-593d6fce-8410-47dc-9b3e-007cb815e113 #033[00;36mNone None#033[00;32m] #033[01;35m#033[00;32mAgent rpc_loop - iteration:7664 completed. Processed ports statistics: {'regular': {'updated': 0, 'added': 0, 'removed': 0}}. Elapsed:0.009#033[00m #033[00;33m{{(pid=11404) loop_count_and_wait /opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py:1875}}#033[00m#033[00m
Jan 24 21:15:05 wallacec-ubuntu dstat.sh[10952]: 24-01 21:15:05| 16 6 78 0 0 0|7065M 29.1M 606M 183M| 536B 0 |4096B 152k|1.00 9.00 |2738 6627 |2.15 2.03 1.96|2.0 0 2.0| 0 0 |cinder-volume 132575.2% 0 0 |dstat 10953 88k 379B0.2%|java 687M|3571M 244M| 33 361 1 64 1
Jan 24 21:15:06 wallacec-ubuntu dstat.sh[10952]: 24-01 21:15:06| 19 3 78 0 0 0|7065M 29.1M 606M 182M| 731B 338B|4096B 48k|1.00 6.00 |2674 6177 |2.15 2.03 1.96|4.0 1.0 0|4096B 0 |cinder-volume 132576.2% 0 0 |dstat 10953 86k 381B0.8%|java 687M|3571M 244M| 33 361 1 55 1
Jan 24 21:15:07 wallacec-ubuntu neutron-openvswitch-agent[11404]: #033[00;32mDEBUG neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [#033[01;36mNone req-593d6fce-8410-47dc-9b3e-007cb815e113 #033[00;36mNone None#033[00;32m] #033[01;35m#033[00;32mAgent rpc_loop - iteration:7665 started#033[00m #033[00;33m{{(pid=11404) rpc_loop /opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py:2090}}#033[00m#033[00m
Jan 24 21:15:07 wallacec-ubuntu neutron-openvswitch-agent[11404]: #033[00;32mDEBUG neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [#033[01;36mNone req-593d6fce-8410-47dc-9b3e-007cb815e113 #033[00;36mNone None#033[00;32m] #033[01;35m#033[00;32mofctl request version=0x4,msg_type=0x12,msg_len=0x38,xid=0x81a9904a,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) result [OFPFlowStatsReply(body=[OFPFlowStats(byte_count=0,cookie=3209422424581828967,duration_nsec=407000000,duration_sec=15340,flags=0,hard_timeout=0,idle_timeout=0,instructions=[],length=56,match=OFPMatch(oxm_fields={}),packet_count=0,priority=0,table_id=23)],flags=0,type=1)]#033[00m #033[00;33m{{(pid=11404) _send_msg /opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py:114}}#033[00m#033[00m
Jan 24 21:15:07 wallacec-ubuntu neutron-openvswitch-agent[11404]: #033[00;32mDEBUG neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [#033[01;36mNone req-593d6fce-8410-47dc-9b3e-007cb815e113 #033[00;36mNone None#033[00;32m] #033[01;35m#033[00;32mAgent rpc_loop - iteration:7665 completed. Processed ports statistics: {'regular': {'updated': 0, 'added': 0, 'removed': 0}}. Elapsed:0.011#033[00m #033[00;33m{{(pid=11404) loop_count_and_wait /opt/stack/neutron/neutron/plugins/ml2/drivers/openvswitch/agent/ovs_neutron_agent.py:1875}}#033[00m#033[00m

[Balazs Gibizer (balazs-gibizer)]

I think you instance did not reached the active power state before you hit rebuild.

If I create and instance then pause it and then I try to rebuild it then I nova api rejectes the operation with HTTP 409:

Cannot 'rebuild' instance 6b6d6775-064a-455a-9c69-a57b5e67c77b while it is in vm_state paused (HTTP 409) (Request-ID: req-aa9b8256-999e-4038-afd2-70291e583326

The difference is that in your case the vm_state is active and the power_state is paused while in my case the vm_state is paused too.

Nova only checks for the vm_state in the compute/api [1] but it seems in the rebuild case we need to check for the power state as well.

[1]https://github.com/openstack/nova/blob/a628d2f09a42a0faa5fcb36793e2304de634638e/nova/compute/api.py#L3151