NoFilterMatched when kill metadata proxy process in external_process.disable method

Bug #1617864 reported by hujin
14
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
Invalid
Medium
hujin

Bug Description

l3_agent.log

2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task [req-b879a237-49a6-4ae0-ae5a-b52fff1be64e - - - - -] Error during L3NATAgentWithStateReport.periodic_sync_routers_task
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task Traceback (most recent call last):
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/oslo_service/periodic_task.py", line 220, in run_periodic_tasks
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task task(self, context)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/l3/agent.py", line 547, in periodic_sync_routers_task
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task self.fetch_and_sync_all_routers(context, ns_manager)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/l3/namespace_manager.py", line 90, in __exit__
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task self._cleanup(_ns_prefix, ns_id)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/l3/namespace_manager.py", line 140, in _cleanup
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task self.process_monitor, ns_id, self.agent_conf)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/metadata/driver.py", line 131, in destroy_monitored_metadata_proxy
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task pm.disable()
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/linux/external_process.py", line 109, in disable
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task utils.execute(cmd, run_as_root=True)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 116, in execute
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task execute_rootwrap_daemon(cmd, process_input, addl_env))
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 102, in execute_rootwrap_daemon
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task return client.execute(cmd, process_input)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib/python2.7/site-packages/oslo_rootwrap/client.py", line 128, in execute
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task res = proxy.run_one_command(cmd, stdin)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "<string>", line 2, in run_one_command
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task File "/usr/lib64/python2.7/multiprocessing/managers.py", line 773, in _callmethod
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task raise convert_to_error(kind, result)
2016-08-26 03:02:08.356 30726 ERROR oslo_service.periodic_task NoFilterMatched

dhcp_agent.log

2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher [req-17ab00ea-166d-402f-8233-01e4c6fdc840 be5b0cbb38af4b18b2e4fd26bbe832d8 aef8e3f16eb549d39bb6585c68b84442 - - -] Exception during message handling:
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 138, in _dispatch_and_reply
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher incoming.message))
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _dispatch
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 127, in _do_dispatch
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 271, in inner
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 313, in network_delete_end
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher self.disable_dhcp_helper(payload['network_id'])
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 266, in disable_dhcp_helper
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher self.disable_isolated_metadata_proxy(network)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 406, in disable_isolated_metadata_proxy
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher self._process_monitor, uuid, self.conf)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/metadata/driver.py", line 131, in destroy_monitored_metadata_proxy
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher pm.disable()
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/linux/external_process.py", line 109, in disable
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher utils.execute(cmd, run_as_root=True)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 116, in execute
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher execute_rootwrap_daemon(cmd, process_input, addl_env))
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 102, in execute_rootwrap_daemon
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher return client.execute(cmd, process_input)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_rootwrap/client.py", line 128, in execute
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher res = proxy.run_one_command(cmd, stdin)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "<string>", line 2, in run_one_command
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher File "/usr/lib64/python2.7/multiprocessing/managers.py", line 773, in _callmethod
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher raise convert_to_error(kind, result)
2016-08-25 16:27:15.597 27017 ERROR oslo_messaging.rpc.dispatcher NoFilterMatched

this consumes memory, cpu, disk.

Revision history for this message
hujin (hujin) wrote :

I found that metadata proxy process started by python2 which is not allowed in rootwrap file

[root@type-controller neutron]# ps -ef|grep metadata
neutron 528 1 0 Aug24 ? 00:00:00 /usr/bin/python2 /bin/neutron-ns-metadata-proxy --pid_file=/var/lib/neutron/external/pids/e28e93ae-304f-4a4e-a3bd-c775928e5908.pid --metadata_proxy_socket=/var/lib/neutron/metadata_proxy --router_id=e28e93ae-304f-4a4e-a3bd-c775928e5908 --state_path=/var/lib/neutron --metadata_port=9697 --metadata_proxy_user=991 --metadata_proxy_group=988 --verbose --log-file=neutron-ns-metadata-proxy-e28e93ae-304f-4a4e-a3bd-c775928e5908.log --log-dir=/var/log/neutron
neutron 955 1 0 Aug17 ? 00:00:01 /usr/bin/python2 /bin/neutron-ns-metadata-proxy --pid_file=/var/lib/neutron/external/pids/c9a49fb1-7e27-42fb-afd3-e42cc14dc2ac.pid --metadata_proxy_socket=/var/lib/neutron/metadata_proxy --router_id=c9a49fb1-7e27-42fb-afd3-e42cc14dc2ac --state_path=/var/lib/neutron --metadata_port=9697 --metadata_proxy_user=991 --metadata_proxy_group=988 --verbose --log-file=neutron-ns-metadata-proxy-c9a49fb1-7e27-42fb-afd3-e42cc14dc2ac.log --log-dir=/var/log/neutron

[root@type-controller neutron]# cd /usr/share/neutron/rootwrap/
[root@type-controller rootwrap]# cat l3.filters
# neutron-rootwrap command filters for nodes on which neutron is
# expected to control network
#
# This file should be owned by (and only-writeable by) the root user

# format seems to be
# cmd-name: filter-name, raw-command, user, args

[Filters]

# arping
arping: CommandFilter, arping, root

# l3_agent
sysctl: CommandFilter, sysctl, root
route: CommandFilter, route, root
radvd: CommandFilter, radvd, root

# metadata proxy
metadata_proxy: CommandFilter, neutron-ns-metadata-proxy, root
# RHEL invocation of the metadata proxy will report /usr/bin/python
kill_metadata: KillFilter, root, python, -9
kill_metadata7: KillFilter, root, python2.7, -9
kill_radvd_usr: KillFilter, root, /usr/sbin/radvd, -9, -HUP
kill_radvd: KillFilter, root, /sbin/radvd, -9, -HUP

Changed in neutron:
assignee: nobody → hujin (hujin)
status: New → In Progress
Changed in neutron:
importance: Undecided → Medium
Revision history for this message
Brian Haley (brian-haley) wrote :

/usr/bin/python2 is usually a symlink to python2.7 (as is /usr/bin/python) - I guess I'm curious what was set in your environment that it wasn't just using 'python' ?

Revision history for this message
zhaobo (zhaobo6) wrote :

The same as Brian Haley, This must be related with your env.

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

Change abandoned by Armando Migliaccio (<email address hidden>) on branch: master
Review: https://review.openstack.org/361799
Reason: This review is > 4 weeks without comment, and failed Jenkins 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.

Changed in neutron:
status: In Progress → Invalid
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.