Exception encountered while processing port

[Alexander]

When i create new instance on Hyper-V 2016 with Hyper-v Nova Driver(Queens release) its start without interface and i see this error all the time:
2018-08-31 04:12:57.009 4268 INFO networking_hyperv.neutron.agent.layer2 [req-33b89cee-bc36-4e3b-a984-d5ee42636cbe - - - - -] Adding port 4cd2c214-5a9b-4680-a0e7-36bf2d85728c
2018-08-31 04:12:57.022 4268 INFO networking_hyperv.neutron.agent.layer2 [req-33b89cee-bc36-4e3b-a984-d5ee42636cbe - - - - -] Port 4cd2c214-5a9b-4680-a0e7-36bf2d85728c updated. Details: {u'profile': {}, u'network_qos_policy_id': None, u'qos_policy_id': None, u'allowed_address_pairs': [], u'admin_state_up': True, u'network_id': u'2f004645-de11-4b04-a3f9-1c2abfb78899', u'segmentation_id': 1001, u'mtu': 1500, u'device_owner': u'compute:test', u'physical_network': u'provider', u'mac_address': u'fa:16:3e:5d:58:7e', u'device': u'4cd2c214-5a9b-4680-a0e7-36bf2d85728c', u'port_security_enabled': True, u'port_id': u'4cd2c214-5a9b-4680-a0e7-36bf2d85728c', u'fixed_ips': [{u'subnet_id': u'2b15aa6c-d9ce-4247-9bc4-4b6896fcf625', u'ip_address': u'172.18.200.5'}], u'network_type': u'vlan'}
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 [-] Exception encountered while processing port 4cd2c214-5a9b-4680-a0e7-36bf2d85728c. Exception: 'ascii' codec can't encode characters in position 31-38: ordinal not in range(128): UnicodeEncodeError: 'ascii' codec can't encode characters in position 31-38: ordinal not in range(128)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 Traceback (most recent call last):
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\agent\layer2.py", line 314, in process_added_port
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 self._process_added_port(device_details)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\agent\hyperv_neutron_agent.py", line 252, in _process_added_port
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 device_details)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\agent\layer2.py", line 302, in _process_added_port
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 set_port_sriov=set_port_sriov)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\_common_utils.py", line 36, in wrapper
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 return inner()
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\oslo_concurrency\lockutils.py", line 274, in inner
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 return f(*args, **kwargs)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\_common_utils.py", line 35, in inner
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 return f(*args, **kwargs)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\agent\layer2.py", line 479, in _treat_vif_port
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 port_security_enabled, set_port_sriov)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\agent\hyperv_neutron_agent.py", line 197, in _port_bound
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 self._vlan_driver.bind_vlan_port(port_id, segmentation_id)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\trunk_driver.py", line 88, in bind_vlan_port
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 trunk = self._fetch_trunk(port_id)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 File "C:\PROGRA~1\CLOUDB~1\OPENST~1\Nova\Python27\lib\site-packages\networking_hyperv\neutron\trunk_driver.py", line 109, in _fetch_trunk
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 if 'CallbackNotFound' not in str(ex):
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2 UnicodeEncodeError: 'ascii' codec can't encode characters in position 31-38: ordinal not in range(128)
2018-08-31 04:12:57.042 4268 ERROR networking_hyperv.neutron.agent.layer2

[Claudiu Belu (cbelu)]

Hi.

Interesting. Can you also look through the Neutron Server's logs as well? The line where it occurs happens when there's a remote call to the Neutron Server and it fails. It seems that there are some encoding issues, probably related to the OS' set language.

Additionally, can you specify the OS languages for both the Hyper-V node and the Neutron Controller node?

[Alexander (wrongroute)]

Hi!
Neutron server log is clear. Hyper-V and CentOS controller node - russian lang OS.

[Hirofumi Ichihara (ichihara-hirofumi)]

Can you try to run with LANG=en_US.UTF-8 temporally?

[Alexander (wrongroute)]

On english Centos instance start without error, but Cirros image work without interface.
When try to add interface manually see this:
2018-09-04 04:57:34.121 12568 WARNING nova.network.neutronv2.api [req-078cc9dd-6429-474f-8bb5-913ded1dd841 f868a5047b76448abe8e16e8c248d285 197530af151d40fb89e8743435b2ef6b - default default] [instance: c6106b22-6dee-408d-86a3-820225bbf4f2] 70e78c09-d763-4251-a562-bfd5fc1bfeb3 already exists in list: networks containing: [u'70e78c09-d763-4251-a562-bfd5fc1bfeb3']. ignoring it
2018-09-04 04:57:34.612 12568 ERROR compute_hyperv.nova.vmops [req-19bf38ca-4684-4943-8387-e8ee35dba56c bec61bd30a3b4472bb74b452a7253a83 2b5f5900fb9e4381926dbb8553b6068e - default default] [instance: c6106b22-6dee-408d-86a3-820225bbf4f2] Cannot hot plug vNIC to a first generation VM.
2018-09-04 04:57:34.617 12568 WARNING nova.compute.manager [req-19bf38ca-4684-4943-8387-e8ee35dba56c bec61bd30a3b4472bb74b452a7253a83 2b5f5900fb9e4381926dbb8553b6068e - default default] [instance: c6106b22-6dee-408d-86a3-820225bbf4f2] attach interface failed , try to deallocate port 094e4c32-f87a-4d1a-bdae-1504f9daddc9, reason: Failed to attach network adapter device to c6106b22-6dee-408d-86a3-820225bbf4f2: InterfaceAttachFailed: Failed to attach network adapter device to c6106b22-6dee-408d-86a3-820225bbf4f2
2018-09-04 04:57:35.895 12568 INFO nova.network.neutronv2.api [req-19bf38ca-4684-4943-8387-e8ee35dba56c bec61bd30a3b4472bb74b452a7253a83 2b5f5900fb9e4381926dbb8553b6068e - default default] [instance: c6106b22-6dee-408d-86a3-820225bbf4f2] Port 094e4c32-f87a-4d1a-bdae-1504f9daddc9 from network info_cache is no longer associated with instance in Neutron. Removing from network info_cache.
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server [req-19bf38ca-4684-4943-8387-e8ee35dba56c bec61bd30a3b4472bb74b452a7253a83 2b5f5900fb9e4381926dbb8553b6068e - default default] Exception during message handling: InterfaceAttachFailed: Failed to attach network adapter device to c6106b22-6dee-408d-86a3-820225bbf4f2
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server File "C:\Program Files\Cloudbase Solutions\OpenStack\Nova\Python27\lib\site-packages\oslo_messaging\rpc\server.py", line 163, in _process_incoming
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server File "C:\Program Files\Cloudbase Solutions\OpenStack\Nova\Python27\lib\site-packages\oslo_messaging\rpc\dispatcher.py", line 220, in dispatch
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server File "C:\Program Files\Cloudbase Solutions\OpenStack\Nova\Python27\lib\site-packages\oslo_messaging\rpc\dispatcher.py", line 190, in _do_dispatch
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2018-09-04 04:57:36.019 12568 ERROR oslo_messaging.rpc.server File "C:\Program Files\Cloudbase Solutions\OpenStack\Nova\Pyt...