yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1760047] [NEW] some ports does not become ACTIVE during provisioning

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Piotr Misiak <piotr.misiak@xxxxxxxxxxx>
Date: Fri, 30 Mar 2018 08:38:09 -0000
Reply-to: Bug 1760047 <1760047@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:


release: Pike

When I try to spawn a 100 VMs at once almost every time it finishes with
a dozen VMs in ERROR state with cause:

Error: Build of instance 30ba80c7-6588-4916-80cb-ed3192b61e36 aborted:
Failed to allocate the network(s), not rescheduling

I debugged this a bit and figured out that a neutron port connected to
failed VM didn't become active because the DHCP provisioning block
entity hadn't been removed for this port.


For this port I see a following logs in the DHCP agent:

2018-03-30 08:05:21.131 7 DEBUG neutron.agent.dhcp.agent [req-b23f4cd3-bdd8-4fbc-bda5-27ad030109b5 aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
2018-03-30 08:05:27.376 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
2018-03-30 08:05:27.378 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:31Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
2018-03-30 08:08:50.283 7 DEBUG neutron.agent.dhcp.agent [req-b23f4cd3-bdd8-4fbc-bda5-27ad030109b5 aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
2018-03-30 08:09:01.605 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
2018-03-30 08:09:01.608 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:31Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409

In comparison on a working port which transitioned to ACTIVE state I
have:

2018-03-30 07:59:55.399 7 INFO neutron.agent.dhcp.agent [req-15e628bd-48f3-4fae-b27c-4364483d114a aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:28Z
2018-03-30 08:05:23.448 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z
2018-03-30 08:05:26.051 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z
2018-03-30 08:08:43.248 7 INFO neutron.agent.dhcp.agent [req-15e628bd-48f3-4fae-b27c-4364483d114a aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:28Z
2018-03-30 08:08:54.850 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z
2018-03-30 08:08:59.332 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z

I have no idea why for some ports DHCP agent think a port is stale but
for others it's not.

Any clues?

** 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/1760047

Title:
  some ports does not become ACTIVE during provisioning

Status in neutron:
  New

Bug description:
  
  release: Pike

  When I try to spawn a 100 VMs at once almost every time it finishes
  with a dozen VMs in ERROR state with cause:

  Error: Build of instance 30ba80c7-6588-4916-80cb-ed3192b61e36 aborted:
  Failed to allocate the network(s), not rescheduling

  I debugged this a bit and figured out that a neutron port connected to
  failed VM didn't become active because the DHCP provisioning block
  entity hadn't been removed for this port.


  For this port I see a following logs in the DHCP agent:

  2018-03-30 08:05:21.131 7 DEBUG neutron.agent.dhcp.agent [req-b23f4cd3-bdd8-4fbc-bda5-27ad030109b5 aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
  2018-03-30 08:05:27.376 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
  2018-03-30 08:05:27.378 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:31Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
  2018-03-30 08:08:50.283 7 DEBUG neutron.agent.dhcp.agent [req-b23f4cd3-bdd8-4fbc-bda5-27ad030109b5 aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
  2018-03-30 08:09:01.605 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409
  2018-03-30 08:09:01.608 7 DEBUG neutron.agent.dhcp.agent [req-e391a8ef-be5a-4768-b9b7-39398731f2de 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Discarding stale port update: admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute12, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:29Z, description=, device_id=f101ca2f-f107-4268-9dca-816d4fce7979, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.25'}], id=35c4b052-c7d8-487b-a213-aef3a3f4e9d3, mac_address=fa:16:3e:28:89:81, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:31Z port_update_end /var/lib/kolla/venv/local/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:409

  In comparison on a working port which transitioned to ACTIVE state I
  have:

  2018-03-30 07:59:55.399 7 INFO neutron.agent.dhcp.agent [req-15e628bd-48f3-4fae-b27c-4364483d114a aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:28Z
  2018-03-30 08:05:23.448 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z
  2018-03-30 08:05:26.051 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z
  2018-03-30 08:08:43.248 7 INFO neutron.agent.dhcp.agent [req-15e628bd-48f3-4fae-b27c-4364483d114a aae866ac58414f81953c57df2494eaf9 579ef78d275a4019865bca2057af3caf - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=3, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:28Z
  2018-03-30 08:08:54.850 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=4, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:29Z
  2018-03-30 08:08:59.332 7 INFO neutron.agent.dhcp.agent [req-7fc32b9a-a76a-46e0-82c9-c7a674f7262f 2f1c221e2bfb476bb9949244268b9596 fecb9ee2da694abeb723e2068b29ac3e - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=cds-compute13, binding:profile=, binding:vif_details=datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2018-03-30T07:59:28Z, description=, device_id=2ca93b42-3da0-456b-92ec-f75bdf97165b, device_owner=compute:nova, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'bd145992-d7fe-4fc8-acc7-ba510f8388e6', u'ip_address': u'10.7.0.12'}], id=1176eac0-2fb0-4088-98c8-626af0484b17, mac_address=fa:16:3e:2c:fe:68, name=, network_id=b86c5078-65fe-480c-b658-300274dba0a2, port_security_enabled=True, project_id=579ef78d275a4019865bca2057af3caf, revision_number=5, security_groups=[u'b165182d-cd0f-42a5-b5d4-5434b9079aa8'], status=DOWN, tags=[], tenant_id=579ef78d275a4019865bca2057af3caf, updated_at=2018-03-30T07:59:30Z

  I have no idea why for some ports DHCP agent think a port is stale but
  for others it's not.

  Any clues?

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

[Bug 1760047] Re: some ports does not become ACTIVE during provisioning
From: Brian Haley, 2022-12-06