yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1883513] [NEW] Adding a third DHCP agent to the network fails due to binding index error

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Justinas Balciunas <1883513@xxxxxxxxxxxxxxxxxx>
Date: Mon, 15 Jun 2020 09:33:56 -0000
Reply-to: Bug 1883513 <1883513@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Using neutron-16.0.0, Ussuri.

Problem: unable to add the third DHCP agent to the network due to a
binding index issue, as follows:

2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource [req-df0a70d4-268e-4c00-a208-e564fde17fb3 390ed4681a7995dc8833b1b176b41595b9d1053357a38de2da9b4de2ab0fa5b5 4e04be9ff9824855be22d0f54176f552 - d1c23cab572446aab6742e5185563575 d1c23cab572446aab6742e5185563575] create failed: No details.: sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original exception was: (pymysql.err.IntegrityError) (1062, "Duplicate entry '51893269-80b5-43ed-9696-e44716c8e111-2' for key 'uniq_network_dhcp_agent_binding0network_id0binding_index0'")
[SQL: INSERT INTO networkdhcpagentbindings (network_id, dhcp_agent_id, binding_index) VALUES (%(network_id)s, %(dhcp_agent_id)s, %(binding_index)s)]
[parameters: {'network_id': '51893269-80b5-43ed-9696-e44716c8e111', 'dhcp_agent_id': '90181fe1-4a97-4a5e-a913-386d26ab9fae', 'binding_index': 2}]
(Background on this error at: http://sqlalche.me/e/gkpj) (Background on this error at: http://sqlalche.me/e/7s2a)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource Traceback (most recent call last):
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/api/v2/resource.py", line 98, in resource
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     result = method(request=request, **args)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/extensions/dhcpagentscheduler.py", line 50, in create
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     network_id)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/agentschedulers_db.py", line 393, in add_network_to_dhcp_agent
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     context, [agent_db], network_id, force_scheduling=True)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     next(self.gen)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1064, in _transaction_scope
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     yield resource
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     next(self.gen)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 666, in _session
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self.session.rollback()
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self.force_reraise()
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/six.py", line 703, in reraise
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     raise value
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 663, in _session
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self._end_session_transaction(self.session)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 691, in _end_session_transaction
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     session.commit()
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 1036, in commit
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self.transaction.commit()
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 501, in commit
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self._assert_active(prepared_ok=True)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 295, in _assert_active
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     code="7s2a",
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original exception was: (pymysql.err.IntegrityError) (1062, "Duplicate entry '51893269-80b5-43ed-9696-e44716c8e111-2' for key 'uniq_network_dhcp_agent_binding0network_id0binding_index0'")
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource [SQL: INSERT INTO networkdhcpagentbindings (network_id, dhcp_agent_id, binding_index) VALUES (%(network_id)s, %(dhcp_agent_id)s, %(binding_index)s)]
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource [parameters: {'network_id': '51893269-80b5-43ed-9696-e44716c8e111', 'dhcp_agent_id': '90181fe1-4a97-4a5e-a913-386d26ab9fae', 'binding_index': 2}]
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource (Background on this error at: http://sqlalche.me/e/gkpj) (Background on this error at: http://sqlalche.me/e/7s2a)
2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource


Database output for the DHCP agent bindings shows that:

MariaDB [neutron]> select * from networkdhcpagentbindings;
+--------------------------------------+--------------------------------------+---------------+
| network_id                           | dhcp_agent_id                        | binding_index |
+--------------------------------------+--------------------------------------+---------------+
| 51893269-80b5-43ed-9696-e44716c8e111 | 4544bcca-5d9c-4573-a76d-1db641d5b79d |             1 |
| 51893269-80b5-43ed-9696-e44716c8e111 | 4f0671c6-60e5-4d5b-adff-ee29a91f7574 |             2 |
+--------------------------------------+--------------------------------------+---------------+

There are three up and running DHCP agents:

root@kolla-ussuri:/etc/kolla# neutron agent-list | grep -i dhcp
neutron CLI is deprecated and will be removed in the future. Use openstack CLI instead.
| 4544bcca-5d9c-4573-a76d-1db641d5b79d | DHCP agent         | z141-ost-ctrl1 | AZ2               | :-)   | True           | neutron-dhcp-agent        |
| 4f0671c6-60e5-4d5b-adff-ee29a91f7574 | DHCP agent         | z141-ost-ctrl2 | AZ2               | :-)   | True           | neutron-dhcp-agent        |
| 90181fe1-4a97-4a5e-a913-386d26ab9fae | DHCP agent         | z141-ost-ctrl3 | AZ2               | :-)   | True           | neutron-dhcp-agent        |

And the error happens upon adding the third DHCP agent, however, as
visible from the error output above, the binding index stays at 2, even
though it should be 3.

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

Title:
  Adding a third DHCP agent to the network fails due to binding index
  error

Status in neutron:
  New

Bug description:
  Using neutron-16.0.0, Ussuri.

  Problem: unable to add the third DHCP agent to the network due to a
  binding index issue, as follows:

  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource [req-df0a70d4-268e-4c00-a208-e564fde17fb3 390ed4681a7995dc8833b1b176b41595b9d1053357a38de2da9b4de2ab0fa5b5 4e04be9ff9824855be22d0f54176f552 - d1c23cab572446aab6742e5185563575 d1c23cab572446aab6742e5185563575] create failed: No details.: sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original exception was: (pymysql.err.IntegrityError) (1062, "Duplicate entry '51893269-80b5-43ed-9696-e44716c8e111-2' for key 'uniq_network_dhcp_agent_binding0network_id0binding_index0'")
  [SQL: INSERT INTO networkdhcpagentbindings (network_id, dhcp_agent_id, binding_index) VALUES (%(network_id)s, %(dhcp_agent_id)s, %(binding_index)s)]
  [parameters: {'network_id': '51893269-80b5-43ed-9696-e44716c8e111', 'dhcp_agent_id': '90181fe1-4a97-4a5e-a913-386d26ab9fae', 'binding_index': 2}]
  (Background on this error at: http://sqlalche.me/e/gkpj) (Background on this error at: http://sqlalche.me/e/7s2a)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource Traceback (most recent call last):
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/api/v2/resource.py", line 98, in resource
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     result = method(request=request, **args)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/extensions/dhcpagentscheduler.py", line 50, in create
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     network_id)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/agentschedulers_db.py", line 393, in add_network_to_dhcp_agent
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     context, [agent_db], network_id, force_scheduling=True)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     next(self.gen)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1064, in _transaction_scope
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     yield resource
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     next(self.gen)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 666, in _session
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self.session.rollback()
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self.force_reraise()
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/six.py", line 703, in reraise
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     raise value
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 663, in _session
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self._end_session_transaction(self.session)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 691, in _end_session_transaction
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     session.commit()
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 1036, in commit
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self.transaction.commit()
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 501, in commit
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     self._assert_active(prepared_ok=True)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/sqlalchemy/orm/session.py", line 295, in _assert_active
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource     code="7s2a",
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original exception was: (pymysql.err.IntegrityError) (1062, "Duplicate entry '51893269-80b5-43ed-9696-e44716c8e111-2' for key 'uniq_network_dhcp_agent_binding0network_id0binding_index0'")
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource [SQL: INSERT INTO networkdhcpagentbindings (network_id, dhcp_agent_id, binding_index) VALUES (%(network_id)s, %(dhcp_agent_id)s, %(binding_index)s)]
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource [parameters: {'network_id': '51893269-80b5-43ed-9696-e44716c8e111', 'dhcp_agent_id': '90181fe1-4a97-4a5e-a913-386d26ab9fae', 'binding_index': 2}]
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource (Background on this error at: http://sqlalche.me/e/gkpj) (Background on this error at: http://sqlalche.me/e/7s2a)
  2020-06-15 12:23:10.874 25 ERROR neutron.api.v2.resource

  
  Database output for the DHCP agent bindings shows that:

  MariaDB [neutron]> select * from networkdhcpagentbindings;
  +--------------------------------------+--------------------------------------+---------------+
  | network_id                           | dhcp_agent_id                        | binding_index |
  +--------------------------------------+--------------------------------------+---------------+
  | 51893269-80b5-43ed-9696-e44716c8e111 | 4544bcca-5d9c-4573-a76d-1db641d5b79d |             1 |
  | 51893269-80b5-43ed-9696-e44716c8e111 | 4f0671c6-60e5-4d5b-adff-ee29a91f7574 |             2 |
  +--------------------------------------+--------------------------------------+---------------+

  There are three up and running DHCP agents:

  root@kolla-ussuri:/etc/kolla# neutron agent-list | grep -i dhcp
  neutron CLI is deprecated and will be removed in the future. Use openstack CLI instead.
  | 4544bcca-5d9c-4573-a76d-1db641d5b79d | DHCP agent         | z141-ost-ctrl1 | AZ2               | :-)   | True           | neutron-dhcp-agent        |
  | 4f0671c6-60e5-4d5b-adff-ee29a91f7574 | DHCP agent         | z141-ost-ctrl2 | AZ2               | :-)   | True           | neutron-dhcp-agent        |
  | 90181fe1-4a97-4a5e-a913-386d26ab9fae | DHCP agent         | z141-ost-ctrl3 | AZ2               | :-)   | True           | neutron-dhcp-agent        |

  And the error happens upon adding the third DHCP agent, however, as
  visible from the error output above, the binding index stays at 2,
  even though it should be 3.

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

[Bug 1883513] Re: Adding a third DHCP agent to the network fails due to binding index error
From: OpenStack Infra, 2020-06-27
[Bug 1883513] Re: Adding a third DHCP agent to the network fails due to binding index error
From: Slawek Kaplonski, 2020-06-15
[Bug 1883513] Re: Adding a third DHCP agent to the network fails due to binding index error
From: Rodolfo Alonso, 2020-06-15