neutron

l3-agent print the ERROR log in l3 log file continuously ,finally fill file space,leading to crash the l3-agent service

Bug #1632540 reported by zhichao zhu on 2016-10-12

This bug affects 2 people

Affects		Status	Importance	Assigned to	Milestone
	neutron	Fix Released	Undecided	Brian Haley

Bug Description

2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent [req-5d499217-05b6-4a56-a3b7-5681adb53d6c - d2b95803757641b6bc55f6309c12c6e9 - - -] Failed to process compatible router 'da82aeb4-07a4-45ca-ae7a-570aec69df29'
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent Traceback (most recent call last):
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 501, in _process_router_update
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self._process_router_if_compatible(router)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 438, in _process_router_if_compatible
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self._process_added_router(router)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 446, in _process_added_router
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent ri.process(self)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_local_router.py", line 488, in process
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(DvrLocalRouter, self).process(agent)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_router_base.py", line 30, in process
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(DvrRouterBase, self).process(agent)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/ha_router.py", line 386, in process
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(HaRouter, self).process(agent)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/common/utils.py", line 385, in call
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.logger(e)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.force_reraise()
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent six.reraise(self.type_, self.value, self.tb)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/common/utils.py", line 382, in call
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent return func(*args, **kwargs)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/router_info.py", line 964, in process
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.process_address_scope()
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_edge_router.py", line 239, in process_address_scope
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.snat_iptables_manager, ports_scopemark)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.gen.next()
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/linux/iptables_manager.py", line 461, in defer_apply
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent raise n_exc.IpTablesApplyException(msg)
2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent IpTablesApplyException: Failure applying iptables rules

for example,this ERROR information will fill l3-agent log file continuously until solving the problem ,it will fill the log file space.

because we resyc the ERROR update into the queue when the update is not been handle successfully.then the greenthread in l3-agent will deal with the update periodicly,so print the log periodicly, but the l3 agent has been deal with this update,wo should delete this update.

we could disable l3-agent in a networknode in ha model, then create router,then restart the l3-agent ，we will see this problem。

See original description

Tags:

zhichao zhu (rtmdk) on 2016-10-12

Changed in neutron:
assignee:	nobody → zhichao zhu (rtmdk)
tags:	added: l3-agent removed: l3-dvr

zhichao zhu (rtmdk) on 2016-10-12

description:	updated
tags:	added: l3-dvr-backlog removed: l3-agent

zhichao zhu (rtmdk) on 2016-10-12

description:

updated

Revision history for this message

Brian Haley (brian-haley) wrote on 2016-10-12:

What branch is this against? The line numbers don't line-up with current master branch.

Revision history for this message

zhichao zhu (rtmdk) wrote on 2016-10-12:

stable/mitak tag 8.1.2

Revision history for this message

Swaminathan Vasudevan (swaminathan-vasudevan) wrote on 2016-10-12:

Do you mean you can recreate this problem just by have a DVR+HA+L3 enabled and then kill the l3 agent and create a router while the L3 agent is down and restart the l3 agent.
Then we should be able to see this problem. Is this right steps to reproduce?

Revision history for this message

zhichao zhu (rtmdk) wrote on 2016-10-12: Re:[Bug 1632540] Re: l3-agent print the ERROR log in l3 log file continuously , finally fill file space, leading to crash the l3-agent service

Download full text (5.4 KiB)

yes，you get the setep to recreate this problem。 i try to solve this problem,but it's difficult to me .i will git commit the modification to gerrit about this bug ,please give some advice

At 2016-10-12 22:55:36, "Swaminathan Vasudevan" <email address hidden> wrote:
>Do you mean you can recreate this problem just by have a DVR+HA+L3 enabled and then kill the l3 agent and create a router while the L3 agent is down and restart the l3 agent.
>Then we should be able to see this problem. Is this right steps to reproduce?
>
>--
>You received this bug notification because you are subscribed to the bug
>report.
>https://bugs.launchpad.net/bugs/1632540
>
>Title:
> l3-agent print the ERROR log in l3 log file continuously ,finally fill
> file space,leading to crash the l3-agent service
>
>Status in neutron:
> New
>
>Bug description:
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent [req-5d499217-05b6-4a56-a3b7-5681adb53d6c - d2b95803757641b6bc55f6309c12c6e9 - - -] Failed to process compatible router 'da82aeb4-07a4-45ca-ae7a-570aec69df29'
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent Traceback (most recent call last):
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 501, in _process_router_update
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self._process_router_if_compatible(router)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 438, in _process_router_if_compatible
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self._process_added_router(router)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 446, in _process_added_router
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent ri.process(self)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_local_router.py", line 488, in process
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(DvrLocalRouter, self).process(agent)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_router_base.py", line 30, in process
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(DvrRouterBase, self).process(agent)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/ha_router.py", line 386, in process
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(HaRouter, self).process(agent)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/common/utils.py", line 385, in call
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.logger(e)
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
> 2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.force_reraise()
> 2016-10-1...

yes，you get the setep to recreate this problem。 i try to solve this problem,but it's difficult to me .i will git commit the modification to gerrit about this bug ,please give some advice

At 2016-10-12 22:55:36, "Swaminathan Vasudevan" <swaminathan.vasudevan@hp.com> wrote:
>Do you mean you can recreate this problem just by have a DVR+HA+L3 enabled and then kill the l3 agent and create a router while the L3 agent is down and restart the l3 agent.
>Then we should be able to see this problem. Is this right steps to reproduce?
>
>-- 
>You received this bug notification because you are subscribed to the bug
>report.
>https://bugs.launchpad.net/bugs/1632540
>
>Title:
>  l3-agent print the ERROR log in l3 log file continuously ,finally fill
>  file space,leading to crash the l3-agent service
>
>Status in neutron:
>  New
>
>Bug description:
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent [req-5d499217-05b6-4a56-a3b7-5681adb53d6c - d2b95803757641b6bc55f6309c12c6e9 - - -] Failed to process compatible router 'da82aeb4-07a4-45ca-ae7a-570aec69df29'
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent Traceback (most recent call last):
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 501, in _process_router_update
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self._process_router_if_compatible(router)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 438, in _process_router_if_compatible
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self._process_added_router(router)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 446, in _process_added_router
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent ri.process(self)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_local_router.py", line 488, in process
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(DvrLocalRouter, self).process(agent)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_router_base.py", line 30, in process
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(DvrRouterBase, self).process(agent)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/ha_router.py", line 386, in process
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent super(HaRouter, self).process(agent)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/common/utils.py", line 385, in call
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.logger(e)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.force_reraise()
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent six.reraise(self.type_, self.value, self.tb)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/common/utils.py", line 382, in call
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent return func(*args, **kwargs)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/router_info.py", line 964, in process
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.process_address_scope()
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/l3/dvr_edge_router.py", line 239, in process_address_scope
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.snat_iptables_manager, ports_scopemark)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib64/python2.7/contextlib.py", line 24, in __exit__
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent self.gen.next()
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent File "/usr/lib/python2.7/site-packages/neutron/agent/linux/iptables_manager.py", line 461, in defer_apply
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent raise n_exc.IpTablesApplyException(msg)
>  2016-10-12 10:04:38.587 25667 ERROR neutron.agent.l3.agent IpTablesApplyException: Failure applying iptables rules
>
>  for example,this ERROR information will fill l3-agent log file
>  continuously until solving the problem ,it will fill the log file
>  space.
>
>  because we resyc the ERROR update into the queue when the update is
>  not been handle successfully.then the greenthread in l3-agent will
>  deal with the update periodicly,so print the log periodicly, but the
>  l3 agent has been deal with this update,wo should delete this update.
>
>  we could disable l3-agent in a networknode in ha model, then create
>  router,then restart the l3-agent ，we will see this problem。
>
>To manage notifications about this bug go to:
>https://bugs.launchpad.net/neutron/+bug/1632540/+subscriptions

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2016-10-13: Fix proposed to neutron (stable/mitaka)

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/385887

Revision history for this message

Brian Haley (brian-haley) wrote on 2016-10-13:

Is there more information in the logs on why the iptables code threw an exception?

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2016-10-13: Fix proposed to neutron (master)

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

Changed in neutron:
status:	New → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2016-10-13: Change abandoned on neutron (master)

Change abandoned by rtmdk (rtmdk@163.com) on branch: master
Review: https://review.openstack.org/386268
Reason: error branch

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2016-10-13: Change abandoned on neutron (stable/mitaka)

Change abandoned by rtmdk (rtmdk@163.com) on branch: stable/mitaka
Review: https://review.openstack.org/385887
Reason: error branch

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2016-10-13: Fix proposed to neutron (master)

#10

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

Revision history for this message

Dariusz Smigiel (smigiel-dariusz) wrote on 2016-10-18:

#11

Please attach all logs

Changed in neutron:
status:	In Progress → Incomplete

Revision history for this message

zhichao zhu (rtmdk) wrote on 2016-10-19:

#12

Download full text (3.8 KiB)

we could disable l3-agent in a networknode in ha model, then create router,then restart the l3-agent ，we will see the root problem。
but in the network node which has been rebooted ,i can find the qrouter namespace of the new router,but i can't see the snat namespace,so appear the followint problem:

2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/agent.py", line 503, in _process_router_update
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent self._process_router_if_compatible(router)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/agent.py", line 440, in _process_router_if_compatible
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent self._process_added_router(router)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/agent.py", line 350, in _router_added
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent super(DvrEdgeHaRouter, self).initialize(process_monitor)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/ha_router.py", line 87, in initialize
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent self.ha_network_added()
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/ha_router.py", line 148, in ha_network_added
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent mtu=self.ha_port.get('mtu'))
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/interface.py", line 249, in plug
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent bridge, namespace, prefix, mtu)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/interface.py", line 342, in plug_new
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent namespace_obj = ip.ensure_namespace(namespace)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 197, in ensure_namespace
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent lo.link.set_up()
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 504, in set_up
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent return self._as_root([], ('set', self.name, 'up'))
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 361, in _as_root
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent use_root_namespace=use_root_namespace)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 94, in _as_root
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent log_fail_as_error=self.log_fail_as_error)
2016-10-...

2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/agent.py", line 503, in _process_router_update
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     self._process_router_if_compatible(router)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/agent.py", line 440, in _process_router_if_compatible
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     self._process_added_router(router)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/agent.py", line 350, in _router_added
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     super(DvrEdgeHaRouter, self).initialize(process_monitor)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/ha_router.py", line 87, in initialize
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     self.ha_network_added()
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/l3/ha_router.py", line 148, in ha_network_added
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     mtu=self.ha_port.get('mtu'))
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/interface.py", line 249, in plug
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     bridge, namespace, prefix, mtu)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/interface.py", line 342, in plug_new
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     namespace_obj = ip.ensure_namespace(namespace)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 197, in ensure_namespace
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     lo.link.set_up()
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 504, in set_up
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     return self._as_root([], ('set', self.name, 'up'))
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 361, in _as_root
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     use_root_namespace=use_root_namespace)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 94, in _as_root
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     log_fail_as_error=self.log_fail_as_error)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/ip_lib.py", line 103, in _execute
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     log_fail_as_error=log_fail_as_error)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent   File "/usr/local/lib/python2.7/dist-packages/neutron/agent/linux/utils.py", line 140, in execute
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent     raise RuntimeError(msg)
2016-10-18 17:12:14.170 1303 ERROR neutron.agent.l3.agent RuntimeError: Exit code: 1; Stdin: ; Stdout: ; Stderr: Cannot open network namespace "snat-845e5c46-0743-4b3e-94bf-fd294b03bb7d": No such file or directory

Revision history for this message

Brian Haley (brian-haley) wrote on 2017-01-11:

#13

A number of changes have merged in Ocata that might have helped to address this issue. Can you re-test with the latest code from the master branch and report back your findings? Thanks.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-02-16:

#14

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

Changed in neutron:
assignee:	zhichao zhu (rtmdk) → Quan Tian (tianquan23)
status:	Incomplete → In Progress

Revision history for this message

Quan Tian (tianquan23) wrote on 2017-02-16:

#15

Hi Brian Haley and Swaminathan Vasudevan, I reproduced the bug in master branch, following the steps:
1. kill a dvr_snat l3 agent
2. create a DVR+HA router
3. start the dvr_snat l3 agent
4. the error logs will continue to be output

The reason is that when the l3 agent does fullsync, for every router, it calls ensure_snat_cleanup depending on whether the agent is dvr_snat or not, since [1]. However, DVR+HA routers always have snat namespaces on dvr_snat agents holding themselves for keepalived. Therefore, the cleanup call is unexpected and cause that the _process_updated_router method always catch an Exception and then put the router back to the RouterProcessingQueue again and again.

[1] https://review.openstack.org/#/c/326729/

I have submitted a patch for this: https://review.openstack.org/434863

Revision history for this message

Quan Tian (tianquan23) wrote on 2017-02-16:

#16

Download full text (3.7 KiB)

The error logs in branch master:

2017-02-16 20:45:18.240 DEBUG neutron.agent.linux.utils [-] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'snat-eaf029d4-424c-45fc-802c-57d16dde3f0e', 'keepalived', '-P', '-f', '/opt/stack/data/neutron/ha_confs/eaf029d4-424c-45fc-802c-57d16dde3f0e/keepalive
d.conf', '-p', '/opt/stack/data/neutron/ha_confs/eaf029d4-424c-45fc-802c-57d16dde3f0e.pid', '-r', '/opt/stack/data/neutron/ha_confs/eaf029d4-424c-45fc-802c-57d16dde3f0e.pid-vrrp'] from (pid=6499) execute_rootwrap_daemon /opt/stack/neutron/neutron/agent/linux/utils.py:11
3
2017-02-16 20:45:18.252 ERROR neutron.agent.linux.utils [-] Exit code: 1; Stdin: ; Stdout: ; Stderr: Cannot open network namespace "snat-eaf029d4-424c-45fc-802c-57d16dde3f0e": No such file or directory

2017-02-16 20:45:18.253 ERROR neutron.agent.l3.agent [-] Failed to process compatible router: eaf029d4-424c-45fc-802c-57d16dde3f0e
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent Traceback (most recent call last):
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/agent.py", line 503, in _process_router_update
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent self._process_router_if_compatible(router)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/agent.py", line 440, in _process_router_if_compatible
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent self._process_updated_router(router)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/agent.py", line 455, in _process_updated_router
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent ri.process()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/dvr_local_router.py", line 646, in process
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent super(DvrLocalRouter, self).process()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/dvr_router_base.py", line 30, in process
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent super(DvrRouterBase, self).process()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/ha_router.py", line 418, in process
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent self.enable_keepalived()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/l3/ha_router.py", line 147, in enable_keepalived
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent self.keepalived_manager.spawn()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/linux/keepalived.py", line 426, in spawn
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent keepalived_pm.enable(reload_cfg=True)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/linux/external_process.py", line 94, in enable
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent run_as_root=self.run_as_root)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 896, in...

The error logs in branch master:

2017-02-16 20:45:18.253 ERROR neutron.agent.l3.agent [-] Failed to process compatible router: eaf029d4-424c-45fc-802c-57d16dde3f0e
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent Traceback (most recent call last):
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/agent.py", line 503, in _process_router_update
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     self._process_router_if_compatible(router)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/agent.py", line 440, in _process_router_if_compatible
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     self._process_updated_router(router)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/agent.py", line 455, in _process_updated_router
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     ri.process()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/dvr_local_router.py", line 646, in process
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     super(DvrLocalRouter, self).process()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/dvr_router_base.py", line 30, in process
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     super(DvrRouterBase, self).process()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/ha_router.py", line 418, in process
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     self.enable_keepalived()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/l3/ha_router.py", line 147, in enable_keepalived
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     self.keepalived_manager.spawn()
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/linux/keepalived.py", line 426, in spawn
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     keepalived_pm.enable(reload_cfg=True)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/linux/external_process.py", line 94, in enable
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     run_as_root=self.run_as_root)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 896, in execute
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     log_fail_as_error=log_fail_as_error, **kwargs)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent   File "/opt/stack/neutron/neutron/agent/linux/utils.py", line 152, in execute
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent     raise ProcessExecutionError(msg, returncode=returncode)
2017-02-16 20:45:18.253 TRACE neutron.agent.l3.agent ProcessExecutionError: Exit code: 1; Stdin: ; Stdout: ; Stderr: Cannot open network namespace "snat-eaf029d4-424c-45fc-802c-57d16dde3f0e": No such file or directory

Brian Haley (brian-haley) on 2017-02-16

tags:

added: newton-backport-potential

Revision history for this message

Saverio Proto (zioproto) wrote on 2017-03-27:

#17

Hello,
we are facing the same bug today in production with Mitaka.

We dont have DVR and we dont have HA.

We get the disk filled up by the log file, with lines like:

2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager [-] Failure applying iptables rules
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager Traceback (most recent call last):
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 457, in defer_apply
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager self.defer_apply_off()
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 468, in defer_apply_off
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager self._apply()
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 482, in _apply
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager return self._apply_synchronized()
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 508, in _apply_synchronized
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager save_output = self.execute(args, run_as_root=True)
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py", line 140, in execute
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager raise RuntimeError(msg)
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager RuntimeError: Exit code: 1; Stdin: ; Stdout: ; Stderr: Cannot open network namespace "qrouter-112b3e2f-ab31-4aa0-9fc4-1e7cc5aa1563": No such file or directory

Hello,
we are facing the same bug today in production with Mitaka.

We dont have DVR and we dont have HA.

We get the disk filled up by the log file, with lines like:

2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager [-] Failure applying iptables rules
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager Traceback (most recent call last):
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager   File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 457, in defer_apply
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager     self.defer_apply_off()
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager   File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 468, in defer_apply_off
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager     self._apply()
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager   File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 482, in _apply
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager     return self._apply_synchronized()
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager   File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/iptables_manager.py", line 508, in _apply_synchronized
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager     save_output = self.execute(args, run_as_root=True)
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager   File "/usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py", line 140, in execute
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager     raise RuntimeError(msg)
2017-03-26 06:44:42.561 20419 ERROR neutron.agent.linux.iptables_manager RuntimeError: Exit code: 1; Stdin: ; Stdout: ; Stderr: Cannot open network namespace "qrouter-112b3e2f-ab31-4aa0-9fc4-1e7cc5aa1563": No such file or directory

Revision history for this message

Saverio Proto (zioproto) wrote on 2017-03-27:

#18

Hello,
I confirm we dont have DVR or HA. In our case what triggered the bug was the time change between CET to CEST in the night of the 26th March 2017.

Because the time jumped from 2:00 am to 3:00 am the neutron server got confused and reported all agents down for about 4 minutes.

OpenStack Infra (hudson-openstack) on 2017-04-06

Changed in neutron:
assignee:	Quan Tian (tianquan23) → Ihar Hrachyshka (ihar-hrachyshka)

OpenStack Infra (hudson-openstack) on 2017-04-11

Changed in neutron:
assignee:	Ihar Hrachyshka (ihar-hrachyshka) → Brian Haley (brian-haley)

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-04-13: Fix proposed to neutron (stable/ocata)

#19

Fix proposed to branch: stable/ocata
Review: https://review.openstack.org/456779

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-04-13: Fix proposed to neutron (stable/newton)

#20

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/456780

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-04-17: Fix merged to neutron (stable/ocata)

#21

Reviewed: https://review.openstack.org/456779
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=4318de7addfdd158ef797963165c09602835891d
Submitter: Jenkins
Branch: stable/ocata

commit 4318de7addfdd158ef797963165c09602835891d
Author: Quan Tian <email address hidden>
Date: Thu Feb 16 20:28:45 2017 +0800

DVR: Don't clean snat-ns of DVR HA router when fullsync

    Since [1], when the l3 agent does fullsync, for every router, it calls
    ensure_snat_cleanup depending on whether the agent is dvr_snat or not.
    However, DVR+HA routers always have snat namespaces on dvr_snat agents
    holding themselves for keepalived. Therefore, the cleanup call is
    unexpected and will cause a series of issues.

This patch ensures that snat namespaces of DVR+HA routers will not be
cleaned when the agent do fullsync.

[1] https://review.openstack.org/#/c/326729/

    Change-Id: I5df0a1404f1a80ab0b226d7a60c2885e24247e02
    Closes-Bug: #1632540
    (cherry picked from commit 1346b4a65701aaec667c8a8a2790ffa345e0efad)

tags:

added: in-stable-ocata

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-05-05: Fix merged to neutron (stable/newton)

#22

Reviewed: https://review.openstack.org/456780
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=636d4a5d204e1d2690594881631a2fa8d84d0b6c
Submitter: Jenkins
Branch: stable/newton

commit 636d4a5d204e1d2690594881631a2fa8d84d0b6c
Author: Quan Tian <email address hidden>
Date: Thu Feb 16 20:28:45 2017 +0800

DVR: Don't clean snat-ns of DVR HA router when fullsync

This patch ensures that snat namespaces of DVR+HA routers will not be
cleaned when the agent do fullsync.

[1] https://review.openstack.org/#/c/326729/

    Change-Id: I5df0a1404f1a80ab0b226d7a60c2885e24247e02
    Closes-Bug: #1632540
    (cherry picked from commit 1346b4a65701aaec667c8a8a2790ffa345e0efad)

tags:

added: in-stable-newton

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-06-01: Fix included in openstack/neutron 9.4.0

#23

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

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-06-01: Fix included in openstack/neutron 10.0.2

#24

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

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-06-09: Fix included in openstack/neutron 11.0.0.0b2

#25

This issue was fixed in the openstack/neutron 11.0.0.0b2 development milestone.

Ihar Hrachyshka (ihar-hrachyshka) on 2017-06-13

tags:

added: neutron-proactive-backport-potential

Ihar Hrachyshka (ihar-hrachyshka) on 2017-06-14

Changed in neutron:
status:	In Progress → Fix Released
tags:	removed: neutron-proactive-backport-potential
tags:	removed: newton-backport-potential

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2017-11-03: Change abandoned on neutron (master)

#26

Change abandoned by zhichao zhu (<email address hidden>) on branch: master
Review: https://review.openstack.org/386272

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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