Public bug reported: Even if DHCP namespace creation fails at the network node due to some reason, neutron API still returns success to the user.
2016-01-18 02:51:12.661 ^[[00;32mDEBUG neutron.agent.dhcp.agent [^[[01 ;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mCalling driver for network: 351d9017-6e92-4310-ae6d-cf1d0bce0b14 action: enable^[[00m ^[[00;33mfrom (pid=26547) call_driver /opt/stack/neutron/neutron/agent/dhcp/agent.py:104 2016-01-18 02:51:12.662 ^[[00;32mDEBUG neutron.agent.linux.dhcp [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mDHCP port dhcpa382383f-19b6-5ca7-94ec-5ec1e62dc705-351d9017-6e92-4310-ae6d-cf1d0bce0b14 on network 351d9017-6e92-4310-ae6d-cf1d0bce0b14 does not yet exist. Checking for a reserved port.^[[00m ^[[00;33mfrom (pid=26547) _setup_reserved_dhcp_port /opt/stack/neutron/neutron/agent/linux/dhcp.py:1098^[[00m 2016-01-18 02:51:12.663 ^[[00;32mDEBUG neutron.agent.linux.dhcp [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mDHCP port dhcpa382383f-19b6-5ca7-94ec-5ec1e62dc705-351d9017-6e92-4310-ae6d-cf1d0bce0b14 on network 351d9017-6e92-4310-ae6d-cf1d0bce0b14 does not yet exist. Creating new one.^[[00m ^[[00;33mfrom (pid=26547) _setup_new_dhcp_port /opt/stack/neutron/neutron/agent/linux/dhcp.py:1119 2016-01-18 02:51:13.000 ^[[01;31mERROR neutron.agent.dhcp.agent [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[01;31m] ^[[01;35m^[[01;31mUnable to enable dhcp for 351d9017-6e92-4310-ae6d-cf1d0bce0b14.^[[00m ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00mTraceback (most recent call last): ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/dhcp/agent.py", line 113, in call_driver ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m getattr(driver, action)(**action_kwargs) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/dhcp.py", line 206, in enable ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m interface_name = self.device_manager.setup(self.network) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/dhcp.py", line 1206, in setup ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m namespace=network.namespace) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/interface.py", line 243, in plug ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m bridge, namespace, prefix) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/interface.py", line 311, in plug_new ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m self.check_bridge_exists(bridge) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/interface.py", line 220, in check_bridge_exists ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m if not ip_lib.device_exists(bridge): ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 908, in device_exists ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return IPDevice(device_name, namespace=namespace).exists() ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 265, in exists ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return bool(self.link.address) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 482, in address ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return self.attributes.get('link/ether') ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 506, in attributes ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return self._parse_line(self._run(['o'], ('show', self.name))) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 315, in _run ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return self._parent._run(options, self.COMMAND, args) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 87, in _run ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m log_fail_as_error=self.log_fail_as_error) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 103, in _execute ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m log_fail_as_error=log_fail_as_error) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/utils.py", line 119, in execute ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m addl_env=addl_env) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/utils.py", line 88, in create_process ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m stderr=subprocess.PIPE) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/common/utils.py", line 206, in subprocess_popen ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m close_fds=close_fds, env=env) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/usr/local/lib/python2.7/dist-packages/eventlet/green/subprocess.py", line 53, in __init__ ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m subprocess_orig.Popen.__init__(self, args, 0, *argss, **kwds) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/usr/lib/python2.7/subprocess.py", line 710, in __init__ ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m errread, errwrite) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/usr/lib/python2.7/subprocess.py", line 1231, in _execute_child ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m self.pid = os.fork() ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00mOSError: [Errno 12] Cannot allocate memory ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m 2016-01-18 02:51:13.016 ^[[00;32mDEBUG oslo_concurrency.lockutils [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mLock "dhcp-agent" released by "neutron.agent.dhcp.agent.network_create_end" :: held 0.521s^[[00m ^[[00;33mfrom (pid=26547) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282 ** Affects: neutron Importance: High Assignee: Gary Kotton (garyk) Status: New ** Changed in: neutron Assignee: (unassigned) => Gary Kotton (garyk) ** Changed in: neutron Importance: Undecided => High -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to neutron. https://bugs.launchpad.net/bugs/1544548 Title: DHCP: no indication in API that DHCP service is not running Status in neutron: New Bug description: Even if DHCP namespace creation fails at the network node due to some reason, neutron API still returns success to the user. 2016-01-18 02:51:12.661 ^[[00;32mDEBUG neutron.agent.dhcp.agent [^[[01 ;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mCalling driver for network: 351d9017-6e92-4310-ae6d-cf1d0bce0b14 action: enable^[[00m ^[[00;33mfrom (pid=26547) call_driver /opt/stack/neutron/neutron/agent/dhcp/agent.py:104 2016-01-18 02:51:12.662 ^[[00;32mDEBUG neutron.agent.linux.dhcp [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mDHCP port dhcpa382383f-19b6-5ca7-94ec-5ec1e62dc705-351d9017-6e92-4310-ae6d-cf1d0bce0b14 on network 351d9017-6e92-4310-ae6d-cf1d0bce0b14 does not yet exist. Checking for a reserved port.^[[00m ^[[00;33mfrom (pid=26547) _setup_reserved_dhcp_port /opt/stack/neutron/neutron/agent/linux/dhcp.py:1098^[[00m 2016-01-18 02:51:12.663 ^[[00;32mDEBUG neutron.agent.linux.dhcp [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mDHCP port dhcpa382383f-19b6-5ca7-94ec-5ec1e62dc705-351d9017-6e92-4310-ae6d-cf1d0bce0b14 on network 351d9017-6e92-4310-ae6d-cf1d0bce0b14 does not yet exist. Creating new one.^[[00m ^[[00;33mfrom (pid=26547) _setup_new_dhcp_port /opt/stack/neutron/neutron/agent/linux/dhcp.py:1119 2016-01-18 02:51:13.000 ^[[01;31mERROR neutron.agent.dhcp.agent [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[01;31m] ^[[01;35m^[[01;31mUnable to enable dhcp for 351d9017-6e92-4310-ae6d-cf1d0bce0b14.^[[00m ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00mTraceback (most recent call last): ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/dhcp/agent.py", line 113, in call_driver ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m getattr(driver, action)(**action_kwargs) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/dhcp.py", line 206, in enable ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m interface_name = self.device_manager.setup(self.network) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/dhcp.py", line 1206, in setup ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m namespace=network.namespace) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/interface.py", line 243, in plug ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m bridge, namespace, prefix) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/interface.py", line 311, in plug_new ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m self.check_bridge_exists(bridge) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/interface.py", line 220, in check_bridge_exists ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m if not ip_lib.device_exists(bridge): ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 908, in device_exists ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return IPDevice(device_name, namespace=namespace).exists() ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 265, in exists ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return bool(self.link.address) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 482, in address ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return self.attributes.get('link/ether') ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 506, in attributes ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return self._parse_line(self._run(['o'], ('show', self.name))) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 315, in _run ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m return self._parent._run(options, self.COMMAND, args) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 87, in _run ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m log_fail_as_error=self.log_fail_as_error) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/ip_lib.py", line 103, in _execute ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m log_fail_as_error=log_fail_as_error) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/utils.py", line 119, in execute ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m addl_env=addl_env) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/linux/utils.py", line 88, in create_process ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m stderr=subprocess.PIPE) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/common/utils.py", line 206, in subprocess_popen ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m close_fds=close_fds, env=env) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/usr/local/lib/python2.7/dist-packages/eventlet/green/subprocess.py", line 53, in __init__ ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m subprocess_orig.Popen.__init__(self, args, 0, *argss, **kwds) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/usr/lib/python2.7/subprocess.py", line 710, in __init__ ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m errread, errwrite) ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m File "/usr/lib/python2.7/subprocess.py", line 1231, in _execute_child ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m self.pid = os.fork() ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00mOSError: [Errno 12] Cannot allocate memory ^[[01;31m2016-01-18 02:51:13.000 TRACE neutron.agent.dhcp.agent ^[[01;35m^[[00m 2016-01-18 02:51:13.016 ^[[00;32mDEBUG oslo_concurrency.lockutils [^[[01;36mreq-f6d7a436-b9ff-45ca-9cfc-0f147b97effb ^[[00;36mctx_rally_bbaa10b4eb2749b3a09b375682b6cb6e_user_0 bbaa10b4eb2749b3a09b375682b6cb6e^[[00;32m] ^[[01;35m^[[00;32mLock "dhcp-agent" released by "neutron.agent.dhcp.agent.network_create_end" :: held 0.521s^[[00m ^[[00;33mfrom (pid=26547) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:282 To manage notifications about this bug go to: https://bugs.launchpad.net/neutron/+bug/1544548/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : yahoo-eng-team@lists.launchpad.net Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp