The relation-joined/changed hooks for the shared-db relation get progressively worse as the model progresses (as each relation is added) as the code iterates through each relation and does multiple new cluster checks and database queries for each one. This results in the last (in a long chain of hooks) taking around 5-6 minutes:
from the machine.lock on the leader (r/w) node:
2020-08-10 13:39:23 unit-mysql-innodb-cluster-2: uniter (run relation-joined (23; mysql-innodb-cluster/0) hook), waited 0s, held 15s
2020-08-10 13:39:39 unit-mysql-innodb-cluster-2: uniter (run relation-joined (22; mysql-innodb-cluster/0) hook), waited 0s, held 15s
2020-08-10 13:39:57 unit-mysql-innodb-cluster-2: uniter (run relation-joined (130; barbican-mysql-router/0) hook), waited 0s, held 18s
2020-08-10 13:40:17 unit-mysql-innodb-cluster-2: uniter (run relation-changed (23; mysql-innodb-cluster/0) hook), waited 0s, held 20s
2020-08-10 13:40:31 unit-mysql-innodb-cluster-2: uniter (run relation-changed (22; mysql-innodb-cluster/0) hook), waited 0s, held 14s
2020-08-10 13:40:50 unit-mysql-innodb-cluster-2: uniter (run relation-changed (130; barbican-mysql-router/0) hook), waited 0s, held 19s
2020-08-10 13:41:36 unit-mysql-innodb-cluster-2: uniter (run relation-joined (138; aodh-mysql-router/0) hook), waited 0s, held 19s
2020-08-10 13:41:54 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/0) hook), waited 0s, held 18s
2020-08-10 13:42:27 unit-mysql-innodb-cluster-2: uniter (run relation-joined (138; aodh-mysql-router/1) hook), waited 0s, held 18s
2020-08-10 13:42:46 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/1) hook), waited 0s, held 18s
2020-08-10 13:43:04 unit-mysql-innodb-cluster-2: uniter (run relation-joined (22; mysql-innodb-cluster/1) hook), waited 0s, held 18s
2020-08-10 13:43:22 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/0) hook), waited 0s, held 18s
2020-08-10 13:43:35 unit-mysql-innodb-cluster-2: uniter (run relation-changed (22; mysql-innodb-cluster/1) hook), waited 0s, held 13s
2020-08-10 13:44:00 unit-mysql-innodb-cluster-2: uniter (run relation-joined (23; mysql-innodb-cluster/1) hook), waited 0s, held 25s
2020-08-10 13:44:18 unit-mysql-innodb-cluster-2: uniter (run relation-changed (23; mysql-innodb-cluster/1) hook), waited 0s, held 17s
2020-08-10 13:44:35 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/1) hook), waited 0s, held 17s
2020-08-10 13:44:52 unit-mysql-innodb-cluster-2: uniter (run relation-joined (128; keystone-mysql-router/0) hook), waited 0s, held 17s
2020-08-10 13:45:46 unit-mysql-innodb-cluster-2: uniter (run relation-changed (23; mysql-innodb-cluster/0) hook), waited 0s, held 55s
2020-08-10 13:46:03 unit-mysql-innodb-cluster-2: uniter (run relation-changed (128; keystone-mysql-router/0) hook), waited 0s, held 17s
2020-08-10 13:46:22 unit-mysql-innodb-cluster-2: uniter (run relation-joined (142; glance-mysql-router/0) hook), waited 0s, held 18s
2020-08-10 13:46:39 unit-mysql-innodb-cluster-2: uniter (run relation-joined (128; keystone-mysql-router/1) hook), waited 0s, held 17s
2020-08-10 13:46:56 unit-mysql-innodb-cluster-2: uniter (run relation-changed (23; mysql-innodb-cluster/0) hook), waited 0s, held 17s
2020-08-10 13:47:13 unit-mysql-innodb-cluster-2: uniter (run relation-joined (136; neutron-api-mysql-router/1) hook), waited 0s, held 17s
2020-08-10 13:47:30 unit-mysql-innodb-cluster-2: uniter (run relation-joined (132; heat-mysql-router/0) hook), waited 0s, held 17s
2020-08-10 13:49:14 unit-mysql-innodb-cluster-2: uniter (run relation-changed (23; mysql-innodb-cluster/1) hook), waited 0s, held 1m44s
2020-08-10 13:49:32 unit-mysql-innodb-cluster-2: uniter (run relation-changed (23; mysql-innodb-cluster/1) hook), waited 0s, held 18s
2020-08-10 13:50:24 unit-mysql-innodb-cluster-2: uniter (run relation-joined (148; placement-mysql-router/0) hook), waited 0s, held 51s
2020-08-10 13:51:14 unit-mysql-innodb-cluster-2: uniter (run relation-joined (134; nova-cloud-controller-mysql-router/0) hook), waited 0s, held 51s
2020-08-10 13:51:33 unit-mysql-innodb-cluster-2: uniter (run relation-changed (136; neutron-api-mysql-router/1) hook), waited 0s, held 19s
2020-08-10 13:52:30 unit-mysql-innodb-cluster-2: uniter (run relation-changed (148; placement-mysql-router/0) hook), waited 0s, held 57s
2020-08-10 13:53:30 unit-mysql-innodb-cluster-2: uniter (run relation-changed (130; barbican-mysql-router/0) hook), waited 0s, held 1m0s
2020-08-10 13:54:33 unit-mysql-innodb-cluster-2: uniter (run relation-joined (148; placement-mysql-router/1) hook), waited 0s, held 1m2s
2020-08-10 13:55:39 unit-mysql-innodb-cluster-2: uniter (run relation-joined (138; aodh-mysql-router/2) hook), waited 0s, held 1m7s
2020-08-10 13:56:49 unit-mysql-innodb-cluster-2: uniter (run relation-changed (132; heat-mysql-router/0) hook), waited 0s, held 1m10s
2020-08-10 13:57:59 unit-mysql-innodb-cluster-2: uniter (run relation-joined (144; designate-mysql-router/1) hook), waited 0s, held 1m10s
2020-08-10 13:59:14 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/2) hook), waited 0s, held 1m14s
2020-08-10 14:00:33 unit-mysql-innodb-cluster-2: uniter (run relation-changed (128; keystone-mysql-router/1) hook), waited 0s, held 1m19s
2020-08-10 14:01:56 unit-mysql-innodb-cluster-2: uniter (run relation-changed (142; glance-mysql-router/0) hook), waited 0s, held 1m24s
2020-08-10 14:03:22 unit-mysql-innodb-cluster-2: uniter (run relation-joined (126; vault-mysql-router/0) hook), waited 0s, held 1m26s
2020-08-10 14:04:51 unit-mysql-innodb-cluster-2: uniter (run relation-changed (144; designate-mysql-router/1) hook), waited 0s, held 1m29s
2020-08-10 14:06:22 unit-mysql-innodb-cluster-2: uniter (run relation-joined (136; neutron-api-mysql-router/0) hook), waited 0s, held 1m31s
2020-08-10 14:06:41 unit-mysql-innodb-cluster-2: uniter (run relation-changed (136; neutron-api-mysql-router/0) hook), waited 0s, held 19s
2020-08-10 14:08:15 unit-mysql-innodb-cluster-2: uniter (run relation-joined (146; cinder-mysql-router/0) hook), waited 0s, held 1m35s
2020-08-10 14:09:55 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/0) hook), waited 0s, held 1m39s
2020-08-10 14:11:39 unit-mysql-innodb-cluster-2: uniter (run relation-joined (142; glance-mysql-router/1) hook), waited 0s, held 1m45s
2020-08-10 14:13:35 unit-mysql-innodb-cluster-2: uniter (run relation-changed (148; placement-mysql-router/1) hook), waited 0s, held 1m56s
2020-08-10 14:15:35 unit-mysql-innodb-cluster-2: uniter (run relation-changed (142; glance-mysql-router/1) hook), waited 0s, held 2m0s
2020-08-10 14:17:37 unit-mysql-innodb-cluster-2: uniter (run relation-changed (138; aodh-mysql-router/1) hook), waited 0s, held 2m2s
2020-08-10 14:19:43 unit-mysql-innodb-cluster-2: uniter (run relation-changed (126; vault-mysql-router/0) hook), waited 0s, held 2m6s
2020-08-10 14:21:54 unit-mysql-innodb-cluster-2: uniter (run relation-changed (134; nova-cloud-controller-mysql-router/0) hook), waited 0s, held 2m11s
2020-08-10 14:24:07 unit-mysql-innodb-cluster-2: uniter (run relation-joined (134; nova-cloud-controller-mysql-router/1) hook), waited 0s, held 2m14s
2020-08-10 14:26:26 unit-mysql-innodb-cluster-2: uniter (run relation-joined (144; designate-mysql-router/0) hook), waited 0s, held 2m18s
2020-08-10 14:28:50 unit-mysql-innodb-cluster-2: uniter (run relation-joined (148; placement-mysql-router/2) hook), waited 0s, held 2m25s
2020-08-10 14:31:18 unit-mysql-innodb-cluster-2: uniter (run relation-joined (132; heat-mysql-router/1) hook), waited 0s, held 2m27s
2020-08-10 14:33:50 unit-mysql-innodb-cluster-2: uniter (run relation-joined (136; neutron-api-mysql-router/2) hook), waited 0s, held 2m32s
2020-08-10 14:36:33 unit-mysql-innodb-cluster-2: uniter (run relation-changed (144; designate-mysql-router/0) hook), waited 0s, held 2m43s
2020-08-10 14:39:16 unit-mysql-innodb-cluster-2: uniter (run relation-joined (128; keystone-mysql-router/2) hook), waited 0s, held 2m43s
2020-08-10 14:42:03 unit-mysql-innodb-cluster-2: uniter (run relation-joined (126; vault-mysql-router/1) hook), waited 0s, held 2m46s
2020-08-10 14:44:54 unit-mysql-innodb-cluster-2: uniter (run relation-joined (144; designate-mysql-router/2) hook), waited 0s, held 2m51s
2020-08-10 14:47:51 unit-mysql-innodb-cluster-2: uniter (run relation-changed (136; neutron-api-mysql-router/2) hook), waited 0s, held 2m58s
2020-08-10 14:50:56 unit-mysql-innodb-cluster-2: uniter (run relation-changed (144; designate-mysql-router/2) hook), waited 0s, held 3m4s
2020-08-10 14:54:04 unit-mysql-innodb-cluster-2: uniter (run relation-changed (128; keystone-mysql-router/2) hook), waited 0s, held 3m9s
2020-08-10 14:57:17 unit-mysql-innodb-cluster-2: uniter (run relation-changed (128; keystone-mysql-router/0) hook), waited 0s, held 3m13s
2020-08-10 15:00:37 unit-mysql-innodb-cluster-2: uniter (run relation-changed (132; heat-mysql-router/1) hook), waited 0s, held 3m20s
2020-08-10 15:04:07 unit-mysql-innodb-cluster-2: uniter (run relation-changed (144; designate-mysql-router/1) hook), waited 0s, held 3m30s
2020-08-10 15:07:41 unit-mysql-innodb-cluster-2: uniter (run relation-joined (140; gnocchi-mysql-router/0) hook), waited 0s, held 3m33s
2020-08-10 15:11:23 unit-mysql-innodb-cluster-2: uniter (run relation-changed (148; placement-mysql-router/2) hook), waited 0s, held 3m43s
2020-08-10 15:15:11 unit-mysql-innodb-cluster-2: uniter (run relation-changed (126; vault-mysql-router/1) hook), waited 0s, held 3m47s
2020-08-10 15:19:01 unit-mysql-innodb-cluster-2: uniter (run relation-joined (142; glance-mysql-router/2) hook), waited 0s, held 3m50s
2020-08-10 15:19:21 unit-mysql-innodb-cluster-2: uniter (run relation-changed (142; glance-mysql-router/2) hook), waited 0s, held 21s
2020-08-10 15:23:12 unit-mysql-innodb-cluster-2: uniter (run relation-changed (136; neutron-api-mysql-router/0) hook), waited 0s, held 3m51s
2020-08-10 15:27:08 unit-mysql-innodb-cluster-2: uniter (run relation-changed (142; glance-mysql-router/2) hook), waited 0s, held 3m56s
2020-08-10 15:31:08 unit-mysql-innodb-cluster-2: uniter (run relation-changed (146; cinder-mysql-router/0) hook), waited 0s, held 4m0s
2020-08-10 15:35:12 unit-mysql-innodb-cluster-2: uniter (run relation-joined (146; cinder-mysql-router/1) hook), waited 0s, held 4m4s
2020-08-10 15:39:16 unit-mysql-innodb-cluster-2: uniter (run relation-changed (136; neutron-api-mysql-router/1) hook), waited 0s, held 4m4s
2020-08-10 15:43:21 unit-mysql-innodb-cluster-2: uniter (run relation-joined (126; vault-mysql-router/2) hook), waited 0s, held 4m5s
2020-08-10 15:43:43 unit-mysql-innodb-cluster-2: uniter (run relation-changed (140; gnocchi-mysql-router/0) hook), waited 0s, held 21s
2020-08-10 15:47:58 unit-mysql-innodb-cluster-2: uniter (run relation-joined (140; gnocchi-mysql-router/1) hook), waited 0s, held 4m15s
2020-08-10 15:52:16 unit-mysql-innodb-cluster-2: uniter (run relation-changed (126; vault-mysql-router/2) hook), waited 0s, held 4m18s
2020-08-10 15:56:39 unit-mysql-innodb-cluster-2: uniter (run relation-joined (132; heat-mysql-router/2) hook), waited 0s, held 4m23s
2020-08-10 16:01:05 unit-mysql-innodb-cluster-2: uniter (run relation-changed (140; gnocchi-mysql-router/1) hook), waited 0s, held 4m27s
2020-08-10 16:05:34 unit-mysql-innodb-cluster-2: uniter (run relation-joined (140; gnocchi-mysql-router/2) hook), waited 0s, held 4m29s
2020-08-10 16:10:15 unit-mysql-innodb-cluster-2: uniter (run relation-changed (134; nova-cloud-controller-mysql-router/1) hook), waited 0s, held 4m42s
2020-08-10 16:15:01 unit-mysql-innodb-cluster-2: uniter (run relation-changed (146; cinder-mysql-router/1) hook), waited 0s, held 4m46s
2020-08-10 16:19:50 unit-mysql-innodb-cluster-2: uniter (run relation-changed (136; neutron-api-mysql-router/1) hook), waited 0s, held 4m48s
2020-08-10 16:24:42 unit-mysql-innodb-cluster-2: uniter (run relation-joined (146; cinder-mysql-router/2) hook), waited 0s, held 4m53s
2020-08-10 16:29:40 unit-mysql-innodb-cluster-2: uniter (run relation-joined (134; nova-cloud-controller-mysql-router/2) hook), waited 0s, held 4m58s
2020-08-10 16:34:44 unit-mysql-innodb-cluster-2: uniter (run relation-changed (146; cinder-mysql-router/2) hook), waited 0s, held 5m4s
2020-08-10 16:40:00 unit-mysql-innodb-cluster-2: uniter (run relation-changed (132; heat-mysql-router/2) hook), waited 0s, held 5m16s
2020-08-10 16:45:24 unit-mysql-innodb-cluster-2: uniter (run relation-changed (134; nova-cloud-controller-mysql-router/2) hook), waited 0s, held 5m24s
2020-08-10 16:50:58 unit-mysql-innodb-cluster-2: uniter (run relation-changed (134; nova-cloud-controller-mysql-router/0) hook), waited 0s, held 5m34s
2020-08-10 16:56:32 unit-mysql-innodb-cluster-2: uniter (run relation-changed (132; heat-mysql-router/0) hook), waited 0s, held 5m34s
2020-08-10 17:02:27 unit-mysql-innodb-cluster-2: uniter (run relation-changed (140; gnocchi-mysql-router/2) hook), waited 0s, held 5m55s
2020-08-10 17:08:07 unit-mysql-innodb-cluster-2: uniter (run relation-changed (140; gnocchi-mysql-router/0) hook), waited 0s, held 5m40s
2020-08-10 17:08:33 unit-mysql-innodb-cluster-2: uniter (run update-status hook), waited 0s, held 26s
I'd argue that the hook should always be about 15 seconds; 1 check that the cluster exists, 1 db query to get all of the existing username/database/info for the shared-db relation; match that against the relation-data; calculate the difference and maybe 2 db calls to update/insert any changed data using the existing connection.
Example from the debug-log showing the activity of a small set of a relation-changed hook:
unit-mysql-innodb-cluster-2: 17:05:44 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Checking cluster status.
unit-mysql-innodb-cluster-2: 17:05:46 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Checking cluster status.
unit-mysql-innodb-cluster-2: 17:05:47 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Opening db connection for clusteruser@172.20.0.67
unit-mysql-innodb-cluster-2: 17:05:47 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Opening db connection for root@None
unit-mysql-innodb-cluster-2: 17:05:48 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Opening db connection for root@None
unit-mysql-innodb-cluster-2: 17:05:48 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Grant exists for host '172.20.0.39' on db 'gnocchi'
unit-mysql-innodb-cluster-2: 17:05:48 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Grant exists for host '172.20.0.24' on db 'gnocchi'
unit-mysql-innodb-cluster-2: 17:05:48 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Grant exists for host '172.20.0.46' on db 'gnocchi'
unit-mysql-innodb-cluster-2: 17:05:48 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Single hostname provided by relation: 172.20.0.24
unit-mysql-innodb-cluster-2: 17:05:49 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Checking cluster status.
unit-mysql-innodb-cluster-2: 17:05:50 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Checking cluster status.
unit-mysql-innodb-cluster-2: 17:05:51 DEBUG unit.mysql-innodb-cluster/2.juju-log db-router:140: Opening db connection for clusteruser@172.20.0.67
unit-mysql-innodb-cluster-2: 17:05:52 WARNING unit.mysql-innodb-cluster/2.juju-log db-router:140: DB user mysqlrouteruser already exists.
unit-mysql-innodb-cluster-2: 17:05:52 WARNING unit.mysql-innodb-cluster/2.juju-log db-router:140: DB user mysqlrouteruser already exists.
un
e.g. it takes 6 seconds to check that a single relation is valid. There are two checks on the cluster-status (that's a mysqlsh shell out call twice), then multiple db checks. And this is repeated for ever shared-db relation, each time, when the hook changes. There has to be a better way, as it slows down deployments and makes testing large models take extra time.
Also compare with the speed issues with keystone.
