Migration fails with deadlock error

Bug #1849125 reported by Liam Young on 2019-10-21
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack heat charm
High
Unassigned
OpenStack neutron-api charm
High
Unassigned
OpenStack percona-cluster charm
High
Unassigned

Bug Description

Database migration fails with database deadlock error. This particular instance of the error was seen during a Xenial Pike install.

```

2019-10-21 13:52:54 DEBUG shared-db-relation-changed oslo_db.exception.DBDeadlock: (pymysql.err.InternalError) (1213, u'Deadlock found when trying to get lock; try restarting transaction') [SQL: u'ALTER TABLE ml2_network_segments RENAME TO networksegments']
2019-10-21 13:52:54 DEBUG shared-db-relation-changed Traceback (most recent call last):
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/shared-db-relation-changed", line 807, in <module>
2019-10-21 13:52:54 DEBUG shared-db-relation-changed main()
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/shared-db-relation-changed", line 800, in main
2019-10-21 13:52:54 DEBUG shared-db-relation-changed hooks.execute(sys.argv)
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/charmhelpers/core/hookenv.py", line 914, in execute
2019-10-21 13:52:54 DEBUG shared-db-relation-changed self._hooks[hook_name]()
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1568, in wrapped_f
2019-10-21 13:52:54 DEBUG shared-db-relation-changed stopstart, restart_functions)
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/charmhelpers/core/host.py", line 741, in restart_on_change_helper
2019-10-21 13:52:54 DEBUG shared-db-relation-changed r = lambda_f()
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/charmhelpers/contrib/openstack/utils.py", line 1567, in <lambda>
2019-10-21 13:52:54 DEBUG shared-db-relation-changed (lambda: f(*args, **kwargs)), __restart_map_cache['cache'],
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/shared-db-relation-changed", line 414, in db_changed
2019-10-21 13:52:54 DEBUG shared-db-relation-changed conditional_neutron_migration()
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/shared-db-relation-changed", line 181, in conditional_neutron_migration
2019-10-21 13:52:54 DEBUG shared-db-relation-changed migrate_neutron_database()
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-neutron-api-1/charm/hooks/neutron_api_utils.py", line 718, in migrate_neutron_database
2019-10-21 13:52:54 DEBUG shared-db-relation-changed subprocess.check_output(cmd)
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/usr/lib/python3.5/subprocess.py", line 626, in check_output
2019-10-21 13:52:54 DEBUG shared-db-relation-changed **kwargs).stdout
2019-10-21 13:52:54 DEBUG shared-db-relation-changed File "/usr/lib/python3.5/subprocess.py", line 708, in run
2019-10-21 13:52:54 DEBUG shared-db-relation-changed output=stdout, stderr=stderr)
2019-10-21 13:52:54 DEBUG shared-db-relation-changed subprocess.CalledProcessError: Command '['neutron-db-manage', '--config-file', '/etc/neutron/neutron.conf', '--config-file', '/etc/neutron/plugins/ml2/ml2_conf.ini', 'upgrade', 'head']' returned non-zero exit status 1
2019-10-21 13:52:54 ERROR juju.worker.uniter.operation runhook.go:132 hook "shared-db-relation-changed" failed: exit status 1
```

http://paste.ubuntu.com/p/TPHYkMXCGM/

Revision history for this message
Liam Young (gnuoy) wrote :
Revision history for this message
Liam Young (gnuoy) wrote :

Bionic train combo when the heat error occurred above.

Revision history for this message
Liam Young (gnuoy) wrote :
Download full text (4.7 KiB)

Hit it on percona itself this time.

# dpkg -l | grep percona-xtradb-cluster-server
ii percona-xtradb-cluster-server 5.7.20-29.24-0ubuntu2.1 all Percona XtraDB Cluster database server
ii percona-xtradb-cluster-server-5.7 5.7.20-29.24-0ubuntu2.1 amd64 Percona XtraDB Cluster database server binaries

# lsb_release -c
Codename: bionic

2019-10-22 15:31:15 DEBUG juju-log shared-db:53: All 3 percona units reporting clustered
2019-10-22 15:31:15 DEBUG juju-log shared-db:53: Opening db connection for root@localhost
2019-10-22 15:31:16 DEBUG juju-log shared-db:53: Opening db connection for root@localhost
2019-10-22 15:31:16 DEBUG shared-db-relation-changed active
2019-10-22 15:31:16 INFO juju-log shared-db:53: Unit is ready
2019-10-22 15:31:17 DEBUG shared-db-relation-changed /var/lib/juju/agents/unit-mysql-1/charm/charmhelpers/contrib/database/mysql.py:130: Warning: (1287, 'Using GRANT for creating new user is deprecated and will be removed in future release. Create new user with CREATE USER statement.')
2019-10-22 15:31:17 DEBUG shared-db-relation-changed password))
2019-10-22 15:31:43 DEBUG juju-log shared-db:104: Single hostname provided by relation: 172.17.104.44
2019-10-22 15:31:43 DEBUG juju-log shared-db:104: Opening db connection for root@localhost
2019-10-22 15:31:47 DEBUG shared-db-relation-changed Traceback (most recent call last):
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/hooks/shared-db-relation-changed", line 1132, in <module>
2019-10-22 15:31:48 DEBUG shared-db-relation-changed main()
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/hooks/shared-db-relation-changed", line 1122, in main
2019-10-22 15:31:48 DEBUG shared-db-relation-changed hooks.execute(sys.argv)
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/charmhelpers/core/hookenv.py", line 914, in execute
2019-10-22 15:31:48 DEBUG shared-db-relation-changed self._hooks[hook_name]()
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/hooks/shared-db-relation-changed", line 897, in shared_db_changed
2019-10-22 15:31:48 DEBUG shared-db-relation-changed db_helper)
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/hooks/shared-db-relation-changed", line 789, in configure_db_for_hosts
2019-10-22 15:31:48 DEBUG shared-db-relation-changed password = db_helper.configure_db(host, database, username)
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/charmhelpers/contrib/database/mysql.py", line 456, in configure_db
2019-10-22 15:31:48 DEBUG shared-db-relation-changed self.create_grant(database, username, remote_ip, password)
2019-10-22 15:31:48 DEBUG shared-db-relation-changed File "/var/lib/juju/agents/unit-mysql-1/charm/charmhelpers/contrib/database/mysql.py", line 130, in create_grant
2019-10-22 15:31:48 DEBUG shared-db-relation-changed password))
2019-10-22 15:31:48 DEBUG shared-d...

Read more...

Changed in charm-heat:
importance: Undecided → Medium
status: New → Triaged
importance: Medium → High
Changed in charm-neutron-api:
importance: Undecided → High
status: New → Triaged
Changed in charm-percona-cluster:
importance: Undecided → High
status: New → Triaged
Revision history for this message
Ryan Beisner (1chb1n) wrote :

Let's look into the pymysql changes, and identify how far back that driver change goes.

Revision history for this message
Aurelien Lourot (aurelien-lourot) wrote :

Seen again on xenial-pike:

http://10.245.162.58:8080/view/MojoMatrix/job/mojo_runner/22469/consoleText

"Deadlock found when trying to get lock; try restarting transaction"

Revision history for this message
Aurelien Lourot (aurelien-lourot) wrote :

This is now happening quite often on OSCI. Last occurence:

http://10.245.162.58:8080/view/MojoMatrix/job/mojo_runner/22773/console

Revision history for this message
Aurelien Lourot (aurelien-lourot) wrote :

In this run this is hitting a keystone hook (relation with percona-cluster):

http://10.245.162.58:8080/view/MojoMatrix/job/mojo_runner/22767/

So this is probably hitting any charm related to percona-cluster with the shared-db relation.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers