yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1544548] [NEW] DHCP: no indication in API that DHCP service is not running

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Gary Kotton <1544548@xxxxxxxxxxxxxxxxxx>
Date: Thu, 11 Feb 2016 13:28:34 -0000
Reply-to: Bug 1544548 <1544548@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
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
Follow ups

[Bug 1544548] Re: DHCP: no indication in API that DHCP service is not running
From: OpenStack Infra, 2016-02-17