yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1789633] [NEW] placement aggregate handling has lock trouble with sqlite files

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Chris Dent <cdent+lp@xxxxxxxxxxxxx>
Date: Wed, 29 Aug 2018 11:27:25 -0000
Reply-to: Bug 1789633 <1789633@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Not sure if this is in itself a bug, but instead indicates that there
are issues with aggregate handling that may show up in the real world
under some conditions.

The placecat tooling at https://github.com/cdent/placecat has a suite of
automated tests that run every now and again against a docker container
built from nova master. It uses a file-based sqlite database. With
recent updates those tests are now failing with 'database locked' errors
(traceback below is from functional tests, but the one in the placecat
server is the same). travis logs at https://travis-
ci.org/cdent/placecat/builds/421991104 but the traceback is not visible
there

In a nova checkout, I've changed the functional tests to use a file
based database for sqlite and can intermittently replicate the problem
when PUTting aggregates for a resource provider. It seems this came in
with 2d7ed309ec4 ( https://review.openstack.org/#/c/592654/ ).


-=-=-
       ERROR [nova.api.openstack.placement.fault_wrap] Placement API unexpected error: (sqlite3.OperationalError) database is locked (Background on this error at: http://sqlalche.me/e/e3q8)
    Traceback (most recent call last):
      File "nova/api/openstack/placement/fault_wrap.py", line 40, in __call__
        return self.application(environ, start_response)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 129, in __call__
        resp = self.call_func(req, *args, **kw)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 193, in call_func
        return self.func(req, *args, **kwargs)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/microversion_parse/middleware.py", line 80, in __call__
        response = req.get_response(self.application)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/request.py", line 1313, in send
        application, catch_exc_info=False)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/request.py", line 1277, in call_application
        app_iter = application(self.environ, start_response)
      File "nova/api/openstack/placement/handler.py", line 213, in __call__
        return dispatch(environ, start_response, self._map)
      File "nova/api/openstack/placement/handler.py", line 150, in dispatch
        return handler(environ, start_response)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 129, in __call__
        resp = self.call_func(req, *args, **kw)
      File "nova/api/openstack/placement/wsgi_wrapper.py", line 29, in call_func
        super(PlacementWsgify, self).call_func(req, *args, **kwargs)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 193, in call_func
        return self.func(req, *args, **kwargs)
      File "nova/api/openstack/placement/util.py", line 191, in decorated_function
        return f(req)
      File "nova/api/openstack/placement/microversion.py", line 166, in decorated_func
        return _find_method(f, version, status_code)(req, *args, **kwargs)
      File "nova/api/openstack/placement/handlers/aggregate.py", line 131, in set_aggregates
        increment_generation=consider_generation)
      File "nova/api/openstack/placement/handlers/aggregate.py", line 72, in _set_aggregates
        aggregate_uuids, increment_generation=increment_generation)
      File "nova/api/openstack/placement/objects/resource_provider.py", line 991, in set_aggregates
        increment_generation=increment_generation)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 993, in wrapper
        return fn(*args, **kwargs)
      File "nova/api/openstack/placement/objects/resource_provider.py", line 557, in _set_aggregates
        agg_id = _ensure_aggregate(context, agg_uuid)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 993, in wrapper
        return fn(*args, **kwargs)
      File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
        self.gen.next()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1043, in _transaction_scope
        yield resource
      File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
        self.gen.next()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 653, in _session
        self.session.rollback()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
        self.force_reraise()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
        six.reraise(self.type_, self.value, self.tb)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 650, in _session
        self._end_session_transaction(self.session)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 678, in _end_session_transaction
        session.commit()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 943, in commit
        self.transaction.commit()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 471, in commit
        t[1].commit()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1643, in commit
        self._do_commit()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1674, in _do_commit
        self.connection._commit_impl()
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 726, in _commit_impl
        self._handle_dbapi_exception(e, None, None, None, None)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception
        util.raise_from_cause(newraise, exc_info)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause
        reraise(type(exception), exception, tb=exc_tb, cause=cause)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 724, in _commit_impl
        self.engine.dialect.do_commit(self.connection)
      File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 462, in do_commit
        dbapi_connection.commit()
    OperationalError: (sqlite3.OperationalError) database is locked (Background on this error at: http://sqlalche.me/e/e3q8)
        INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /resource_providers/ed83df92-38c2-4674-8aaa-774190e9d5f2/aggregates" status: 500 len: 362 microversion: 1.30
-=-=-

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: db placement testing

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1789633

Title:
  placement aggregate handling has lock trouble with sqlite files

Status in OpenStack Compute (nova):
  New

Bug description:
  Not sure if this is in itself a bug, but instead indicates that there
  are issues with aggregate handling that may show up in the real world
  under some conditions.

  The placecat tooling at https://github.com/cdent/placecat has a suite
  of automated tests that run every now and again against a docker
  container built from nova master. It uses a file-based sqlite
  database. With recent updates those tests are now failing with
  'database locked' errors (traceback below is from functional tests,
  but the one in the placecat server is the same). travis logs at https
  ://travis-ci.org/cdent/placecat/builds/421991104 but the traceback is
  not visible there

  In a nova checkout, I've changed the functional tests to use a file
  based database for sqlite and can intermittently replicate the problem
  when PUTting aggregates for a resource provider. It seems this came in
  with 2d7ed309ec4 ( https://review.openstack.org/#/c/592654/ ).


  -=-=-
         ERROR [nova.api.openstack.placement.fault_wrap] Placement API unexpected error: (sqlite3.OperationalError) database is locked (Background on this error at: http://sqlalche.me/e/e3q8)
      Traceback (most recent call last):
        File "nova/api/openstack/placement/fault_wrap.py", line 40, in __call__
          return self.application(environ, start_response)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 129, in __call__
          resp = self.call_func(req, *args, **kw)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 193, in call_func
          return self.func(req, *args, **kwargs)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/microversion_parse/middleware.py", line 80, in __call__
          response = req.get_response(self.application)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/request.py", line 1313, in send
          application, catch_exc_info=False)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/request.py", line 1277, in call_application
          app_iter = application(self.environ, start_response)
        File "nova/api/openstack/placement/handler.py", line 213, in __call__
          return dispatch(environ, start_response, self._map)
        File "nova/api/openstack/placement/handler.py", line 150, in dispatch
          return handler(environ, start_response)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 129, in __call__
          resp = self.call_func(req, *args, **kw)
        File "nova/api/openstack/placement/wsgi_wrapper.py", line 29, in call_func
          super(PlacementWsgify, self).call_func(req, *args, **kwargs)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/webob/dec.py", line 193, in call_func
          return self.func(req, *args, **kwargs)
        File "nova/api/openstack/placement/util.py", line 191, in decorated_function
          return f(req)
        File "nova/api/openstack/placement/microversion.py", line 166, in decorated_func
          return _find_method(f, version, status_code)(req, *args, **kwargs)
        File "nova/api/openstack/placement/handlers/aggregate.py", line 131, in set_aggregates
          increment_generation=consider_generation)
        File "nova/api/openstack/placement/handlers/aggregate.py", line 72, in _set_aggregates
          aggregate_uuids, increment_generation=increment_generation)
        File "nova/api/openstack/placement/objects/resource_provider.py", line 991, in set_aggregates
          increment_generation=increment_generation)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 993, in wrapper
          return fn(*args, **kwargs)
        File "nova/api/openstack/placement/objects/resource_provider.py", line 557, in _set_aggregates
          agg_id = _ensure_aggregate(context, agg_uuid)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 993, in wrapper
          return fn(*args, **kwargs)
        File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
          self.gen.next()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1043, in _transaction_scope
          yield resource
        File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
          self.gen.next()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 653, in _session
          self.session.rollback()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
          self.force_reraise()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
          six.reraise(self.type_, self.value, self.tb)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 650, in _session
          self._end_session_transaction(self.session)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 678, in _end_session_transaction
          session.commit()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 943, in commit
          self.transaction.commit()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 471, in commit
          t[1].commit()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1643, in commit
          self._do_commit()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1674, in _do_commit
          self.connection._commit_impl()
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 726, in _commit_impl
          self._handle_dbapi_exception(e, None, None, None, None)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1409, in _handle_dbapi_exception
          util.raise_from_cause(newraise, exc_info)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 265, in raise_from_cause
          reraise(type(exception), exception, tb=exc_tb, cause=cause)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 724, in _commit_impl
          self.engine.dialect.do_commit(self.connection)
        File "/mnt/share/cdentsrc/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 462, in do_commit
          dbapi_connection.commit()
      OperationalError: (sqlite3.OperationalError) database is locked (Background on this error at: http://sqlalche.me/e/e3q8)
          INFO [nova.api.openstack.placement.requestlog] 127.0.0.1 "PUT /resource_providers/ed83df92-38c2-4674-8aaa-774190e9d5f2/aggregates" status: 500 len: 362 microversion: 1.30
  -=-=-

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1789633/+subscriptions
Follow ups

[Bug 1789633] Re: placement aggregate handling has lock trouble with sqlite files
From: OpenStack Infra, 2018-08-30