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 : [email protected]
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
