OpenStack Percona Cluster Charm

Migration fails with deadlock error

Bug #1849125 reported by Liam Young
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Heat Charm
Triaged
High
Unassigned
OpenStack Neutron API Charm
Triaged
High
Unassigned
OpenStack Percona Cluster Charm
Triaged
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 :

Hit this with heat

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

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...

Alex Kavanagh (ajkavanagh)
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  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.