yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1561540] Re: Neutron dhcp agent not able to provide dhcp ip to VM

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Narinder Gupta <1561540@xxxxxxxxxxxxxxxxxx>
Date: Sat, 28 May 2016 04:17:47 -0000
Reply-to: Bug 1561540 <1561540@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: opnfv
       Status: New => Invalid

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1561540

Title:
  Neutron dhcp agent not able to provide dhcp ip to VM

Status in neutron:
  Invalid
Status in OPNFV:
  Invalid

Bug description:
  VMs are not getting an ip from dhcp.  Occasionally a VM may get an ip.

  Pre-conditions: OpenStack (Liberty, HA, OpenDaylight) built via OPNFV
  JOID (Canonical) deployment automation that leverages MAAS/Juju.

  Whoami:  JOID user.  This is my first neutron reported bug.

  ubuntu@juma:~$ neutron --version
  3.1.0

  Perceived severity: is this a blocker for my project.

  Error seen in dhcp-agent.log:
  2016-03-24 02:04:52.245 23148 ERROR oslo.messaging._drivers.impl_rabbit [req-e5037584-e5c6-4dc5-961b-6300b372f60b - - - - -] AMQP server on 127.0.0.1:5672 is unreachable: [Errno 111] ECONNREFUSED. Trying again in 2 seconds.
  /Error
  2016-03-24 02:15:34.895 6657 ERROR neutron.agent.dhcp.agent     message = self.waiters.get(msg_id, timeout=timeout)
  2016-03-24 02:15:34.895 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 223, in get
  2016-03-24 02:15:34.895 6657 ERROR neutron.agent.dhcp.agent     'to message ID %s' % msg_id)
  2016-03-24 02:15:34.895 6657 ERROR neutron.agent.dhcp.agent MessagingTimeout: Timed out waiting for a reply to message ID 80fcb2ba9c444b1592ef9e7955cea0ba
  2016-03-24 02:15:34.895 6657 ERROR neutron.agent.dhcp.agent
  2016-03-24 02:15:34.896 6657 WARNING oslo.service.loopingcall [req-1009548a-c589-43b4-8a25-cc6d265d9dea - - - - -] Function 'neutron.agent.dhcp.agent.DhcpAgentWithStateReport._report_state' run outlasted interval by 30.01 sec
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent [req-45baaca9-a59d-4b2e-9b28-b0761996e6a9 - - - - -] Failed reporting state!
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent Traceback (most recent call last):
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/neutron/agent/dhcp/agent.py", line 571, in _report_state
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent     ctx, self.agent_state, True)
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/neutron/agent/rpc.py", line 86, in report_state
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent     return method(context, 'report_state', **kwargs)
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent     retry=self.retry)
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent     timeout=timeout, retry=retry)
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent     retry=retry)
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent   File "/usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 422, in _send
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent     raise result
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent RemoteError: Remote error: DBError (pymysql.err.InternalError) (1054, u"Unknown column 'agents.load' in 'field list'") [SQL: u'SELECT agents.id AS agents_id, agents.agent_type AS agents_agent_type, agents.`binary` AS agents_binary, agents.topic AS agents_topic, agents.host AS agents_host, agents.admin_state_up AS agents_admin_state_up, agents.created_at AS agents_created_at, agents.started_at AS agents_started_at, agents.heartbeat_timestamp AS agents_heartbeat_timestamp, agents.description AS agents_description, agents.configurations AS agents_configurations, agents.`load` AS agents_load \nFROM agents \nWHERE agents.agent_type = %s AND agents.host = %s'] [parameters: (u'DHCP agent', u'node4-control')]
  2016-03-24 02:15:34.969 6657 ERROR neutron.agent.dhcp.agent [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply\n    executor_callback))\n', u'  File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch\n    executor_callback)\n', u'  File "/usr/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch\n    result = func(ctxt, **new_args)\n', u'  File "/usr/lib/python2.7/dist-packages/neutron/db/agents_db.py", line 317, in report_state\n    return self.plugin.create_or_update_agent(context, agent_state)\n', u'  File "/usr/lib/python2.7/dist-packages/neutron/db/agents_db.py", line 265, in create_or_update_agent\n    return self._create_or_update_agent(context, agent)\n', u'  File "/usr/lib/python2.7/dist-packages/neutron/db/agents_db.py", line 238, in _create_or_update_agent\n    context, agent_state[\'agent_type\'], agent_state[\'host\'])\n', u'  File "/usr/lib/python2.7/dist-packages/neutron/db/agents_db.py", line 198, in _get_agent_by_type_and_host\n    Agent.host == host).one()\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2473, in one\n    ret = list(self)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2516, in __iter__\n    return self._execute_and_instances(context)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2531, in _execute_and_instances\n    result = conn.execute(querycontext.statement, self._params)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute\n    return meth(self, multiparams, params)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection\n    return connection._execute_clauseelement(self, multiparams, params)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement\n    compiled_sql, distilled_params\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context\n    context)\n', u'  File "/usr/lib/python2.7/dist-

  
  packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception\n    util.raise_from_cause(newraise, exc_info)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause\n    reraise(type(exception), exception, tb=exc_tb)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context\n    context)\n', u'  File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute\n    cursor.execute(statement, parameters)\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 132, in execute\n    result = self._query(query)\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/cursors.py", line 271, in _query\n    conn.query(q)\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 726, in query\n    self._affected_rows = self._read_query_result(unbuffered=unbuffered)\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 861, in _read_query_result\n    result.read()\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 1064, in read\n    first_packet = self.connection._read_packet()\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 826, in _read_packet\n    packet.check_error()\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/connections.py", line 370, in check_error\n    raise_mysql_exception(self._data)\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/err.py", line 116, in raise_mysql_exception\n    _check_mysql_exception(errinfo)\n', u'  File "/usr/lib/python2.7/dist-packages/pymysql/err.py", line 112, in _check_mysql_exception\n    raise InternalError(errno, errorvalue)\n', u'DBError: (pymysql.err.InternalError) (1054, u"Unknown column \'agents.load\' in \'field list\'") [SQL: u\'SELECT agents.id AS agents_id, agents.agent_type AS agents_agent_type, agents.`binary` AS agents_binary, agents.topic AS agents_topic, agents.host AS agents_host, agents.admin_state_up AS agents_admin_state_up, agents.created_at AS agents_created_at, agents.started_at AS agents_started_at, agents.heartbeat_timestamp AS agents_heartbeat_timestamp, agents.description AS agents_description, agents.configurations AS agents_configurations, agents.`load` AS agents_load \\nFROM agents \\nWHERE agents.agent_type = %s AND agents.host = %s\'] [parameters: (u\'DHCP agent\', u\'node4-control\')]\n'].

  
  Full logs are at:
  ubuntu@node4-control:/var/log/neutron$ pastebinit < dhcp-agent.log
  http://paste.ubuntu.com/15487135/
  ubuntu@node4-control:/var/log/neutron$ pastebinit < l3-agent.log
  http://paste.ubuntu.com/15487137/
  ubuntu@node4-control:/var/log/neutron$ pastebinit < neutron-lbaas-agent.log
  http://paste.ubuntu.com/15487138/
  ubuntu@node4-control:/var/log/neutron$ pastebinit < neutron-metering-agent.log
  http://paste.ubuntu.com/15487143/
  ubuntu@node4-control:/var/log/neutron$ pastebinit < neutron-ns-metadata-proxy-7feece98-fdd4-4b44-b4b8-0a6b5bdfd08d.log
  http://paste.ubuntu.com/15487146/

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1561540/+subscriptions
References

[Bug 1561540] [NEW] Neutron dhcp agent not able to provide dhcp ip to VM
From: Dave Urschatz, 2016-03-24