yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1795631] [NEW] DBAPIError

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Christoph Manns <christoph.manns@xxxxxxxxx>
Date: Tue, 02 Oct 2018 12:08:15 -0000
Reply-to: Bug 1795631 <1795631@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Hiho,
we recently discovered that our neutron server are throwing exception upon various DB operations.


2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters [req-1eacbfed-9560-4fba-b1fa-bfcf0136d504 - - - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1305, u'SAVEPOINT sa_savepoint_28 does not exist') [SQL: u'ROLLBACK TO SAVEPOINT sa_savepoint_28'] (Background on this error at: http://sqlalche.me/e/2j85): InternalError: (1305, u'SAVEPOINT sa_savepoint_28 does not exist')
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     context)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 170, in execute
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 328, in _query
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 893, in query
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1103, in _read_query_result
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1396, in read
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1059, in _read_packet
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 384, in check_error
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 109, in raise_mysql_exception
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1305, u'SAVEPOINT sa_savepoint_28 does not exist')
2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters


------------------------
LATEST DETECTED DEADLOCK
------------------------
2018-10-02 13:32:45 7f2c88915700
*** (1) TRANSACTION:
TRANSACTION 221633832, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1184, 3 row lock(s), undo log entries 2
MySQL thread id 35685062, OS thread handle 0x7f2c993bc700, query id 528303451 $hostname $ip neutron updating
UPDATE standardattributes SET revision_number=6, updated_at='2018-10-02 11:32:45' WHERE standardattributes.id = 291182 AND standardattributes.revision_number = 5
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 401 page no 17 n bits 368 index `PRIMARY` of table `neutron`.`standardattributes` trx id 221633832 lock_mode X locks rec but not gap waiting
*** (2) TRANSACTION:
TRANSACTION 221633901, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1
MySQL thread id 35700724, OS thread handle 0x7f2c88915700, query id 528303621 $hostname $ip neutron updating
UPDATE standardattributes SET revision_number=7, updated_at='2018-10-02 11:32:45' WHERE standardattributes.id = 291212 AND standardattributes.revision_number = 6
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 401 page no 17 n bits 368 index `PRIMARY` of table `neutron`.`standardattributes` trx id 221633901 lock_mode X locks rec but not gap
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 401 page no 17 n bits 368 index `PRIMARY` of table `neutron`.`standardattributes` trx id 221633901 lock_mode X locks rec but not gap waiting
*** WE ROLL BACK TRANSACTION (2)


Any help is greatly appreciated.

** Affects: neutron
     Importance: Undecided
         Status: New

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

Title:
  DBAPIError

Status in neutron:
  New

Bug description:
  Hiho,
  we recently discovered that our neutron server are throwing exception upon various DB operations.

  
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters [req-1eacbfed-9560-4fba-b1fa-bfcf0136d504 - - - - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1305, u'SAVEPOINT sa_savepoint_28 does not exist') [SQL: u'ROLLBACK TO SAVEPOINT sa_savepoint_28'] (Background on this error at: http://sqlalche.me/e/2j85): InternalError: (1305, u'SAVEPOINT sa_savepoint_28 does not exist')
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     context)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     cursor.execute(statement, parameters)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 170, in execute
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     result = self._query(query)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 328, in _query
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     conn.query(q)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 893, in query
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1103, in _read_query_result
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     result.read()
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1396, in read
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     first_packet = self.connection._read_packet()
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 1059, in _read_packet
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 384, in check_error
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/lib/python2.7/site-packages/pymysql/err.py", line 109, in raise_mysql_exception
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1305, u'SAVEPOINT sa_savepoint_28 does not exist')
  2018-10-02 13:32:45.384 6479 ERROR oslo_db.sqlalchemy.exc_filters

  
  ------------------------
  LATEST DETECTED DEADLOCK
  ------------------------
  2018-10-02 13:32:45 7f2c88915700
  *** (1) TRANSACTION:
  TRANSACTION 221633832, ACTIVE 0 sec starting index read
  mysql tables in use 1, locked 1
  LOCK WAIT 3 lock struct(s), heap size 1184, 3 row lock(s), undo log entries 2
  MySQL thread id 35685062, OS thread handle 0x7f2c993bc700, query id 528303451 $hostname $ip neutron updating
  UPDATE standardattributes SET revision_number=6, updated_at='2018-10-02 11:32:45' WHERE standardattributes.id = 291182 AND standardattributes.revision_number = 5
  *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
  RECORD LOCKS space id 401 page no 17 n bits 368 index `PRIMARY` of table `neutron`.`standardattributes` trx id 221633832 lock_mode X locks rec but not gap waiting
  *** (2) TRANSACTION:
  TRANSACTION 221633901, ACTIVE 0 sec starting index read
  mysql tables in use 1, locked 1
  3 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1
  MySQL thread id 35700724, OS thread handle 0x7f2c88915700, query id 528303621 $hostname $ip neutron updating
  UPDATE standardattributes SET revision_number=7, updated_at='2018-10-02 11:32:45' WHERE standardattributes.id = 291212 AND standardattributes.revision_number = 6
  *** (2) HOLDS THE LOCK(S):
  RECORD LOCKS space id 401 page no 17 n bits 368 index `PRIMARY` of table `neutron`.`standardattributes` trx id 221633901 lock_mode X locks rec but not gap
  *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
  RECORD LOCKS space id 401 page no 17 n bits 368 index `PRIMARY` of table `neutron`.`standardattributes` trx id 221633901 lock_mode X locks rec but not gap waiting
  *** WE ROLL BACK TRANSACTION (2)

  
  Any help is greatly appreciated.

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

[Bug 1795631] Re: DBAPIError
From: Launchpad Bug Tracker, 2018-12-03