Public bug reported:

I'm using networking-ovn as the mechanism driver,  sometimes the port
status of vm is down after vm migration.

This is because the bind port is not completed when ovn reports status
up for the port

See the details below.

2019-10-25 10:24:03.183 16030 INFO networking_ovn.ml2.mech_driver 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] OVN reports status up for 
port: 6f60a6b4-0c6f-4529-9541-d9e523f371d2
2019-10-25 10:24:03.187 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.192 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.006s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.208 16024 INFO networking_ovn.db.revision 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Successfully bumped 
revision number for resource 6f60a6b4-0c6f-4529-9541-d9e523f371d2 (type: ports) 
to 27
2019-10-25 10:24:03.238 16024 DEBUG neutron.plugins.ml2.managers 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attempting to bind port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 on host node-44795-15156 for vnic_type 
normal with profile  bind_port 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:747
2019-10-25 10:24:03.238 16024 DEBUG neutron.plugins.ml2.managers 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attempting to bind port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 on host node-44795-15156 at level 0 using 
segments [{'network_id': '722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 
'segmentation_id': 29, 'physical_network': None, 'id': 
'3d35c69a-01ba-4182-bc23-1ace3a20bbfd', 'network_type': u'geneve'}] 
_bind_port_level 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:768
2019-10-25 10:24:03.239 16024 DEBUG networking_ovn.ml2.mech_driver 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attempting to bind port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 on host node-44795-15156 for network 
segment with type geneve, segmentation ID 29, physical network None bind_port 
/usr/lib/python2.7/site-packages/networking_ovn/ml2/mech_driver.py:644
2019-10-25 10:24:03.239 16024 DEBUG neutron.plugins.ml2.managers 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Bound port: 
6f60a6b4-0c6f-4529-9541-d9e523f371d2, host: node-44795-15156, vif_type: ovs, 
vif_details: {"port_filter": true}, binding_levels: [{'bound_driver': 'ovn', 
'bound_segment': {'network_id': '722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 
'segmentation_id': 29, 'physical_network': None, 'id': 
'3d35c69a-01ba-4182-bc23-1ace3a20bbfd', 'network_type': u'geneve'}}] 
_bind_port_level 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:816
2019-10-25 10:24:03.240 16024 DEBUG neutron_lib.callbacks.manager 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Notify callbacks 
['neutron.plugins.ml2.plugin.Ml2Plugin._ensure_default_security_group_handler--9223372036853843044']
 for port, before_update _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
2019-10-25 10:24:03.242 16030 DEBUG neutron.db.provisioning_blocks 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Provisioning for port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 completed by entity L2. 
provisioning_complete 
/usr/lib/python2.7/site-packages/neutron/db/provisioning_blocks.py:132
2019-10-25 10:24:03.248 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.251 16030 DEBUG neutron.db.provisioning_blocks 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Provisioning complete for 
port 6f60a6b4-0c6f-4529-9541-d9e523f371d2 triggered by entity L2. 
provisioning_complete 
/usr/lib/python2.7/site-packages/neutron/db/provisioning_blocks.py:138
2019-10-25 10:24:03.251 16030 DEBUG neutron_lib.callbacks.manager 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Notify callbacks 
['neutron.plugins.ml2.plugin.Ml2Plugin._port_provisioned--9223372036821954182'] 
for port, provisioning_complete _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
2019-10-25 10:24:03.273 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.025s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.303 16024 DEBUG neutron.plugins.ml2.db 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] For port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2, host node-44795-15156, cleared binding 
levels clear_binding_levels 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/db.py:90
2019-10-25 10:24:03.305 16024 DEBUG neutron.plugins.ml2.db 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] For port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2, host node-44795-15156, set binding levels 
[<neutron.plugins.ml2.driver_context.InstanceSnapshot object at 
0x7f080c889d10>] set_binding_levels 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/db.py:61
2019-10-25 10:24:03.307 16024 DEBUG networking_ovn.ml2.mech_driver 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] No provisioning block for 
port 6f60a6b4-0c6f-4529-9541-d9e523f371d2 since host unchanged 
_is_port_provisioning_required 
/usr/lib/python2.7/site-packages/networking_ovn/ml2/mech_driver.py:428
2019-10-25 10:24:03.308 16024 DEBUG neutron_lib.callbacks.manager 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Notify callbacks 
['neutron.plugins.ml2.plugin.Ml2Plugin.notify_sg_on_port_change--9223372036853843112',
 'neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.handle_event-23186942', 
'networking_ovn.l3.l3_ovn._port_update--9223363307320551277', 
'neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._native_event_send_dhcp_notification--9223372036831097911']
 for port, after_update _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
2019-10-25 10:24:03.320 16024 DEBUG oslo_concurrency.lockutils [-] Lock 
"event-dispatch" acquired by "neutron.plugins.ml2.ovo_rpc.dispatch_events" :: 
waited 0.000s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.340 16030 DEBUG neutron.plugins.ml2.plugin 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 cannot update to ACTIVE because it is not 
bound. _port_provisioned 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/plugin.py:291
2019-10-25 10:24:03.360 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.372 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.012s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.430 16024 DEBUG neutron.api.rpc.handlers.resources_rpc 
[req-631c9280-ec1a-4616-861f-5ae30b510786 - - - - -] Pushing event updated for 
resources: {'Port': 
['ID=6f60a6b4-0c6f-4529-9541-d9e523f371d2,revision_number=28']} push 
/usr/lib/python2.7/site-packages/neutron/api/rpc/handlers/resources_rpc.py:241
2019-10-25 10:24:03.434 16024 DEBUG oslo_concurrency.lockutils 
[req-631c9280-ec1a-4616-861f-5ae30b510786 - - - - -] Lock "event-dispatch" 
released by "neutron.plugins.ml2.ovo_rpc.dispatch_events" :: held 0.114s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.453 16024 DEBUG 
neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Network 
722eeddf-af9a-4d92-a4c5-e2d4b83e9c54 is not hosted by any dhcp agent 
_notify_agents 
/usr/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py:218
2019-10-25 10:24:03.493 16024 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] 
Running txn n=1 command(idx=0): CheckRevisionNumberCommand(if_exists=True, 
resource={'status': u'DOWN', 'binding:host_id': u'node-44795-15156', 
'description': u'', 'allowed_address_pairs': [], 'tags': [], 'extra_dhcp_opts': 
[], 'updated_at': '2019-10-25T02:24:02Z', 'device_owner': u'compute:nova', 
'revision_number': 27, 'port_security_enabled': False, 'network': 
{'provider:physical_network': None, 'ipv6_address_scope': None, 
'revision_number': 4, 'port_security_enabled': True, 'provider:network_type': 
u'geneve', 'id': u'722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 'router:external': 
False, 'availability_zone_hints': [], 'availability_zones': [], 
'ipv4_address_scope': None, 'shared': False, 'project_id': 
u'e487a13b6dfd32a2016dfd618d7401d5', 'status': u'ACTIVE', 'subnets': 
[u'7f5d0ee0-5912-4680-b060-9b83711a1638'], 'description': u'', 'tags': [], 
'updated_at': '2019-10-24T13:37:57Z', 'provider:segmentation_id': 29, 'name': 
u'ss', 'admin_state_up': True, 'tenant_id': 
u'e487a13b6dfd32a2016dfd618d7401d5', 'created_at': '2019-10-24T10:48:12Z', 
'mtu': 1442, 'vlan_transparent': None}, 'binding:profile': {}, 'fixed_ips': 
[{'subnet_id': u'7f5d0ee0-5912-4680-b060-9b83711a1638', 'ip_address': 
u'192.168.12.3'}], 'id': u'6f60a6b4-0c6f-4529-9541-d9e523f371d2', 
'security_groups': [], 'device_id': u'i-00000C', 'name': u'vna72813370', 
'admin_state_up': True, 'network_id': u'722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 
'tenant_id': u'icsAdmin', 'binding:vif_details': {u'port_filter': True}, 
'binding:vnic_type': u'normal', 'binding:vif_type': 'ovs', 'mac_address': 
u'00:16:3e:a3:91:9b', 'project_id': u'icsAdmin', 'created_at': 
'2019-10-24T10:55:25Z'}, name=6f60a6b4-0c6f-4529-9541-d9e523f371d2, 
resource_type=ports) do_commit 
/usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84
2019-10-25 10:24:03.493 16024 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] 
Running txn n=1 command(idx=1): 
SetLSwitchPortCommand(lport=6f60a6b4-0c6f-4529-9541-d9e523f371d2, 
if_exists=False, columns={'parent_name': [], 'addresses': [u'00:16:3e:a3:91:9b 
192.168.12.3'], 'enabled': True, 'port_security': [], 'dhcpv6_options': [], 
'external_ids': {'neutron:cidrs': '192.168.12.3/24', 'neutron:device_id': 
u'i-00000C', 'neutron:revision_number': '27', 'neutron:port_name': 
u'vna72813370', 'neutron:network_name': 
u'neutron-722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 'neutron:project_id': 
u'icsAdmin', 'neutron:device_owner': u'compute:nova', 
'neutron:security_group_ids': ''}, 'tag': [], 'type': '', 'options': 
{'requested-chassis': u'node-44795-15156'}, 'dhcpv4_options': 
[UUID('770c3daa-3128-4a7a-9a3a-6f27b55aa0f8')]}) do_commit 
/usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84
2019-10-25 10:24:03.494 16024 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] 
Running txn n=1 command(idx=2): PgDelPortCommand(if_exists=False, 
lsp=[u'6f60a6b4-0c6f-4529-9541-d9e523f371d2'], port_group=neutron_pg_drop) 
do_commit 
/usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84
2019-10-25 10:24:03.502 16030 DEBUG ovsdbapp.backend.ovs_idl.event [-] 
ChassisEvent : Matched Chassis, ('create', 'update', 'delete'), None None 
matches /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/event.py:40
2019-10-25 10:24:03.503 16030 DEBUG ovsdbapp.backend.ovs_idl.event [-] 
ChassisEvent : Matched Chassis, ('create', 'update', 'delete'), None None 
matches /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/event.py:40
2019-10-25 10:24:03.503 16030 DEBUG ovsdbapp.backend.ovs_idl.event [-] 
ChassisEvent : Matched Chassis, ('create', 'update', 'delete'), None None 
matches /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/event.py:40
2019-10-25 10:24:03.515 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.518 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.004s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.565 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.568 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.003s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.616 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2019-10-25 10:24:03.619 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.003s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
2019-10-25 10:24:03.776 16024 INFO networking_ovn.db.revision 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Successfully bumped 
revision number for resource 6f60a6b4-0c6f-4529-9541-d9e523f371d2 (type: ports) 
to 27
2019-10-25 10:24:03.787 16024 DEBUG neutron.pecan_wsgi.hooks.policy_enforcement 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attributes excluded by 
policy engine: [u'network'] _exclude_attributes_by_policy 
/usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256
2019-10-25 10:24:03.788 16024 DEBUG neutron_lib.callbacks.manager 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Notify callbacks 
['neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._send_dhcp_notification--9223372036831097890',
 'neutron.notifiers.nova.Notifier._send_nova_notification-6708'] for port, 
before_response _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
2019-10-25 10:24:03.790 16024 INFO neutron.wsgi 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] 127.0.0.1 "PUT 
/v2.0/ports/6f60a6b4-0c6f-4529-9541-d9e523f371d2 HTTP/1.1" status: 200  len: 
967 time: 1.2829940

** Affects: neutron
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1849796

Title:
  port status is down after vm migration

Status in neutron:
  New

Bug description:
  I'm using networking-ovn as the mechanism driver,  sometimes the port
  status of vm is down after vm migration.

  This is because the bind port is not completed when ovn reports status
  up for the port

  See the details below.

  2019-10-25 10:24:03.183 16030 INFO networking_ovn.ml2.mech_driver 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] OVN reports status up for 
port: 6f60a6b4-0c6f-4529-9541-d9e523f371d2
  2019-10-25 10:24:03.187 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.192 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.006s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.208 16024 INFO networking_ovn.db.revision 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Successfully bumped 
revision number for resource 6f60a6b4-0c6f-4529-9541-d9e523f371d2 (type: ports) 
to 27
  2019-10-25 10:24:03.238 16024 DEBUG neutron.plugins.ml2.managers 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attempting to bind port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 on host node-44795-15156 for vnic_type 
normal with profile  bind_port 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:747
  2019-10-25 10:24:03.238 16024 DEBUG neutron.plugins.ml2.managers 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attempting to bind port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 on host node-44795-15156 at level 0 using 
segments [{'network_id': '722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 
'segmentation_id': 29, 'physical_network': None, 'id': 
'3d35c69a-01ba-4182-bc23-1ace3a20bbfd', 'network_type': u'geneve'}] 
_bind_port_level 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:768
  2019-10-25 10:24:03.239 16024 DEBUG networking_ovn.ml2.mech_driver 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attempting to bind port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 on host node-44795-15156 for network 
segment with type geneve, segmentation ID 29, physical network None bind_port 
/usr/lib/python2.7/site-packages/networking_ovn/ml2/mech_driver.py:644
  2019-10-25 10:24:03.239 16024 DEBUG neutron.plugins.ml2.managers 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Bound port: 
6f60a6b4-0c6f-4529-9541-d9e523f371d2, host: node-44795-15156, vif_type: ovs, 
vif_details: {"port_filter": true}, binding_levels: [{'bound_driver': 'ovn', 
'bound_segment': {'network_id': '722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 
'segmentation_id': 29, 'physical_network': None, 'id': 
'3d35c69a-01ba-4182-bc23-1ace3a20bbfd', 'network_type': u'geneve'}}] 
_bind_port_level 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py:816
  2019-10-25 10:24:03.240 16024 DEBUG neutron_lib.callbacks.manager 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Notify callbacks 
['neutron.plugins.ml2.plugin.Ml2Plugin._ensure_default_security_group_handler--9223372036853843044']
 for port, before_update _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
  2019-10-25 10:24:03.242 16030 DEBUG neutron.db.provisioning_blocks 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Provisioning for port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 completed by entity L2. 
provisioning_complete 
/usr/lib/python2.7/site-packages/neutron/db/provisioning_blocks.py:132
  2019-10-25 10:24:03.248 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.251 16030 DEBUG neutron.db.provisioning_blocks 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Provisioning complete for 
port 6f60a6b4-0c6f-4529-9541-d9e523f371d2 triggered by entity L2. 
provisioning_complete 
/usr/lib/python2.7/site-packages/neutron/db/provisioning_blocks.py:138
  2019-10-25 10:24:03.251 16030 DEBUG neutron_lib.callbacks.manager 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Notify callbacks 
['neutron.plugins.ml2.plugin.Ml2Plugin._port_provisioned--9223372036821954182'] 
for port, provisioning_complete _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
  2019-10-25 10:24:03.273 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.025s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.303 16024 DEBUG neutron.plugins.ml2.db 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] For port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2, host node-44795-15156, cleared binding 
levels clear_binding_levels 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/db.py:90
  2019-10-25 10:24:03.305 16024 DEBUG neutron.plugins.ml2.db 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] For port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2, host node-44795-15156, set binding levels 
[<neutron.plugins.ml2.driver_context.InstanceSnapshot object at 
0x7f080c889d10>] set_binding_levels 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/db.py:61
  2019-10-25 10:24:03.307 16024 DEBUG networking_ovn.ml2.mech_driver 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] No provisioning block for 
port 6f60a6b4-0c6f-4529-9541-d9e523f371d2 since host unchanged 
_is_port_provisioning_required 
/usr/lib/python2.7/site-packages/networking_ovn/ml2/mech_driver.py:428
  2019-10-25 10:24:03.308 16024 DEBUG neutron_lib.callbacks.manager 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Notify callbacks 
['neutron.plugins.ml2.plugin.Ml2Plugin.notify_sg_on_port_change--9223372036853843112',
 'neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.handle_event-23186942', 
'networking_ovn.l3.l3_ovn._port_update--9223363307320551277', 
'neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._native_event_send_dhcp_notification--9223372036831097911']
 for port, after_update _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
  2019-10-25 10:24:03.320 16024 DEBUG oslo_concurrency.lockutils [-] Lock 
"event-dispatch" acquired by "neutron.plugins.ml2.ovo_rpc.dispatch_events" :: 
waited 0.000s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.340 16030 DEBUG neutron.plugins.ml2.plugin 
[req-8dce69eb-0668-4c95-81da-e3a91d484cc9 - - - - -] Port 
6f60a6b4-0c6f-4529-9541-d9e523f371d2 cannot update to ACTIVE because it is not 
bound. _port_provisioned 
/usr/lib/python2.7/site-packages/neutron/plugins/ml2/plugin.py:291
  2019-10-25 10:24:03.360 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.372 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.012s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.430 16024 DEBUG neutron.api.rpc.handlers.resources_rpc 
[req-631c9280-ec1a-4616-861f-5ae30b510786 - - - - -] Pushing event updated for 
resources: {'Port': 
['ID=6f60a6b4-0c6f-4529-9541-d9e523f371d2,revision_number=28']} push 
/usr/lib/python2.7/site-packages/neutron/api/rpc/handlers/resources_rpc.py:241
  2019-10-25 10:24:03.434 16024 DEBUG oslo_concurrency.lockutils 
[req-631c9280-ec1a-4616-861f-5ae30b510786 - - - - -] Lock "event-dispatch" 
released by "neutron.plugins.ml2.ovo_rpc.dispatch_events" :: held 0.114s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.453 16024 DEBUG 
neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Network 
722eeddf-af9a-4d92-a4c5-e2d4b83e9c54 is not hosted by any dhcp agent 
_notify_agents 
/usr/lib/python2.7/site-packages/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py:218
  2019-10-25 10:24:03.493 16024 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] 
Running txn n=1 command(idx=0): CheckRevisionNumberCommand(if_exists=True, 
resource={'status': u'DOWN', 'binding:host_id': u'node-44795-15156', 
'description': u'', 'allowed_address_pairs': [], 'tags': [], 'extra_dhcp_opts': 
[], 'updated_at': '2019-10-25T02:24:02Z', 'device_owner': u'compute:nova', 
'revision_number': 27, 'port_security_enabled': False, 'network': 
{'provider:physical_network': None, 'ipv6_address_scope': None, 
'revision_number': 4, 'port_security_enabled': True, 'provider:network_type': 
u'geneve', 'id': u'722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 'router:external': 
False, 'availability_zone_hints': [], 'availability_zones': [], 
'ipv4_address_scope': None, 'shared': False, 'project_id': 
u'e487a13b6dfd32a2016dfd618d7401d5', 'status': u'ACTIVE', 'subnets': 
[u'7f5d0ee0-5912-4680-b060-9b83711a1638'], 'description': u'', 'tags': [], 
'updated_at': '2019-10-24T13:37:57Z', 'provider:segmentation_id': 29, 'name': 
u'ss', 'admin_state_up': True, 'tenant_id': 
u'e487a13b6dfd32a2016dfd618d7401d5', 'created_at': '2019-10-24T10:48:12Z', 
'mtu': 1442, 'vlan_transparent': None}, 'binding:profile': {}, 'fixed_ips': 
[{'subnet_id': u'7f5d0ee0-5912-4680-b060-9b83711a1638', 'ip_address': 
u'192.168.12.3'}], 'id': u'6f60a6b4-0c6f-4529-9541-d9e523f371d2', 
'security_groups': [], 'device_id': u'i-00000C', 'name': u'vna72813370', 
'admin_state_up': True, 'network_id': u'722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 
'tenant_id': u'icsAdmin', 'binding:vif_details': {u'port_filter': True}, 
'binding:vnic_type': u'normal', 'binding:vif_type': 'ovs', 'mac_address': 
u'00:16:3e:a3:91:9b', 'project_id': u'icsAdmin', 'created_at': 
'2019-10-24T10:55:25Z'}, name=6f60a6b4-0c6f-4529-9541-d9e523f371d2, 
resource_type=ports) do_commit 
/usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84
  2019-10-25 10:24:03.493 16024 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] 
Running txn n=1 command(idx=1): 
SetLSwitchPortCommand(lport=6f60a6b4-0c6f-4529-9541-d9e523f371d2, 
if_exists=False, columns={'parent_name': [], 'addresses': [u'00:16:3e:a3:91:9b 
192.168.12.3'], 'enabled': True, 'port_security': [], 'dhcpv6_options': [], 
'external_ids': {'neutron:cidrs': '192.168.12.3/24', 'neutron:device_id': 
u'i-00000C', 'neutron:revision_number': '27', 'neutron:port_name': 
u'vna72813370', 'neutron:network_name': 
u'neutron-722eeddf-af9a-4d92-a4c5-e2d4b83e9c54', 'neutron:project_id': 
u'icsAdmin', 'neutron:device_owner': u'compute:nova', 
'neutron:security_group_ids': ''}, 'tag': [], 'type': '', 'options': 
{'requested-chassis': u'node-44795-15156'}, 'dhcpv4_options': 
[UUID('770c3daa-3128-4a7a-9a3a-6f27b55aa0f8')]}) do_commit 
/usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84
  2019-10-25 10:24:03.494 16024 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] 
Running txn n=1 command(idx=2): PgDelPortCommand(if_exists=False, 
lsp=[u'6f60a6b4-0c6f-4529-9541-d9e523f371d2'], port_group=neutron_pg_drop) 
do_commit 
/usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84
  2019-10-25 10:24:03.502 16030 DEBUG ovsdbapp.backend.ovs_idl.event [-] 
ChassisEvent : Matched Chassis, ('create', 'update', 'delete'), None None 
matches /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/event.py:40
  2019-10-25 10:24:03.503 16030 DEBUG ovsdbapp.backend.ovs_idl.event [-] 
ChassisEvent : Matched Chassis, ('create', 'update', 'delete'), None None 
matches /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/event.py:40
  2019-10-25 10:24:03.503 16030 DEBUG ovsdbapp.backend.ovs_idl.event [-] 
ChassisEvent : Matched Chassis, ('create', 'update', 'delete'), None None 
matches /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/event.py:40
  2019-10-25 10:24:03.515 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.518 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.004s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.565 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.568 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.003s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.616 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" acquired by 
"neutron.services.segments.db.update_segment_host_mapping" :: waited 0.000s 
inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
  2019-10-25 10:24:03.619 16030 DEBUG oslo_concurrency.lockutils 
[req-d037496a-62cc-4132-96ba-fddd7cd4f065 - - - - -] Lock 
"update_segment_host_mapping" released by 
"neutron.services.segments.db.update_segment_host_mapping" :: held 0.003s inner 
/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285
  2019-10-25 10:24:03.776 16024 INFO networking_ovn.db.revision 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Successfully bumped 
revision number for resource 6f60a6b4-0c6f-4529-9541-d9e523f371d2 (type: ports) 
to 27
  2019-10-25 10:24:03.787 16024 DEBUG 
neutron.pecan_wsgi.hooks.policy_enforcement 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Attributes excluded by 
policy engine: [u'network'] _exclude_attributes_by_policy 
/usr/lib/python2.7/site-packages/neutron/pecan_wsgi/hooks/policy_enforcement.py:256
  2019-10-25 10:24:03.788 16024 DEBUG neutron_lib.callbacks.manager 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] Notify callbacks 
['neutron.api.rpc.agentnotifiers.dhcp_rpc_agent_api.DhcpAgentNotifyAPI._send_dhcp_notification--9223372036831097890',
 'neutron.notifiers.nova.Notifier._send_nova_notification-6708'] for port, 
before_response _notify_loop 
/usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:193
  2019-10-25 10:24:03.790 16024 INFO neutron.wsgi 
[req-b6ea06db-db6c-44de-b957-1d139411ecf0 - - - - -] 127.0.0.1 "PUT 
/v2.0/ports/6f60a6b4-0c6f-4529-9541-d9e523f371d2 HTTP/1.1" status: 200  len: 
967 time: 1.2829940

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1849796/+subscriptions

-- 
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to     : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help   : https://help.launchpad.net/ListHelp

Reply via email to