KeyError in DHPC RPC when port_update happens.- this is seen when a delete_port event occurs

Bug #1378508 reported by Swaminathan Vasudevan
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
neutron
Fix Released
High
Numan Siddique
Juno
Fix Released
Undecided
Numan Siddique

Bug Description

When there is a delete_port event occassionally we are seeing a TRACE in dhcp_rpc.py file.

2014-10-07 12:31:39.803 DEBUG neutron.api.rpc.handlers.dhcp_rpc [req-803de1d2-a128-41f1-8686-2bec72c61f5a None None] Update dhcp port {u'port': {u'network_id': u'12548499-8387-480e-b29c-625dbf320ecf', u'fixed_ips': [{u'subnet_id': u'88031ffe-9149-4e96-a022-65468f6bcc0e'}]}} from ubuntu. from (pid=4414) update_dhcp_port /opt/stack/neutron/neutron/api/rpc/handlers/dhcp_rpc.py:290
2014-10-07 12:31:39.803 DEBUG neutron.openstack.common.lockutils [req-803de1d2-a128-41f1-8686-2bec72c61f5a None None] Got semaphore "db-access" from (pid=4414) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168
2014-10-07 12:31:39.832 ERROR oslo.messaging.rpc.dispatcher [req-803de1d2-a128-41f1-8686-2bec72c61f5a None None] Exception during message handling: 'network_id'
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/neutron/neutron/api/rpc/handlers/dhcp_rpc.py", line 294, in update_dhcp_port
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher 'update_port')
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/neutron/neutron/api/rpc/handlers/dhcp_rpc.py", line 81, in _port_action
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher net_id = port['port']['network_id']
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher KeyError: 'network_id'
2014-10-07 12:31:39.832 TRACE oslo.messaging.rpc.dispatcher
2014-10-07 12:31:39.833 ERROR oslo.messaging._drivers.common [req-803de1d2-a128-41f1-8686-2bec72c61f5a None None] Returning exception 'network_id' to caller
2014-10-07 12:31:39.833 ERROR oslo.messaging._drivers.common [req-803de1d2-a128-41f1-8686-2bec72c61f5a None None] ['Traceback (most recent call last):\n', ' File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply\n incoming.message))\n', ' File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', ' File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch\n result = getattr(endpoint, method)(ctxt, **new_args)\n', ' File "/opt/stack/neutron/neutron/api/rpc/handlers/dhcp_rpc.py", line 294, in update_dhcp_port\n \'update_port\')\n', ' File "/opt/stack/neutron/neutron/api/rpc/handlers/dhcp_rpc.py", line 81, in _port_action\n net_id = port[\'port\'][\'network_id\']\n', "KeyError: 'network_id'\n"]
2014-10-07 12:31:39.839 DEBUG neutron.context [req-7d40234b-6e11-4645-9bab-8f9958df5064 None None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} from (pid=4414) __init__ /opt/stack/neutron/neutron/context.py:83

Changed in neutron:
assignee: nobody → Numan Siddique (numansiddique)
Revision history for this message
Eugene Nikanorov (enikanorov) wrote :

Which plugin and openstack version are you using? Is it master?

Changed in neutron:
importance: Undecided → High
tags: added: l3-ipam-dhcp
Changed in neutron:
status: New → Incomplete
Revision history for this message
Swaminathan Vasudevan (swaminathan-vasudevan) wrote :

Hi Eugene,
Yes this is seen in the master while I was testing the "dvr".
Since it was specific to the dhcp, I did not tag it to "l3-dvr-backlog".

Revision history for this message
Numan Siddique (numansiddique) wrote :

Hi Swaminathan,
Can you please share the steps you used to reproduce the issue. Can you share what neutron CLI commands you used

Thanks

Revision history for this message
Numan Siddique (numansiddique) wrote :

Found the cause of the issue.
I will submit the patch shortly

Changed in neutron:
status: Incomplete → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (master)

Fix proposed to branch: master
Review: https://review.openstack.org/127746

Changed in neutron:
status: In Progress → Incomplete
assignee: Numan Siddique (numansiddique) → nobody
Revision history for this message
Numan Siddique (numansiddique) wrote :

IMHO this is a valid bug.

Revision history for this message
Numan Siddique (numansiddique) wrote :

Armando - my apologies. I wasn't aware that the bug status is decided by the cores and without knowing it I changed from Incomplete to InProgress.

Revision history for this message
Armando Migliaccio (armando-migliaccio) wrote :

I agree that the bug is valid. I marked it incomplete because I wanted to solicit more input from author. The trace may be genuine but it may be the manifestation of some different issue. Gettting rid of the trace is fine. But what if there is a larger problem at play? W cannot determine whether the fix is complete.

Changed in neutron:
assignee: nobody → Numan Siddique (numansiddique)
Changed in neutron:
status: Incomplete → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (master)

Reviewed: https://review.openstack.org/127746
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=7ea605df3ac71dc568194bcd5eaf1c115008e1ee
Submitter: Jenkins
Branch: master

commit 7ea605df3ac71dc568194bcd5eaf1c115008e1ee
Author: Numan Siddique <email address hidden>
Date: Sat Oct 11 17:38:05 2014 +0530

    Fix KeyError in dhcp_rpc when plugin.port_update raise exception

    KeyError exception is seen because of following reasons

    * DhcpRpcCallback._port_action() is called by two functions
       - DhcpRpcCallback.create_dchp_port()
       - DhcpRpcCallback.update_dhcp_port()

    * When create_dhcp_port() function calls _port_action(), the
      function argument 'port' will have the body as
      {'port': {'network_id': foo_network_id, 'fixed_ips': [..] ...}

    * When update_dhcp_port() function calls _port_action(), the
      function argument 'port' will have the body as
      {'id': port_id, 'port': {{'port': {'network_id': foo_network_id,
                   'fixed_ips': [..] ...}}

    * If an exception occurs when _port_action() calls plugin.create_port(),
      network id is accessed as
      net_id = port['port']['network_id']

    * If an exception occurs when _port_action() calls plugin.update_port(),
      network id is accessed as
      net_id = port['port']['network_id']
      which is causing the KeyError. network_id should have been accessed as
      net_id = port['port']['port']['network_id']

    This patch fixes the issue by making the _port_action() take the
    same port body. update_dhcp_port() insteading of passing the port_id
    and port information in a single argument, it now adds port_id
    in the port body itself.

    Change-Id: I70b92fa20b421b05ca2053a9a57f62db726f7625
    Closes-bug: #1378508

Changed in neutron:
status: In Progress → Fix Committed
Revision history for this message
Numan Siddique (numansiddique) wrote :

Is this fix required for proposed/juno ?

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to neutron (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/128864

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on neutron (master)

Change abandoned by Kevin Benton (<email address hidden>) on branch: master
Review: https://review.openstack.org/128864

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (feature/lbaasv2)

Fix proposed to branch: feature/lbaasv2
Review: https://review.openstack.org/130864

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (feature/lbaasv2)
Download full text (72.6 KiB)

Reviewed: https://review.openstack.org/130864
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=c089154a94e5872efc95eab33d3d0c9de8619fe4
Submitter: Jenkins
Branch: feature/lbaasv2

commit 62588957fbeccfb4f80eaa72bef2b86b6f08dcf8
Author: Kevin Benton <email address hidden>
Date: Wed Oct 22 13:04:03 2014 -0700

    Big Switch: Switch to TLSv1 in server manager

    Switch to TLSv1 for the connections to the backend
    controllers. The default SSLv3 is no longer considered
    secure.

    TLSv1 was chosen over .1 or .2 because the .1 and .2 weren't
    added until python 2.7.9 so TLSv1 is the only compatible option
    for py26.

    Closes-Bug: #1384487
    Change-Id: I68bd72fc4d90a102003d9ce48c47a4a6a3dd6e03

commit 17204e8f02fdad046dabdb8b31397289d72c877b
Author: OpenStack Proposal Bot <email address hidden>
Date: Wed Oct 22 06:20:15 2014 +0000

    Imported Translations from Transifex

    For more information about this automatic import see:
    https://wiki.openstack.org/wiki/Translations/Infrastructure

    Change-Id: I58db0476c810aa901463b07c42182eef0adb5114

commit d712663b99520e6d26269b0ca193527603178742
Author: Carl Baldwin <email address hidden>
Date: Mon Oct 20 21:48:42 2014 +0000

    Move disabling of metadata and ipv6_ra to _destroy_router_namespace

    I noticed that disable_ipv6_ra is called from the wrong place and that
    in some cases it was called with a bogus router_id because the code
    made an incorrect assumption about the context. In other case, it was
    never called because _destroy_router_namespace was being called
    directly. This patch moves the disabling of metadata and ipv6_ra in
    to _destroy_router_namespace to ensure they get called correctly and
    avoid duplication.

    Change-Id: Ia76a5ff4200df072b60481f2ee49286b78ece6c4
    Closes-Bug: #1383495

commit f82a5117f6f484a649eadff4b0e6be9a5a4d18bb
Author: OpenStack Proposal Bot <email address hidden>
Date: Tue Oct 21 12:11:19 2014 +0000

    Updated from global requirements

    Change-Id: Idcbd730f5c781d21ea75e7bfb15959c8f517980f

commit be6bd82d43fbcb8d1512d8eb5b7a106332364c31
Author: Angus Lees <email address hidden>
Date: Mon Aug 25 12:14:29 2014 +1000

    Remove duplicate import of constants module

    .. and enable corresponding pylint check now the only offending instance
    is fixed.

    Change-Id: I35a12ace46c872446b8c87d0aacce45e94d71bae

commit 9902400039018d77aa3034147cfb24ca4b2353f6
Author: rajeev <email address hidden>
Date: Mon Oct 13 16:25:36 2014 -0400

    Fix race condition on processing DVR floating IPs

    Fip namespace and agent gateway port can be shared by multiple dvr routers.
    This change uses a set as the control variable for these shared resources
    and ensures that Test and Set operation on the control variable are
    performed atomically so that race conditions do not occur among
    multiple threads processing floating IPs.
    Limitation: The scope of this change is limited to addressing the race
    condition described in the bug report. It may not address other issues
    such as pre-existing issue wit...

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to neutron (stable/juno)

Fix proposed to branch: stable/juno
Review: https://review.openstack.org/133940

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to neutron (stable/juno)

Reviewed: https://review.openstack.org/133940
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=b0d3e7423c2b0eb95a1df00ba479cd9ed896c116
Submitter: Jenkins
Branch: stable/juno

commit b0d3e7423c2b0eb95a1df00ba479cd9ed896c116
Author: Numan Siddique <email address hidden>
Date: Sat Oct 11 17:38:05 2014 +0530

    Fix KeyError in dhcp_rpc when plugin.port_update raise exception

    KeyError exception is seen because of following reasons

    * DhcpRpcCallback._port_action() is called by two functions
       - DhcpRpcCallback.create_dchp_port()
       - DhcpRpcCallback.update_dhcp_port()

    * When create_dhcp_port() function calls _port_action(), the
      function argument 'port' will have the body as
      {'port': {'network_id': foo_network_id, 'fixed_ips': [..] ...}

    * When update_dhcp_port() function calls _port_action(), the
      function argument 'port' will have the body as
      {'id': port_id, 'port': {{'port': {'network_id': foo_network_id,
                   'fixed_ips': [..] ...}}

    * If an exception occurs when _port_action() calls plugin.create_port(),
      network id is accessed as
      net_id = port['port']['network_id']

    * If an exception occurs when _port_action() calls plugin.update_port(),
      network id is accessed as
      net_id = port['port']['network_id']
      which is causing the KeyError. network_id should have been accessed as
      net_id = port['port']['port']['network_id']

    This patch fixes the issue by making the _port_action() take the
    same port body. update_dhcp_port() insteading of passing the port_id
    and port information in a single argument, it now adds port_id
    in the port body itself.

    Change-Id: I70b92fa20b421b05ca2053a9a57f62db726f7625
    Closes-bug: #1378508
    (cherry picked from commit 7ea605df3ac71dc568194bcd5eaf1c115008e1ee)

tags: added: in-stable-juno
Thierry Carrez (ttx)
Changed in neutron:
milestone: none → kilo-1
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in neutron:
milestone: kilo-1 → 2015.1.0
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.