| 2018-04-04 15:02:12 |
praveenraj |
bug |
|
|
added bug |
| 2018-04-04 18:03:19 |
praveenraj |
description |
Unable to launch instance after installing sfc and enabling OVS driver. The instance can be launcher without enabling the OVS driver.
ovs version:
ovs-ofctl (Open vSwitch) 2.6.1
OpenFlow versions 0x1:0x4
Following error is seen in nova-compute.log
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1938, in _build_and_run_instance
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] block_device_info=block_device_info)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2759, in spawn
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] destroy_disks_on_failure=True)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5204, in _create_domain_and_network
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] raise exception.VirtualInterfaceCreateException()
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b]
2018-04-04 07:50:44.325 1613 WARNING nova.image.glance [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] No protocol specified in for api_server 'http://10.66.247.62:9292', please update [glance] api_servers with fully qualified url including scheme (http / https)
2018-04-04 07:50:44.326 1613 DEBUG nova.compute.utils [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Virtual Interface creation failed notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:317
2018-04-04 07:50:44.330 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: 13fd8143568e47668c62340641624599 NOTIFY exchange 'nova' topic 'notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.347 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: aa3c3bf078154a7892f0296c6e5561d0 NOTIFY exchange 'nova' topic 'versioned_notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1788, in _do_build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] filter_properties)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1998, in _build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] reason=msg)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] BuildAbortException: Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
Following error is found in /var/log/neutron/openvswitch-agent.log
2018-01-02 09:19:25.593 1642 ERROR neutron.agent.linux.async_process [-] Error received from [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json]: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:25.614 1642 ERROR neutron.agent.linux.async_process [-] Process [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json] dies due to the error: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:38.115 1642 ERROR oslo.messaging._drivers.impl_rabbit [-] [e1c7a23d-f3ad-432c-b2ad-60c416e4fcad] AMQP server on 10.66.247.62:5672 is unreachable: [Errno 32] Broken pipe. Trying again in 1 seconds. Client port: None
2018-01-02 09:19:38.671 1642 ERROR OfctlService [-] unknown dpid 266822661720900
2018-01-02 09:19:38.754 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] Failed to communicate with the switch
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int Traceback (most recent call last):
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/br_int.py", line 52, in check_canary_table
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int flows = self.dump_flows(constants.CANARY_TABLE)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 131, in dump_flows
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int reply_multi=True)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 79, in _send_msg
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int raise RuntimeError(m)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int RuntimeError: ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int
2018-01-02 09:19:38.874 1642 WARNING neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] OVS is dead. OVSNeutronAgent will keep running and checking OVS status periodically. |
Unable to launch instance after installing sfc and enabling OVS driver. The instance can be launched smoothly by disabling OVS driver.
The error drops down to be "Failed to allocate the network(s), not rescheduling"
Here are some links where it talk similar kind of issue I am facing with:
http://openstack.10931.n7.nabble.com/Neutron-Issues-td134182.html#a134186
https://ask.openstack.org/en/question/54531/failed-to-allocate-the-networks-not-rescheduling/
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c0
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c2
Below is the OVS version I am using
ovs version:
ovs-ofctl (Open vSwitch) 2.6.1
OpenFlow versions 0x1:0x4
Following error is seen in nova-compute.log
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1938, in _build_and_run_instance
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] block_device_info=block_device_info)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2759, in spawn
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] destroy_disks_on_failure=True)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5204, in _create_domain_and_network
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] raise exception.VirtualInterfaceCreateException()
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b]
2018-04-04 07:50:44.325 1613 WARNING nova.image.glance [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] No protocol specified in for api_server 'http://10.66.247.62:9292', please update [glance] api_servers with fully qualified url including scheme (http / https)
2018-04-04 07:50:44.326 1613 DEBUG nova.compute.utils [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Virtual Interface creation failed notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:317
2018-04-04 07:50:44.330 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: 13fd8143568e47668c62340641624599 NOTIFY exchange 'nova' topic 'notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.347 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: aa3c3bf078154a7892f0296c6e5561d0 NOTIFY exchange 'nova' topic 'versioned_notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1788, in _do_build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] filter_properties)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1998, in _build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] reason=msg)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] BuildAbortException: Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
Following error is found in /var/log/neutron/openvswitch-agent.log
2018-01-02 09:19:25.593 1642 ERROR neutron.agent.linux.async_process [-] Error received from [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json]: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:25.614 1642 ERROR neutron.agent.linux.async_process [-] Process [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json] dies due to the error: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:38.115 1642 ERROR oslo.messaging._drivers.impl_rabbit [-] [e1c7a23d-f3ad-432c-b2ad-60c416e4fcad] AMQP server on 10.66.247.62:5672 is unreachable: [Errno 32] Broken pipe. Trying again in 1 seconds. Client port: None
2018-01-02 09:19:38.671 1642 ERROR OfctlService [-] unknown dpid 266822661720900
2018-01-02 09:19:38.754 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] Failed to communicate with the switch
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int Traceback (most recent call last):
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/br_int.py", line 52, in check_canary_table
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int flows = self.dump_flows(constants.CANARY_TABLE)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 131, in dump_flows
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int reply_multi=True)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 79, in _send_msg
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int raise RuntimeError(m)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int RuntimeError: ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int
2018-01-02 09:19:38.874 1642 WARNING neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] OVS is dead. OVSNeutronAgent will keep running and checking OVS status periodically. |
|
| 2018-04-04 18:03:49 |
praveenraj |
summary |
Unable to launch instance after installing sfc |
Unable to launch instance after installing SFC with OVS driver |
|
| 2018-04-04 18:05:41 |
praveenraj |
description |
Unable to launch instance after installing sfc and enabling OVS driver. The instance can be launched smoothly by disabling OVS driver.
The error drops down to be "Failed to allocate the network(s), not rescheduling"
Here are some links where it talk similar kind of issue I am facing with:
http://openstack.10931.n7.nabble.com/Neutron-Issues-td134182.html#a134186
https://ask.openstack.org/en/question/54531/failed-to-allocate-the-networks-not-rescheduling/
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c0
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c2
Below is the OVS version I am using
ovs version:
ovs-ofctl (Open vSwitch) 2.6.1
OpenFlow versions 0x1:0x4
Following error is seen in nova-compute.log
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1938, in _build_and_run_instance
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] block_device_info=block_device_info)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2759, in spawn
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] destroy_disks_on_failure=True)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5204, in _create_domain_and_network
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] raise exception.VirtualInterfaceCreateException()
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b]
2018-04-04 07:50:44.325 1613 WARNING nova.image.glance [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] No protocol specified in for api_server 'http://10.66.247.62:9292', please update [glance] api_servers with fully qualified url including scheme (http / https)
2018-04-04 07:50:44.326 1613 DEBUG nova.compute.utils [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Virtual Interface creation failed notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:317
2018-04-04 07:50:44.330 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: 13fd8143568e47668c62340641624599 NOTIFY exchange 'nova' topic 'notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.347 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: aa3c3bf078154a7892f0296c6e5561d0 NOTIFY exchange 'nova' topic 'versioned_notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1788, in _do_build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] filter_properties)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1998, in _build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] reason=msg)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] BuildAbortException: Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
Following error is found in /var/log/neutron/openvswitch-agent.log
2018-01-02 09:19:25.593 1642 ERROR neutron.agent.linux.async_process [-] Error received from [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json]: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:25.614 1642 ERROR neutron.agent.linux.async_process [-] Process [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json] dies due to the error: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:38.115 1642 ERROR oslo.messaging._drivers.impl_rabbit [-] [e1c7a23d-f3ad-432c-b2ad-60c416e4fcad] AMQP server on 10.66.247.62:5672 is unreachable: [Errno 32] Broken pipe. Trying again in 1 seconds. Client port: None
2018-01-02 09:19:38.671 1642 ERROR OfctlService [-] unknown dpid 266822661720900
2018-01-02 09:19:38.754 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] Failed to communicate with the switch
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int Traceback (most recent call last):
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/br_int.py", line 52, in check_canary_table
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int flows = self.dump_flows(constants.CANARY_TABLE)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 131, in dump_flows
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int reply_multi=True)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 79, in _send_msg
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int raise RuntimeError(m)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int RuntimeError: ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int
2018-01-02 09:19:38.874 1642 WARNING neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] OVS is dead. OVSNeutronAgent will keep running and checking OVS status periodically. |
Unable to launch instance after installing neutron sfc on OpenStack (Ocata) compute node and enabling OVS driver. The instance can be launched smoothly by disabling OVS driver.
The error drops down to be "Failed to allocate the network(s), not rescheduling"
Here are some links where it talk similar kind of issue I am facing with:
http://openstack.10931.n7.nabble.com/Neutron-Issues-td134182.html#a134186
https://ask.openstack.org/en/question/54531/failed-to-allocate-the-networks-not-rescheduling/
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c0
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c2
Below is the OVS version I am using
ovs version:
ovs-ofctl (Open vSwitch) 2.6.1
OpenFlow versions 0x1:0x4
Following error is seen in nova-compute.log
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1938, in _build_and_run_instance
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] block_device_info=block_device_info)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2759, in spawn
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] destroy_disks_on_failure=True)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5204, in _create_domain_and_network
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] raise exception.VirtualInterfaceCreateException()
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b]
2018-04-04 07:50:44.325 1613 WARNING nova.image.glance [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] No protocol specified in for api_server 'http://10.66.247.62:9292', please update [glance] api_servers with fully qualified url including scheme (http / https)
2018-04-04 07:50:44.326 1613 DEBUG nova.compute.utils [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Virtual Interface creation failed notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:317
2018-04-04 07:50:44.330 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: 13fd8143568e47668c62340641624599 NOTIFY exchange 'nova' topic 'notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.347 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: aa3c3bf078154a7892f0296c6e5561d0 NOTIFY exchange 'nova' topic 'versioned_notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1788, in _do_build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] filter_properties)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1998, in _build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] reason=msg)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] BuildAbortException: Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
Following error is found in /var/log/neutron/openvswitch-agent.log
2018-01-02 09:19:25.593 1642 ERROR neutron.agent.linux.async_process [-] Error received from [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json]: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:25.614 1642 ERROR neutron.agent.linux.async_process [-] Process [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json] dies due to the error: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:38.115 1642 ERROR oslo.messaging._drivers.impl_rabbit [-] [e1c7a23d-f3ad-432c-b2ad-60c416e4fcad] AMQP server on 10.66.247.62:5672 is unreachable: [Errno 32] Broken pipe. Trying again in 1 seconds. Client port: None
2018-01-02 09:19:38.671 1642 ERROR OfctlService [-] unknown dpid 266822661720900
2018-01-02 09:19:38.754 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] Failed to communicate with the switch
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int Traceback (most recent call last):
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/br_int.py", line 52, in check_canary_table
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int flows = self.dump_flows(constants.CANARY_TABLE)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 131, in dump_flows
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int reply_multi=True)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 79, in _send_msg
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int raise RuntimeError(m)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int RuntimeError: ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int
2018-01-02 09:19:38.874 1642 WARNING neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] OVS is dead. OVSNeutronAgent will keep running and checking OVS status periodically. |
|
| 2018-04-04 18:07:22 |
praveenraj |
description |
Unable to launch instance after installing neutron sfc on OpenStack (Ocata) compute node and enabling OVS driver. The instance can be launched smoothly by disabling OVS driver.
The error drops down to be "Failed to allocate the network(s), not rescheduling"
Here are some links where it talk similar kind of issue I am facing with:
http://openstack.10931.n7.nabble.com/Neutron-Issues-td134182.html#a134186
https://ask.openstack.org/en/question/54531/failed-to-allocate-the-networks-not-rescheduling/
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c0
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c2
Below is the OVS version I am using
ovs version:
ovs-ofctl (Open vSwitch) 2.6.1
OpenFlow versions 0x1:0x4
Following error is seen in nova-compute.log
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1938, in _build_and_run_instance
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] block_device_info=block_device_info)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2759, in spawn
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] destroy_disks_on_failure=True)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5204, in _create_domain_and_network
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] raise exception.VirtualInterfaceCreateException()
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b]
2018-04-04 07:50:44.325 1613 WARNING nova.image.glance [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] No protocol specified in for api_server 'http://10.66.247.62:9292', please update [glance] api_servers with fully qualified url including scheme (http / https)
2018-04-04 07:50:44.326 1613 DEBUG nova.compute.utils [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Virtual Interface creation failed notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:317
2018-04-04 07:50:44.330 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: 13fd8143568e47668c62340641624599 NOTIFY exchange 'nova' topic 'notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.347 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: aa3c3bf078154a7892f0296c6e5561d0 NOTIFY exchange 'nova' topic 'versioned_notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1788, in _do_build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] filter_properties)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1998, in _build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] reason=msg)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] BuildAbortException: Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
Following error is found in /var/log/neutron/openvswitch-agent.log
2018-01-02 09:19:25.593 1642 ERROR neutron.agent.linux.async_process [-] Error received from [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json]: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:25.614 1642 ERROR neutron.agent.linux.async_process [-] Process [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json] dies due to the error: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:38.115 1642 ERROR oslo.messaging._drivers.impl_rabbit [-] [e1c7a23d-f3ad-432c-b2ad-60c416e4fcad] AMQP server on 10.66.247.62:5672 is unreachable: [Errno 32] Broken pipe. Trying again in 1 seconds. Client port: None
2018-01-02 09:19:38.671 1642 ERROR OfctlService [-] unknown dpid 266822661720900
2018-01-02 09:19:38.754 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] Failed to communicate with the switch
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int Traceback (most recent call last):
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/br_int.py", line 52, in check_canary_table
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int flows = self.dump_flows(constants.CANARY_TABLE)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 131, in dump_flows
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int reply_multi=True)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 79, in _send_msg
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int raise RuntimeError(m)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int RuntimeError: ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int
2018-01-02 09:19:38.874 1642 WARNING neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] OVS is dead. OVSNeutronAgent will keep running and checking OVS status periodically. |
Unable to launch instance after installing neutron sfc on OpenStack (Ocata) compute node and enabling OVS driver. The instance can be launched smoothly by disabling OVS driver.
The error drops down to be "Failed to allocate the network(s), not rescheduling"
Here are some links, where similar kind of issue have been discussed: http://openstack.10931.n7.nabble.com/Neutron-Issues-td134182.html#a134186
https://ask.openstack.org/en/question/54531/failed-to-allocate-the-networks-not-rescheduling/
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c0
https://bugzilla.redhat.com/show_bug.cgi?id=1491628#c2
Below is the OVS version I am using
ovs version:
ovs-ofctl (Open vSwitch) 2.6.1
OpenFlow versions 0x1:0x4
Following error is seen in nova-compute.log
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1938, in _build_and_run_instance
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] block_device_info=block_device_info)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2759, in spawn
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] destroy_disks_on_failure=True)
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 5204, in _create_domain_and_network
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] raise exception.VirtualInterfaceCreateException()
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] VirtualInterfaceCreateException: Virtual Interface creation failed
2018-04-04 07:50:44.323 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b]
2018-04-04 07:50:44.325 1613 WARNING nova.image.glance [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] No protocol specified in for api_server 'http://10.66.247.62:9292', please update [glance] api_servers with fully qualified url including scheme (http / https)
2018-04-04 07:50:44.326 1613 DEBUG nova.compute.utils [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Virtual Interface creation failed notify_about_instance_usage /usr/lib/python2.7/site-packages/nova/compute/utils.py:317
2018-04-04 07:50:44.330 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: 13fd8143568e47668c62340641624599 NOTIFY exchange 'nova' topic 'notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.347 1613 DEBUG oslo_messaging._drivers.amqpdriver [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] CAST unique_id: aa3c3bf078154a7892f0296c6e5561d0 NOTIFY exchange 'nova' topic 'versioned_notifications.error' _send /usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py:534
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [req-e7973a9a-f541-4a20-b1c3-e9d8416412b8 dd726096fff84ff2b57f2ccb30cdb66b fe138f2c8b7d485790eb07242ea88f93 - - -] [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] Traceback (most recent call last):
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1788, in _do_build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] filter_properties)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 1998, in _build_and_run_instance
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] reason=msg)
2018-04-04 07:50:44.353 1613 ERROR nova.compute.manager [instance: d9b4c625-333c-4071-8e20-b50861c73a5b] BuildAbortException: Build of instance d9b4c625-333c-4071-8e20-b50861c73a5b aborted: Failed to allocate the network(s), not rescheduling.
Following error is found in /var/log/neutron/openvswitch-agent.log
2018-01-02 09:19:25.593 1642 ERROR neutron.agent.linux.async_process [-] Error received from [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json]: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:25.614 1642 ERROR neutron.agent.linux.async_process [-] Process [ovsdb-client monitor tcp:127.0.0.1:6640 Interface name,ofport,external_ids --format=json] dies due to the error: 2018-01-02T17:19:20Z|00001|timeval|WARN|Unreasonably long 1070ms poll interval (112ms user, 137ms system)
2018-01-02 09:19:38.115 1642 ERROR oslo.messaging._drivers.impl_rabbit [-] [e1c7a23d-f3ad-432c-b2ad-60c416e4fcad] AMQP server on 10.66.247.62:5672 is unreachable: [Errno 32] Broken pipe. Trying again in 1 seconds. Client port: None
2018-01-02 09:19:38.671 1642 ERROR OfctlService [-] unknown dpid 266822661720900
2018-01-02 09:19:38.754 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.ofswitch [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] Failed to communicate with the switch
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int Traceback (most recent call last):
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/br_int.py", line 52, in check_canary_table
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int flows = self.dump_flows(constants.CANARY_TABLE)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 131, in dump_flows
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int reply_multi=True)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/openvswitch/agent/openflow/native/ofswitch.py", line 79, in _send_msg
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int raise RuntimeError(m)
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int RuntimeError: ofctl request version=None,msg_type=None,msg_len=None,xid=None,OFPFlowStatsRequest(cookie=0,cookie_mask=0,flags=0,match=OFPMatch(oxm_fields={}),out_group=4294967295,out_port=4294967295,table_id=23,type=1) error Datapath Invalid 266822661720900
2018-01-02 09:19:38.784 1642 ERROR neutron.plugins.ml2.drivers.openvswitch.agent.openflow.native.br_int
2018-01-02 09:19:38.874 1642 WARNING neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-af8383c4-57d3-4fb2-8ec3-1b41fe3f5d5d - - - - -] OVS is dead. OVSNeutronAgent will keep running and checking OVS status periodically. |
|
