yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1545584] Re: OVN devstack: Network creation fails when a VM with provider and private network interface is activatied

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Martin Hickey <martin.hickey@xxxxxxxxxx>
Date: Mon, 15 Feb 2016 07:23:29 -0000
Reply-to: Bug 1545584 <1545584@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Project changed: neutron => networking-ovn

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

Title:
  OVN devstack: Network creation fails when a VM with provider and
  private network interface is activatied

Status in networking-ovn:
  New

Bug description:
  We have a 5 node OVN devstack installation. We have created networks,
  subnets, routers and activated VMs on private network.  Then added
  provider network and activated VMs with both private and provider
  network interface.  In this devstack implementation we also started
  two ovsdb servers one with 6640 port and another with 6641.  OVSDB
  6641 connects to OVN contorller plug-in.

  When a VM with both private and provider interface is activated,   I
  see Internal server error,  neutron server log shows connection lost
  in the middle of a mysql operation.

  Rally benchmark is enhanced to activate a VM with both network
  interfaces.

  Rally errors: 
  016-02-12 13:46:36.403 28528 DEBUG neutronclient.client [-] RESP: 500 {'Date': 'Fri, 12 Feb 2016 19:46:36 GMT', 'Connection': 'keep-alive', 'Content-Type':
   'application/json; charset=UTF-8', 'Content-Length': '150', 'X-Openstack-Request-Id': 'req-a5d49508-8501-4802-a46b-674d36a46d23'} {"NeutronError": {"message": 
   "Request Failed: internal server error while processing your request.", "type": "HTTPInternalServerError", "detail": ""}} http_log_resp /usr/lib/python2.7/site-packages/neutronclient/common/utils.py:146
  2016-02-12 13:46:36.403 28528 DEBUG neutronclient.v2_0.client [-] Error message: {"NeutronError": {"message": "Request Failed: internal server error 
  while processing your request.", "type": "HTTPInternalServerError", "detail": ""}} _handle_fault_response 
  /usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py:176
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner [-] Request Failed: internal server error while processing your request.
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner Traceback (most recent call last):
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/rally/task/runner.py", line 64, in _run_scenario_once
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     method_name)(**kwargs) or scenario_output
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/home/stack/sahil/OVN/rally_runs/cnps_ovn.py", line 100, in boot_server_overlay_network
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     self.wait_for_dhcp_port_up()
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/home/stack/sahil/OVN/rally_runs/cnps_ovn.py", line 200, in wait_for_dhcp_port_up
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     dhcp_port_id = self._get_dhcp_port(network_id, poll_count=poll_count)["id"]
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/rally/cnp/cnp_base_scenario.py", line 510, in _get_dhcp_port
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     device_owner=device_owner)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 102, in with_params
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     ret = self.function(instance, *args, **kwargs)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 547, in list_ports
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     **_params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 307, in list
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     for r in self._pagination(collection, path, **params):
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 320, in _pagination
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     res = self.get(path, params=params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 293, in get
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     headers=headers, params=params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 270, in retry_request
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     headers=headers, params=params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     res = self.get(path, params=params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 293, in get
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     headers=headers, params=params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 270, in retry_request
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     headers=headers, params=params)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 211, in do_request
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     self._handle_fault_response(status_code, replybody)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 185, in _handle_fault_response
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     exception_handler_v20(status_code, des_error_body)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner   File "/usr/lib/python2.7/site-packages/neutronclient/v2_0/client.py", line 70, in exception_handler_v20
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner     status_code=status_code)
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner InternalServerError: Request Failed: internal server error while processing your request.
  2016-02-12 13:46:36.405 28528 ERROR rally.task.runner
  2016-02-12 13:46:36.406 28528 INFO rally.task.runner [-] Task 9e9de8e0-bc62-4c3d-a22f-3850f90e8b33 | ITER: 192 END: Error InternalServerError: Request Failed: internal server error while processing your request.
  2016-02-12 13:46:36.406 28528 INFO rally.task.runner [-]  custom_actions : OrderedDict()
  2016-02-12 13:46:36.408 28528 INFO rally.plugins.cnp_runner [-] tenant_runner : cnp_get_scenario_context : tenent_id to use e6be88b56aea4ce8b1b8ecfd9ad945e7

  Tracing back to neutron controller log:
  q-svc.log
  2016-02-12 13:46:29.905 ^[[00;36mINFO neutron.wsgi [^[[01;36mreq-8d718982-44bf-471d-9843-d1717ff360e8 ^[[00;36mneutron c57602c68b7743a592da920bb9c0af6f^[[00;36m] ^[[01;35m^[[00;36m10.139.192.140 - - [12/Feb/2016 13:46:29] "GET /v2.0/ports.json?network_id=24c5e842-f737-4d9b-b778-e631b7d44ccb&device_owner=network%3Adhcp HTTP/1.1" 200 899 0.013816^[[00m
  2016-02-12 13:46:36.395 ^[[01;31mERROR neutron.api.v2.resource [^[[01;36mreq-a5d49508-8501-4802-a46b-674d36a46d23 ^[[00;36mPRF_ctx_rally_56a12f009988422694a3e8b7c1f2c461_user_0 
  56a12f009988422694a3e8b7c1f2c461^[[01;31m] ^[[01;35m^[[01;31mindex failed^[[00m
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00mTraceback (most recent call last):
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83, in resource
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    result = method(request=request, **args)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/opt/stack/neutron/neutron/api/v2/base.py", line 340, in index
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return self._items(request, True, parent_id)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/opt/stack/neutron/neutron/api/v2/base.py", line 267, in _items
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    obj_list = obj_getter(request.context, **kwargs)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1284, in get_ports
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    for c in query:
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2732, in __iter__
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return self._execute_and_instances(context)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2745, in _execute_and_instances
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    close_with_result=True)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2736, in _connection_from_session
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    **kw)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 905, in connection
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    execution_options=execution_options)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 912, in _connection_for_bind
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    conn = engine.contextual_connect(**kw)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2039, in contextual_connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    self._wrap_pool_connect(self.pool.connect, None),
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2078, in _wrap_pool_connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    e, dialect, self)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1401, in _handle_dbapi_exception_noconnection
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    util.raise_from_cause(newraise, exc_info)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    reraise(type(exception), exception, tb=exc_tb)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 2074, in _wrap_pool_connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return fn()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 376, in connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return _ConnectionFairy._checkout(self)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 713, in _checkout
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    fairy = _ConnectionRecord.checkout(pool)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 485, in checkout
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    rec.checkin()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    compat.reraise(exc_type, exc_value, exc_tb)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 482, in checkout
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    dbapi_connection = rec.get_connection()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 594, in get_connection
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    self.connection = self.__connect()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/pool.py", line 607, in __connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    connection = self.__pool._invoke_creator(self)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/strategies.py", line 97, in connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return dialect.connect(*cargs, **cparams)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 385, in connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return self.dbapi.connect(*cargs, **cparams)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib/python2.7/site-packages/pymysql/__init__.py", line 88, in Connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    return Connection(*args, **kwargs)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 657, in __init__
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    self.connect()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 851, in connect
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    self._request_authentication()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1034, in _request_authentication
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    auth_packet = self._read_packet()
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 895, in _read_packet
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    packet_header = self._read_bytes(4)
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m  File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 922, in _read_bytes
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m    2013, "Lost connection to MySQL server during query")
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00mDBConnectionError: (pymysql.err.OperationalError) (2013, 'Lost connection to MySQL server during query')
  ^[[01;31m2016-02-12 13:46:36.395 TRACE neutron.api.v2.resource ^[[01;35m^[[00m

To manage notifications about this bug go to:
https://bugs.launchpad.net/networking-ovn/+bug/1545584/+subscriptions
References

[Bug 1545584] [NEW] OVN devstack: Network creation fails when a VM with provider and private network interface is activatied
From: Mala Anand, 2016-02-15