Bug #1912596 “neutron-server report 500 error when update floati...” : Bugs : neutron

Revision history for this message

Slawek Kaplonski (slaweq) wrote on 2021-01-21:

#1

Can You give us neutron-server log with the error which You have there? Probably there is some stacktrace in that log and that would be useful for us to triage this bug.

Changed in neutron:
status:	New → Incomplete
tags:	added: api l3-dvr-backlog

Revision history for this message

yangjianfeng (yangjianfeng) wrote on 2021-01-21:

#2

Download full text (9.4 KiB)

Hi slawek, this is the error logs:
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api [req-4f675cb5-aa3a-4ade-8357-3b0437d64263 cb50cb5cb0fa42f485dc79a81a0249b1 f936cee5d7fb46c5980b2a47f4559c31 - default default] DB exceeded retry limit.: DBDuplicateEntry: (pymysql.err.IntegrityError) (1062, u"Duplicate entry '76a1f0d2-08ad-4975-a2ee-02d877960b35-192.168.5.4:7687' for key 'uniq_port_forwardings0internal_neutron_port_id0socket'") [SQL: u'UPDATE portforwardings SET socket=%(socket)s WHERE portforwardings.id = %(portforwardings_id)s'] [parameters: {'socket': '192.168.5.4:7687', 'portforwardings_id': u'fea45432-321b-4362-b2d4-525680a4b6d9'}] (Background on this error at: http://sqlalche.me/e/gkpj)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api Traceback (most recent call last):
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 142, in wrapper
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api return f(*args, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 183, in wrapped
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api LOG.debug("Retry wrapper got retriable exception: %s", e)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api self.force_reraise()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api six.reraise(self.type_, self.value, self.tb)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 179, in wrapped
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api return f(*dup_args, **dup_kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron/api/v2/base.py", line 682, in _update
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api obj = obj_updater(request.context, id, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_common.py", line 51, in inner
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api result = f(*args, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron/services/portforwarding/pf_plugin.py", line 400, in update_floatingip_port_forwarding
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api pf_obj.update()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron/objects/base.py", line 342, in decorator
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api return func(self, *args, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron/objects/base.py", line 876, in update
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api self._get_composite_keys()))
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api File "/usr/lib/python2.7/site-packages/neutron/objec...

Hi slawek, this is the error logs:
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api [req-4f675cb5-aa3a-4ade-8357-3b0437d64263 cb50cb5cb0fa42f485dc79a81a0249b1 f936cee5d7fb46c5980b2a47f4559c31 - default default] DB exceeded retry limit.: DBDuplicateEntry: (pymysql.err.IntegrityError) (1062, u"Duplicate entry '76a1f0d2-08ad-4975-a2ee-02d877960b35-192.168.5.4:7687' for key 'uniq_port_forwardings0internal_neutron_port_id0socket'") [SQL: u'UPDATE portforwardings SET socket=%(socket)s WHERE portforwardings.id = %(portforwardings_id)s'] [parameters: {'socket': '192.168.5.4:7687', 'portforwardings_id': u'fea45432-321b-4362-b2d4-525680a4b6d9'}] (Background on this error at: http://sqlalche.me/e/gkpj)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api Traceback (most recent call last):
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 142, in wrapper
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     return f(*args, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 183, in wrapped
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     LOG.debug("Retry wrapper got retriable exception: %s", e)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     self.force_reraise()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     six.reraise(self.type_, self.value, self.tb)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron_lib/db/api.py", line 179, in wrapped
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     return f(*dup_args, **dup_kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron/api/v2/base.py", line 682, in _update
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     obj = obj_updater(request.context, id, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron/db/db_base_plugin_common.py", line 51, in inner
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     result = f(*args, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron/services/portforwarding/pf_plugin.py", line 400, in update_floatingip_port_forwarding
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     pf_obj.update()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron/objects/base.py", line 342, in decorator
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     return func(self, *args, **kwargs)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron/objects/base.py", line 876, in update
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     self._get_composite_keys()))
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/neutron/objects/db/api.py", line 82, in update_object
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     db_obj.save(session=context.session)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/models.py", line 50, in save
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     session.flush()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2254, in flush
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     self._flush(objects)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2380, in _flush
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     transaction.rollback(_capture_exception=True)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     compat.reraise(exc_type, exc_value, exc_tb)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2344, in _flush
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     flush_context.execute()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     rec.execute(self)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     uow
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 177, in save_obj
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     mapper, table, update)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 768, in _emit_update_statements
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     execute(statement, multiparams)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 948, in execute
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     return meth(self, multiparams, params)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 269, in _execute_on_connection
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     return connection._execute_clauseelement(self, multiparams, params)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1060, in _execute_clauseelement
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     compiled_sql, distilled_params
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1200, in _execute_context
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     context)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     util.raise_from_cause(newraise, exc_info)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     reraise(type(exception), exception, tb=exc_tb, cause=cause)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     context)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     cursor.execute(statement, parameters)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 170, in execute
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     result = self._query(query)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 328, in _query
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     conn.query(q)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 516, in query
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 727, in _read_query_result
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     result.read()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1066, in read
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     first_packet = self.connection._read_packet()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 683, in _read_packet
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     packet.check_error()
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/protocol.py", line 220, in check_error
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     err.raise_mysql_exception(self._data)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 109, in raise_mysql_exception
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api     raise errorclass(errno, errval)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api DBDuplicateEntry: (pymysql.err.IntegrityError) (1062, u"Duplicate entry '76a1f0d2-08ad-4975-a2ee-02d877960b35-192.168.5.4:7687' for key 'uniq_port_forwardings0internal_neutron_port_id0socket'") [SQL: u'UPDATE portforwardings SET socket=%(socket)s WHERE portforwardings.id = %(portforwardings_id)s'] [parameters: {'socket': '192.168.5.4:7687', 'portforwardings_id': u'fea45432-321b-4362-b2d4-525680a4b6d9'}] (Background on this error at: http://sqlalche.me/e/gkpj)
2021-01-21 16:04:14.182 1121930 ERROR oslo_db.api

Revision history for this message

Slawek Kaplonski (slaweq) wrote on 2021-01-21:

#3

Thx. So it seems that it don't properly catch db exception to return some nicer error message to the user in such case.
I think that this should be easy bug to fix. I will mark it as low-hanging-fruit for now.

tags:	added: low-hanging-fruit
Changed in neutron:
status:	Incomplete → Confirmed
importance:	Undecided → Medium

Mamatisa Nurmatov (isabek) on 2021-01-21

Changed in neutron:
assignee:	nobody → Mamatisa Nurmatov (isabek)

Revision history for this message

yangjianfeng (yangjianfeng) wrote on 2021-01-21:

#4

Hi slawek, mamatisa:

I already committed a patch to fix it: https://review.opendev.org/c/openstack/neutron/+/771776

Mamatisa Nurmatov (isabek) on 2021-01-22

Changed in neutron:
assignee:	Mamatisa Nurmatov (isabek) → nobody

Bence Romsics (bence-romsics) on 2021-01-25

Changed in neutron:
status:	Confirmed → In Progress

Bernard Cafarelli (bcafarel) on 2021-02-09

Changed in neutron:
assignee:	nobody → yangjianfeng (yangjianfeng)
status:	In Progress → Fix Released

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-03-18: Fix included in openstack/neutron 16.3.1

#5

This issue was fixed in the openstack/neutron 16.3.1 release.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-03-18: Fix included in openstack/neutron 17.1.1

#6

This issue was fixed in the openstack/neutron 17.1.1 release.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-03-26: Fix included in openstack/neutron 18.0.0.0rc1

#7

This issue was fixed in the openstack/neutron 18.0.0.0rc1 release candidate.

Revision history for this message

Slawek Kaplonski (slaweq) wrote on 2021-04-14: auto-abandon-script

#8

This bug has had a related patch abandoned and has been automatically un-assigned due to inactivity. Please re-assign yourself if you are continuing work or adjust the state as appropriate if it is no longer valid.

Changed in neutron:
assignee:	yangjianfeng (yangjianfeng) → nobody
tags:	added: timeout-abandon

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-04-14: Change abandoned on neutron (stable/train)

#9

Change abandoned by "Slawek Kaplonski <email address hidden>" on branch: stable/train
Review: https://review.opendev.org/c/openstack/neutron/+/774585
Reason: This review is > 4 weeks without comment, and failed Zuul jobs the last time it was checked. We are abandoning this for now. Feel free to reactivate the review by pressing the restore button and leaving a 'recheck' comment to get fresh test results.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-05-07: Change abandoned on neutron (stable/stein)

#10

Change abandoned by "Bernard Cafarelli <email address hidden>" on branch: stable/stein
Review: https://review.opendev.org/c/openstack/neutron/+/774489
Reason: train review is abandoned, don't hesitate to reopen this one if you still plan to work on it (and have train one fixed)

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-05-13: Fix merged to neutron (stable/train)

#11

Reviewed: https://review.opendev.org/c/openstack/neutron/+/774585
Committed: https://opendev.org/openstack/neutron/commit/3e06f40e3dfe3e39c4b13bebc3fe5ce1abb08cba
Submitter: "Zuul (22348)"
Branch: stable/train

commit 3e06f40e3dfe3e39c4b13bebc3fe5ce1abb08cba
Author: yangjianfeng <email address hidden>
Date: Sat Feb 6 02:13:04 2021 +0000

Fix incorrect exception catch when update floating ip port forwarding

    Closes-Bug: #1912596
    Change-Id: Ib1a95dd41d25f39f3378a6728d752a6589b9b61c
    (cherry picked from commit e9e4395d578e40bb59272b409c7ca3617ec1e6e3)

tags:

added: in-stable-train

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-05-18: Fix merged to neutron (stable/stein)

#12

Reviewed: https://review.opendev.org/c/openstack/neutron/+/774489
Committed: https://opendev.org/openstack/neutron/commit/b536fc0159ec107622eb3c855d555e32cd655aa4
Submitter: "Zuul (22348)"
Branch: stable/stein

commit b536fc0159ec107622eb3c855d555e32cd655aa4
Author: yangjianfeng <email address hidden>
Date: Sat Feb 6 02:13:04 2021 +0000

Fix incorrect exception catch when update floating ip port forwarding

    Closes-Bug: #1912596
    Change-Id: Ib1a95dd41d25f39f3378a6728d752a6589b9b61c
    (cherry picked from commit e9e4395d578e40bb59272b409c7ca3617ec1e6e3)

tags:

added: in-stable-stein

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2021-05-22: Change abandoned on neutron (stable/rocky)

#13

Change abandoned by "yangjianfeng <email address hidden>" on branch: stable/rocky
Review: https://review.opendev.org/c/openstack/neutron/+/774590

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2022-11-18: Fix included in openstack/neutron stein-eol

#14

This issue was fixed in the openstack/neutron stein-eol release.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-10-10: Fix included in openstack/neutron train-eol

#15

This issue was fixed in the openstack/neutron train-eol release.

neutron

neutron-server report 500 error when update floating ip port forwarding

Bug Description

Other bug subscribers

Remote bug watches