Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Speed up integration tests #104

Open
carlcsaposs-canonical opened this issue Feb 3, 2023 · 11 comments
Open

Speed up integration tests #104

carlcsaposs-canonical opened this issue Feb 3, 2023 · 11 comments

Comments

@carlcsaposs-canonical
Copy link
Contributor

Integration tests currently take 40+ minutes (example)

Caching the charmcraft pack LXC container (#78) decreased the time by about 15-20 minutes

This issue is to document efforts to further decrease the time

@carlcsaposs-canonical
Copy link
Contributor Author

Experimenting with running one integration test per GitHub Actions runner in #101

@carlcsaposs-canonical
Copy link
Contributor Author

Results of consolidating multiple ops_test.wait_for_idle statements to one statement in
tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection:

Multiple statements

7d68ff5
Actions runs: https://github.com/canonical/mysql-operator/actions/runs/4085168249/jobs/7044205797

  1. 15 min 0 sec
  2. 15 min 7 sec
  3. 15 min 17 sec
  4. 14 min 46 sec
  5. 18 min 3 sec

Runs on Google Cloud VM:

  1. 15 min 22 sec
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 16:09:23 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 16:09:24 ============================= test session starts ==============================
Feb 03 16:09:24 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 16:09:24 cachedir: .tox/integration/.pytest_cache
Feb 03 16:09:24 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 16:09:24 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 16:09:24 asyncio: mode=auto
Feb 03 16:09:24 collecting ... collected 1 item
Feb 03 16:09:24 
Feb 03 16:09:24 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 16:09:24 -------------------------------- live log setup --------------------------------
Feb 03 16:09:24 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-rlto on cloud localhost
Feb 03 16:09:28 -------------------------------- live log call ---------------------------------
Feb 03 16:09:28 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-rlto0
Feb 03 16:09:28 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 16:09:50 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 22.76s
Feb 03 16:09:56 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 16:09:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:09:57   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:09:57   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:09:57   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:10:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:10:27   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:10:27   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:10:27   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:10:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:10:57   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:10:57   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:10:57   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:11:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:11:27   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:11:27   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:11:27   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:11:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:11:57   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:11:57   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:11:57   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:12:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:12:27   mysql/0 [allocating] waiting: agent initializing
Feb 03 16:12:27   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 16:12:27   mysql/2 [allocating] waiting: agent initializing
Feb 03 16:12:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:12:57   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 16:12:57   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 16:12:57   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 16:13:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:13:27   mysql/0 [executing] maintenance: Setting up cluster node
Feb 03 16:13:27   mysql/1 [executing] maintenance: Setting up cluster node
Feb 03 16:13:27   mysql/2 [executing] waiting: Waiting to start MySQL
Feb 03 16:13:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:13:57   mysql/0 [idle] waiting: Waiting to join the cluster
Feb 03 16:13:57   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 16:13:57   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 16:14:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:14:27   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 16:14:27   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 16:14:27   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:14:46 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-rlto0
Feb 03 16:14:46 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 16:15:07 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 21.88s
Feb 03 16:15:15 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 16:15:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:15:16   application/0 [allocating] waiting: waiting for machine
Feb 03 16:15:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:15:46   application/0 [allocating] waiting: waiting for machine
Feb 03 16:16:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:16:16   application/0 [allocating] waiting: waiting for machine
Feb 03 16:16:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:16:47   application/0 [executing] maintenance: installing charm software
Feb 03 16:17:05 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:17:05   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 16:17:05   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 16:17:05   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:17:05   application/0 [idle] waiting: 
Feb 03 16:17:34 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 16:17:34 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:17:55 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:18:02 INFO     integration.high_availability.test_replication:test_replication.py:74 Destroying leader unit
Feb 03 16:18:24 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:18:24   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:18:24   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:18:43 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:18:47 INFO     integration.high_availability.test_replication:test_replication.py:93 Scaling back to 3 units
Feb 03 16:18:48 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:18:48   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 16:18:48   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:18:48   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:19:18 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:19:18   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:19:49 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:19:49   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:20:19 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:20:19   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:20:49 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:20:49   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:21:19 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:21:19   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 16:21:49 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:21:49   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 16:22:19 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:22:19   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:22:19   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 03 16:22:19   mysql/3 [executing] waiting: Waiting to start MySQL
Feb 03 16:22:49 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:22:49   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:22:49   mysql/3 [idle] waiting: Waiting to join the cluster
Feb 03 16:23:19 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:23:19   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 16:23:19   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:23:19   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 16:23:42 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 16:23:45 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 16:23:45 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:24:07 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:24:27 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:24:33 PASSED
Feb 03 16:24:33 ------------------------------ live log teardown -------------------------------
Feb 03 16:24:33 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 16:24:33 
Feb 03 16:24:33 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 16:24:33 test-replication-rlto  lxd         localhost/localhost  2.9.29   unsupported  16:24:33Z
Feb 03 16:24:33 
Feb 03 16:24:33 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 16:24:33 application                   active      1  application             0  no       
Feb 03 16:24:33 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 16:24:33 
Feb 03 16:24:33 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 16:24:33 application/0*  active    idle   3        10.45.7.156            
Feb 03 16:24:33 mysql/0*        active    idle   0        10.45.7.103            Unit is ready: Mode: RW
Feb 03 16:24:33 mysql/2         active    idle   2        10.45.7.224            Unit is ready: Mode: RO
Feb 03 16:24:33 mysql/3         active    idle   4        10.45.7.34             Unit is ready: Mode: RO
Feb 03 16:24:33 
Feb 03 16:24:33 Machine  State    Address      Inst id        Series  AZ  Message
Feb 03 16:24:33 0        started  10.45.7.103  juju-65f99c-0  jammy       Running
Feb 03 16:24:33 2        started  10.45.7.224  juju-65f99c-2  jammy       Running
Feb 03 16:24:33 3        started  10.45.7.156  juju-65f99c-3  focal       Running
Feb 03 16:24:33 4        started  10.45.7.34   juju-65f99c-4  jammy       Running
Feb 03 16:24:33 
Feb 03 16:24:33 
Feb 03 16:24:33 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 16:24:33 
Feb 03 16:24:33 machine-1: 16:12:05 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:24:33 unit-mysql-1: 16:12:05 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:24:33 unit-mysql-0: 16:12:15 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:24:33 machine-2: 16:12:18 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:24:33 unit-mysql-2: 16:12:19 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:24:33 unit-application-0: 16:16:39 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:24:33 machine-3: 16:16:40 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:24:33 machine-4: 16:21:00 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:24:33 unit-mysql-3: 16:21:01 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:24:33 
Feb 03 16:24:33 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-rlto...
Feb 03 16:24:33 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 16:24:33 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 16:24:34 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 16:24:39 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 03 16:24:40 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 16:24:41 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 16:24:43 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 16:24:44 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 16:24:45 
Feb 03 16:24:45 
Feb 03 16:24:45 ======================== 1 passed in 921.51s (0:15:21) =========================
Feb 03 16:24:45   integration: OK (922.65=setup[0.05]+cmd[922.59] seconds)
Feb 03 16:24:45   congratulations :) (922.72 seconds)
2. 15 min 43 sec
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 16:49:38 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 16:49:39 ============================= test session starts ==============================
Feb 03 16:49:39 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 16:49:39 cachedir: .tox/integration/.pytest_cache
Feb 03 16:49:39 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 16:49:39 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 16:49:39 asyncio: mode=auto
Feb 03 16:49:39 collecting ... collected 1 item
Feb 03 16:49:39 
Feb 03 16:49:39 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 16:49:39 -------------------------------- live log setup --------------------------------
Feb 03 16:49:39 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-rzd2 on cloud localhost
Feb 03 16:49:43 -------------------------------- live log call ---------------------------------
Feb 03 16:49:43 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-rzd20
Feb 03 16:49:43 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 16:50:05 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 22.50s
Feb 03 16:50:11 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 16:50:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:50:12   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:50:12   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:50:12   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:50:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:50:42   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:50:42   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:50:42   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:51:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:51:12   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:51:12   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:51:12   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:51:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:51:42   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:51:42   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:51:42   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:52:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:52:12   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:52:12   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:52:12   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:52:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:52:42   mysql/0 [allocating] waiting: agent initializing
Feb 03 16:52:42   mysql/1 [allocating] waiting: agent initializing
Feb 03 16:52:42   mysql/2 [allocating] waiting: agent initializing
Feb 03 16:53:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:53:12   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 16:53:12   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 16:53:12   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 16:53:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:53:42   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 16:53:42   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 16:53:42   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 16:54:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:54:12   mysql/0 [executing] waiting: Waiting to join the cluster
Feb 03 16:54:12   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 16:54:12   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 16:54:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:54:42   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 16:54:42   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 16:54:42   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 03 16:55:05 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-rzd20
Feb 03 16:55:05 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 16:55:26 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 21.22s
Feb 03 16:55:33 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 16:55:34 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:55:34   application/0 [allocating] waiting: waiting for machine
Feb 03 16:56:04 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:56:04   application/0 [allocating] waiting: waiting for machine
Feb 03 16:56:34 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:56:34   application/0 [allocating] waiting: waiting for machine
Feb 03 16:57:04 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:57:04   application/0 [executing] maintenance: installing charm software
Feb 03 16:57:21 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:57:21   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 16:57:21   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 16:57:21   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:57:21   application/0 [idle] waiting: 
Feb 03 16:57:50 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 16:57:50 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:58:15 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:58:20 INFO     integration.high_availability.test_replication:test_replication.py:74 Destroying leader unit
Feb 03 16:58:41 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:58:41   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 16:58:41   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:59:08 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:59:15 INFO     integration.high_availability.test_replication:test_replication.py:93 Scaling back to 3 units
Feb 03 16:59:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:59:17   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 16:59:17   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 16:59:17   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:59:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:59:47   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:00:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:00:17   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:00:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:00:47   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:01:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:01:17   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:01:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:01:47   mysql/3 [executing] waiting: agent initializing
Feb 03 17:02:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:02:17   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 17:02:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:02:47   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 17:03:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:03:17   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 17:03:17   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 17:03:17   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 03 17:03:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:03:47   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 17:03:47   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 17:03:47   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 17:04:15 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 17:04:21 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 17:04:22 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:04:44 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:05:02 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:05:09 PASSED
Feb 03 17:05:09 ------------------------------ live log teardown -------------------------------
Feb 03 17:05:09 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 17:05:09 
Feb 03 17:05:09 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 17:05:09 test-replication-rzd2  lxd         localhost/localhost  2.9.29   unsupported  17:05:09Z
Feb 03 17:05:09 
Feb 03 17:05:09 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 17:05:09 application                   active      1  application             0  no       
Feb 03 17:05:09 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 17:05:09 
Feb 03 17:05:09 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 17:05:09 application/0*  active    idle   3        10.45.7.40             
Feb 03 17:05:09 mysql/0*        active    idle   0        10.45.7.42             Unit is ready: Mode: RO
Feb 03 17:05:09 mysql/2         active    idle   2        10.45.7.10             Unit is ready: Mode: RW
Feb 03 17:05:09 mysql/3         active    idle   4        10.45.7.197            Unit is ready: Mode: RO
Feb 03 17:05:09 
Feb 03 17:05:09 Machine  State    Address      Inst id        Series  AZ  Message
Feb 03 17:05:09 0        started  10.45.7.42   juju-2d8966-0  jammy       Running
Feb 03 17:05:09 2        started  10.45.7.10   juju-2d8966-2  jammy       Running
Feb 03 17:05:09 3        started  10.45.7.40   juju-2d8966-3  focal       Running
Feb 03 17:05:09 4        started  10.45.7.197  juju-2d8966-4  jammy       Running
Feb 03 17:05:09 
Feb 03 17:05:09 
Feb 03 17:05:09 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 17:05:09 
Feb 03 17:05:09 machine-1: 16:52:28 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:05:09 unit-mysql-1: 16:52:28 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:05:09 machine-2: 16:52:29 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:05:09 unit-mysql-2: 16:52:30 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:05:09 machine-0: 16:52:31 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:05:09 unit-mysql-0: 16:52:32 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:05:09 machine-3: 16:56:54 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:05:09 unit-application-0: 16:56:55 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:05:09 machine-4: 17:01:35 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:05:09 unit-mysql-3: 17:01:35 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:05:09 
Feb 03 17:05:09 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-rzd2...
Feb 03 17:05:09 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 17:05:09 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 17:05:09 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 17:05:16 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 03 17:05:18 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 17:05:19 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 17:05:20 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 17:05:22 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 17:05:23 
Feb 03 17:05:23 
Feb 03 17:05:23 ======================== 1 passed in 943.27s (0:15:43) =========================
Feb 03 17:05:23   integration: OK (944.58=setup[0.06]+cmd[944.52] seconds)
Feb 03 17:05:23   congratulations :) (944.63 seconds)
3. 15 min 11 sec
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 18:16:41 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 18:16:42 ============================= test session starts ==============================
Feb 03 18:16:42 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 18:16:42 cachedir: .tox/integration/.pytest_cache
Feb 03 18:16:42 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 18:16:42 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 18:16:42 asyncio: mode=auto
Feb 03 18:16:42 collecting ... collected 1 item
Feb 03 18:16:42 
Feb 03 18:16:42 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 18:16:42 -------------------------------- live log setup --------------------------------
Feb 03 18:16:42 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-qrdl on cloud localhost
Feb 03 18:16:45 -------------------------------- live log call ---------------------------------
Feb 03 18:16:45 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-qrdl0
Feb 03 18:16:45 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 18:17:07 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 22.23s
Feb 03 18:17:12 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 18:17:14 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:17:14   mysql/0 [allocating] waiting: waiting for machine
Feb 03 18:17:14   mysql/1 [allocating] waiting: waiting for machine
Feb 03 18:17:14   mysql/2 [allocating] waiting: waiting for machine
Feb 03 18:17:44 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:17:44   mysql/0 [allocating] waiting: waiting for machine
Feb 03 18:17:44   mysql/1 [allocating] waiting: waiting for machine
Feb 03 18:17:44   mysql/2 [allocating] waiting: waiting for machine
Feb 03 18:18:14 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:18:14   mysql/0 [allocating] waiting: waiting for machine
Feb 03 18:18:14   mysql/1 [allocating] waiting: waiting for machine
Feb 03 18:18:14   mysql/2 [allocating] waiting: waiting for machine
Feb 03 18:18:44 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:18:44   mysql/0 [allocating] waiting: waiting for machine
Feb 03 18:18:44   mysql/1 [allocating] waiting: waiting for machine
Feb 03 18:18:44   mysql/2 [allocating] waiting: waiting for machine
Feb 03 18:19:14 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:19:14   mysql/0 [allocating] waiting: waiting for machine
Feb 03 18:19:14   mysql/1 [allocating] waiting: waiting for machine
Feb 03 18:19:14   mysql/2 [allocating] waiting: waiting for machine
Feb 03 18:19:44 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:19:44   mysql/0 [executing] maintenance: installing charm software
Feb 03 18:19:44   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 18:19:44   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 18:20:14 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:20:14   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 18:20:14   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 18:20:14   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 18:20:44 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:20:44   mysql/0 [executing] maintenance: Setting up cluster node
Feb 03 18:20:44   mysql/1 [executing] maintenance: Setting up cluster node
Feb 03 18:20:44   mysql/2 [executing] maintenance: Setting up cluster node
Feb 03 18:21:14 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:21:14   mysql/0 [executing] waiting: Waiting to join the cluster
Feb 03 18:21:14   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 03 18:21:14   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 18:21:44 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:21:44   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 18:21:44   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 18:21:44   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 18:21:58 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-qrdl0
Feb 03 18:21:58 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 18:22:20 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 21.67s
Feb 03 18:22:27 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 18:22:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:22:27   application/0 [allocating] waiting: waiting for machine
Feb 03 18:22:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:22:57   application/0 [allocating] waiting: waiting for machine
Feb 03 18:23:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:23:27   application/0 [allocating] waiting: waiting for machine
Feb 03 18:23:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:23:57   application/0 [executing] maintenance: installing charm software
Feb 03 18:24:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:24:16   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 18:24:16   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 18:24:16   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 18:24:16   application/0 [idle] waiting: 
Feb 03 18:24:45 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 18:24:45 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 18:25:09 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 18:25:14 INFO     integration.high_availability.test_replication:test_replication.py:74 Destroying leader unit
Feb 03 18:25:35 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:25:35   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 18:25:35   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 18:25:57 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 18:26:01 INFO     integration.high_availability.test_replication:test_replication.py:93 Scaling back to 3 units
Feb 03 18:26:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:26:02   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 18:26:02   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 18:26:02   mysql/3 [allocating] waiting: waiting for machine
Feb 03 18:26:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:26:32   mysql/3 [allocating] waiting: waiting for machine
Feb 03 18:27:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:27:02   mysql/3 [allocating] waiting: waiting for machine
Feb 03 18:27:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:27:32   mysql/3 [allocating] waiting: waiting for machine
Feb 03 18:28:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:28:02   mysql/3 [allocating] waiting: waiting for machine
Feb 03 18:28:33 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:28:33   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 18:29:03 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:29:03   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 18:29:33 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:29:33   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 18:29:33   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 18:29:33   mysql/3 [executing] maintenance: Setting up cluster node
Feb 03 18:30:03 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:30:03   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 18:30:03   mysql/3 [idle] waiting: Waiting to join the cluster
Feb 03 18:30:33 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 18:30:33   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 18:30:33   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 18:30:50 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 18:30:52 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 18:30:53 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 18:31:13 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 18:31:34 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 18:31:40 PASSED
Feb 03 18:31:40 ------------------------------ live log teardown -------------------------------
Feb 03 18:31:40 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 18:31:40 
Feb 03 18:31:40 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 18:31:40 test-replication-qrdl  lxd         localhost/localhost  2.9.29   unsupported  18:31:40Z
Feb 03 18:31:40 
Feb 03 18:31:40 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 18:31:40 application                   active      1  application             0  no       
Feb 03 18:31:40 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 18:31:40 
Feb 03 18:31:40 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 18:31:40 application/0*  active    idle   3        10.45.7.249            
Feb 03 18:31:40 mysql/0         active    idle   0        10.45.7.242            Unit is ready: Mode: RO
Feb 03 18:31:40 mysql/1*        active    idle   1        10.45.7.131            Unit is ready: Mode: RW
Feb 03 18:31:40 mysql/3         active    idle   4        10.45.7.146            Unit is ready: Mode: RO
Feb 03 18:31:40 
Feb 03 18:31:40 Machine  State    Address      Inst id        Series  AZ  Message
Feb 03 18:31:40 0        started  10.45.7.242  juju-111203-0  jammy       Running
Feb 03 18:31:40 1        started  10.45.7.131  juju-111203-1  jammy       Running
Feb 03 18:31:40 3        started  10.45.7.249  juju-111203-3  focal       Running
Feb 03 18:31:40 4        started  10.45.7.146  juju-111203-4  jammy       Running
Feb 03 18:31:40 
Feb 03 18:31:40 
Feb 03 18:31:40 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 18:31:40 
Feb 03 18:31:40 machine-2: 18:19:22 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 18:31:40 unit-mysql-2: 18:19:23 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 18:31:40 machine-1: 18:19:24 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 18:31:40 unit-mysql-1: 18:19:24 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 18:31:40 machine-0: 18:19:26 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 18:31:40 unit-mysql-0: 18:19:28 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 18:31:40 machine-3: 18:23:49 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 18:31:40 unit-application-0: 18:23:49 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 18:31:40 unit-mysql-3: 18:28:09 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 18:31:40 machine-4: 18:28:09 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 18:31:40 
Feb 03 18:31:40 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-qrdl...
Feb 03 18:31:40 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 18:31:40 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 18:31:40 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 18:31:45 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 03 18:31:47 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 18:31:48 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 18:31:49 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 18:31:50 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 18:31:51 
Feb 03 18:31:51 
Feb 03 18:31:51 ======================== 1 passed in 909.65s (0:15:09) =========================
Feb 03 18:31:52   integration: OK (910.84=setup[0.05]+cmd[910.78] seconds)
Feb 03 18:31:52   congratulations :) (910.89 seconds)

One statement

af46d38
Actions runs: https://github.com/canonical/mysql-operator/actions/runs/4085415379/jobs/7044684607

  1. 19 min 1 sec
  2. 13 min 35 sec
  3. 15 min 17 sec
  4. 13 min 10 sec
  5. 13 min 11 sec

Runs on Google Cloud VM:

  1. 14 min 58 sec
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 15:35:31 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 15:35:32 ============================= test session starts ==============================
Feb 03 15:35:32 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 15:35:32 cachedir: .tox/integration/.pytest_cache
Feb 03 15:35:32 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 15:35:32 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 15:35:32 asyncio: mode=auto
Feb 03 15:35:32 collecting ... collected 1 item
Feb 03 15:35:32 
Feb 03 15:35:32 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 15:35:32 -------------------------------- live log setup --------------------------------
Feb 03 15:35:32 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-82pp on cloud localhost
Feb 03 15:35:35 -------------------------------- live log call ---------------------------------
Feb 03 15:35:35 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-82pp0
Feb 03 15:35:35 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 15:36:04 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 28.84s
Feb 03 15:36:04 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-82pp0
Feb 03 15:36:04 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 15:36:23 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 19.65s
Feb 03 15:36:29 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 15:36:40 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 15:36:41 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:36:41   mysql/0 [allocating] waiting: waiting for machine
Feb 03 15:36:41   mysql/1 [allocating] waiting: waiting for machine
Feb 03 15:36:41   mysql/2 [allocating] waiting: waiting for machine
Feb 03 15:36:41   application/0 [allocating] waiting: waiting for machine
Feb 03 15:37:11 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:37:11   mysql/0 [allocating] waiting: waiting for machine
Feb 03 15:37:11   mysql/1 [allocating] waiting: waiting for machine
Feb 03 15:37:11   mysql/2 [allocating] waiting: waiting for machine
Feb 03 15:37:11   application/0 [allocating] waiting: waiting for machine
Feb 03 15:37:41 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:37:41   mysql/0 [allocating] waiting: waiting for machine
Feb 03 15:37:41   mysql/1 [allocating] waiting: waiting for machine
Feb 03 15:37:41   mysql/2 [allocating] waiting: waiting for machine
Feb 03 15:37:41   application/0 [allocating] waiting: waiting for machine
Feb 03 15:38:11 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:38:11   mysql/0 [allocating] waiting: waiting for machine
Feb 03 15:38:11   mysql/1 [allocating] waiting: waiting for machine
Feb 03 15:38:11   mysql/2 [allocating] waiting: waiting for machine
Feb 03 15:38:11   application/0 [allocating] waiting: waiting for machine
Feb 03 15:38:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:38:42   mysql/0 [allocating] waiting: waiting for machine
Feb 03 15:38:42   mysql/1 [allocating] waiting: waiting for machine
Feb 03 15:38:42   mysql/2 [allocating] waiting: waiting for machine
Feb 03 15:38:42   application/0 [allocating] waiting: waiting for machine
Feb 03 15:39:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:39:12   mysql/0 [allocating] waiting: waiting for machine
Feb 03 15:39:12   mysql/1 [allocating] waiting: waiting for machine
Feb 03 15:39:12   mysql/2 [allocating] waiting: waiting for machine
Feb 03 15:39:12   application/0 [allocating] waiting: waiting for machine
Feb 03 15:39:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:39:42   mysql/0 [allocating] waiting: agent initializing
Feb 03 15:39:42   mysql/1 [allocating] waiting: agent initializing
Feb 03 15:39:42   mysql/2 [allocating] waiting: agent initializing
Feb 03 15:39:42   application/0 [allocating] waiting: waiting for machine
Feb 03 15:40:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:40:12   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 15:40:12   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 15:40:12   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 15:40:12   application/0 [executing] maintenance: installing charm software
Feb 03 15:40:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:40:42   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 15:40:42   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 15:40:42   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 15:40:42   application/0 [idle] waiting: 
Feb 03 15:41:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:41:12   mysql/0 [executing] maintenance: Setting up cluster node
Feb 03 15:41:12   mysql/1 [executing] maintenance: Setting up cluster node
Feb 03 15:41:12   mysql/2 [executing] maintenance: Setting up cluster node
Feb 03 15:41:12   application/0 [idle] waiting: 
Feb 03 15:41:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:41:42   mysql/0 [idle] waiting: Waiting to join the cluster
Feb 03 15:41:42   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 15:41:42   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 15:41:42   application/0 [idle] active: 
Feb 03 15:42:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:42:12   mysql/0 [executing] waiting: Waiting to join the cluster
Feb 03 15:42:12   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 03 15:42:12   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 15:42:12   application/0 [idle] active: 
Feb 03 15:42:43 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:42:43   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 15:42:43   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 15:43:13 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:43:13   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 15:43:13   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 15:43:22 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 03 15:43:22 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 15:43:22 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 15:43:43 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 15:43:48 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 03 15:44:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:44:09   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 15:44:09   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 15:44:32 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 15:44:37 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 03 15:44:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:44:39   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 15:44:39   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 15:44:39   mysql/3 [allocating] waiting: waiting for machine
Feb 03 15:45:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:45:09   mysql/3 [allocating] waiting: waiting for machine
Feb 03 15:45:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:45:39   mysql/3 [allocating] waiting: waiting for machine
Feb 03 15:46:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:46:09   mysql/3 [allocating] waiting: waiting for machine
Feb 03 15:46:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:46:39   mysql/3 [allocating] waiting: waiting for machine
Feb 03 15:47:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:47:09   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 15:47:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:47:40   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 15:48:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:48:10   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 15:48:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:48:40   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 15:48:40   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 15:48:40   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 03 15:49:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 15:49:10   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 15:49:10   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 15:49:10   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 15:49:25 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 15:49:28 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 15:49:29 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 15:49:55 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 15:50:12 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 15:50:17 PASSED
Feb 03 15:50:17 ------------------------------ live log teardown -------------------------------
Feb 03 15:50:17 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 15:50:17 
Feb 03 15:50:17 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 15:50:17 test-replication-82pp  lxd         localhost/localhost  2.9.29   unsupported  15:50:17Z
Feb 03 15:50:17 
Feb 03 15:50:17 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 15:50:17 application                   active      1  application             0  no       
Feb 03 15:50:17 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 15:50:17 
Feb 03 15:50:17 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 15:50:17 application/0*  active    idle   3        10.45.7.183            
Feb 03 15:50:17 mysql/0*        active    idle   0        10.45.7.170            Unit is ready: Mode: RW
Feb 03 15:50:17 mysql/1         active    idle   1        10.45.7.36             Unit is ready: Mode: RO
Feb 03 15:50:17 mysql/3         active    idle   4        10.45.7.132            Unit is ready: Mode: RO
Feb 03 15:50:17 
Feb 03 15:50:17 Machine  State    Address      Inst id        Series  AZ  Message
Feb 03 15:50:17 0        started  10.45.7.170  juju-93a802-0  jammy       Running
Feb 03 15:50:17 1        started  10.45.7.36   juju-93a802-1  jammy       Running
Feb 03 15:50:17 3        started  10.45.7.183  juju-93a802-3  focal       Running
Feb 03 15:50:17 4        started  10.45.7.132  juju-93a802-4  jammy       Running
Feb 03 15:50:17 
Feb 03 15:50:17 
Feb 03 15:50:18 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 15:50:18 
Feb 03 15:50:18 machine-2: 15:39:26 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 15:50:18 unit-mysql-2: 15:39:27 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 15:50:18 machine-0: 15:39:31 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 15:50:18 unit-mysql-0: 15:39:31 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 15:50:18 unit-mysql-1: 15:39:35 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 15:50:18 machine-1: 15:39:36 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 15:50:18 machine-3: 15:39:53 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 15:50:18 unit-application-0: 15:39:53 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 15:50:18 machine-4: 15:46:51 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 15:50:18 unit-mysql-3: 15:46:52 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 15:50:18 
Feb 03 15:50:18 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-82pp...
Feb 03 15:50:18 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 15:50:18 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 15:50:18 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 15:50:22 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 03 15:50:24 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 15:50:25 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 15:50:27 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 15:50:28 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 15:50:29 
Feb 03 15:50:29 
Feb 03 15:50:29 ======================== 1 passed in 897.10s (0:14:57) =========================
Feb 03 15:50:29   integration: OK (898.32=setup[0.07]+cmd[898.25] seconds)
Feb 03 15:50:29   congratulations :) (898.44 seconds)
  1. 14 min 54 sec
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 16:30:51 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 16:30:52 ============================= test session starts ==============================
Feb 03 16:30:52 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 16:30:52 cachedir: .tox/integration/.pytest_cache
Feb 03 16:30:52 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 16:30:52 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 16:30:52 asyncio: mode=auto
Feb 03 16:30:52 collecting ... collected 1 item
Feb 03 16:30:52 
Feb 03 16:30:52 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 16:30:52 -------------------------------- live log setup --------------------------------
Feb 03 16:30:52 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-cd9n on cloud localhost
Feb 03 16:30:56 -------------------------------- live log call ---------------------------------
Feb 03 16:30:56 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-cd9n0
Feb 03 16:30:56 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 16:31:18 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 22.14s
Feb 03 16:31:18 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-cd9n0
Feb 03 16:31:18 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 16:31:38 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 19.88s
Feb 03 16:31:43 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 16:31:56 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 16:31:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:31:57   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:31:57   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:31:57   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:31:57   application/0 [allocating] waiting: waiting for machine
Feb 03 16:32:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:32:27   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:32:27   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:32:27   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:32:27   application/0 [allocating] waiting: waiting for machine
Feb 03 16:32:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:32:57   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:32:57   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:32:57   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:32:57   application/0 [allocating] waiting: waiting for machine
Feb 03 16:33:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:33:27   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:33:27   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:33:27   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:33:27   application/0 [allocating] waiting: waiting for machine
Feb 03 16:33:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:33:58   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:33:58   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:33:58   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:33:58   application/0 [allocating] waiting: waiting for machine
Feb 03 16:34:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:34:28   mysql/0 [allocating] waiting: waiting for machine
Feb 03 16:34:28   mysql/1 [allocating] waiting: waiting for machine
Feb 03 16:34:28   mysql/2 [allocating] waiting: waiting for machine
Feb 03 16:34:28   application/0 [allocating] waiting: waiting for machine
Feb 03 16:34:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:34:58   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 16:34:58   mysql/1 [allocating] waiting: agent initializing
Feb 03 16:34:58   mysql/2 [executing] waiting: agent initializing
Feb 03 16:34:58   application/0 [allocating] waiting: waiting for machine
Feb 03 16:35:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:35:28   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 16:35:28   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 16:35:28   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 16:35:28   application/0 [idle] waiting: 
Feb 03 16:35:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:35:58   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 16:35:58   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 16:35:58   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 16:35:58   application/0 [idle] waiting: 
Feb 03 16:36:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:36:28   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:36:28   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 03 16:36:28   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 03 16:36:28   application/0 [idle] waiting: 
Feb 03 16:36:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:36:58   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:36:58   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 16:36:58   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 16:37:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:37:28   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:37:28   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 16:37:28   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 16:37:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:37:59   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 16:37:59   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 16:37:59   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 16:37:59   application/0 [idle] active: 
Feb 03 16:38:24 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 03 16:38:24 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 16:38:24 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:38:49 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:38:57 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 03 16:39:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:39:17   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 16:39:17   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 16:39:40 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:39:44 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 03 16:39:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:39:46   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 16:39:46   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 16:39:46   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:40:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:40:16   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:40:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:40:46   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:41:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:41:16   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:41:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:41:46   mysql/3 [allocating] waiting: waiting for machine
Feb 03 16:42:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:42:16   mysql/3 [allocating] waiting: agent initializing
Feb 03 16:42:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:42:47   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 16:43:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:43:17   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 16:43:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:43:47   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 16:43:47   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 16:43:47   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 03 16:44:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 16:44:17   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 16:44:17   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 16:44:17   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 16:44:43 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 16:44:46 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 16:44:47 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:45:08 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:45:27 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 16:45:33 PASSED
Feb 03 16:45:33 ------------------------------ live log teardown -------------------------------
Feb 03 16:45:33 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 16:45:33 
Feb 03 16:45:33 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 16:45:33 test-replication-cd9n  lxd         localhost/localhost  2.9.29   unsupported  16:45:33Z
Feb 03 16:45:33 
Feb 03 16:45:33 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 16:45:33 application                   active      1  application             0  no       
Feb 03 16:45:33 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 16:45:33 
Feb 03 16:45:33 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 16:45:33 application/0*  active    idle   3        10.45.7.194            
Feb 03 16:45:33 mysql/1*        active    idle   1        10.45.7.71             Unit is ready: Mode: RO
Feb 03 16:45:33 mysql/2         active    idle   2        10.45.7.253            Unit is ready: Mode: RW
Feb 03 16:45:33 mysql/3         active    idle   4        10.45.7.79             Unit is ready: Mode: RO
Feb 03 16:45:33 
Feb 03 16:45:33 Machine  State    Address      Inst id        Series  AZ  Message
Feb 03 16:45:33 1        started  10.45.7.71   juju-dffdf2-1  jammy       Running
Feb 03 16:45:33 2        started  10.45.7.253  juju-dffdf2-2  jammy       Running
Feb 03 16:45:33 3        started  10.45.7.194  juju-dffdf2-3  focal       Running
Feb 03 16:45:33 4        started  10.45.7.79   juju-dffdf2-4  jammy       Running
Feb 03 16:45:33 
Feb 03 16:45:33 
Feb 03 16:45:34 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 16:45:34 
Feb 03 16:45:34 unit-mysql-0: 16:34:34 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:45:34 unit-mysql-2: 16:34:38 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:45:34 machine-2: 16:34:39 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:45:34 machine-1: 16:34:41 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:45:34 unit-mysql-1: 16:34:42 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:45:34 machine-3: 16:35:03 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:45:34 unit-application-0: 16:35:03 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:45:34 machine-4: 16:42:05 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 16:45:34 unit-mysql-3: 16:42:06 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 16:45:34 
Feb 03 16:45:34 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-cd9n...
Feb 03 16:45:34 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 16:45:34 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 16:45:34 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 03 16:45:39 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 03 16:45:40 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 16:45:42 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 16:45:44 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 16:45:45 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 16:45:46 
Feb 03 16:45:46 
Feb 03 16:45:46 ======================== 1 passed in 893.80s (0:14:53) =========================
Feb 03 16:45:46   integration: OK (894.92=setup[0.05]+cmd[894.87] seconds)
Feb 03 16:45:46   congratulations :) (894.97 seconds)
3. 14 min 32 sec
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 17:24:02 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 17:24:03 ============================= test session starts ==============================
Feb 03 17:24:03 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 17:24:03 cachedir: .tox/integration/.pytest_cache
Feb 03 17:24:03 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 17:24:03 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 17:24:03 asyncio: mode=auto
Feb 03 17:24:03 collecting ... collected 1 item
Feb 03 17:24:03 
Feb 03 17:24:03 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 17:24:03 -------------------------------- live log setup --------------------------------
Feb 03 17:24:03 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-6df7 on cloud localhost
Feb 03 17:24:04 -------------------------------- live log call ---------------------------------
Feb 03 17:24:04 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-6df70
Feb 03 17:24:04 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 17:24:27 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 22.10s
Feb 03 17:24:27 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-6df70
Feb 03 17:24:27 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 17:24:46 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 19.74s
Feb 03 17:24:52 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 17:25:04 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 17:25:05 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:25:05   mysql/0 [allocating] waiting: waiting for machine
Feb 03 17:25:05   mysql/1 [allocating] waiting: waiting for machine
Feb 03 17:25:05   mysql/2 [allocating] waiting: waiting for machine
Feb 03 17:25:05   application/0 [allocating] waiting: waiting for machine
Feb 03 17:25:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:25:36   mysql/0 [allocating] waiting: waiting for machine
Feb 03 17:25:36   mysql/1 [allocating] waiting: waiting for machine
Feb 03 17:25:36   mysql/2 [allocating] waiting: waiting for machine
Feb 03 17:25:36   application/0 [allocating] waiting: waiting for machine
Feb 03 17:26:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:26:06   mysql/0 [allocating] waiting: waiting for machine
Feb 03 17:26:06   mysql/1 [allocating] waiting: waiting for machine
Feb 03 17:26:06   mysql/2 [allocating] waiting: waiting for machine
Feb 03 17:26:06   application/0 [allocating] waiting: waiting for machine
Feb 03 17:26:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:26:36   mysql/0 [allocating] waiting: waiting for machine
Feb 03 17:26:36   mysql/1 [allocating] waiting: waiting for machine
Feb 03 17:26:36   mysql/2 [allocating] waiting: waiting for machine
Feb 03 17:26:36   application/0 [allocating] waiting: waiting for machine
Feb 03 17:27:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:27:06   mysql/0 [allocating] waiting: waiting for machine
Feb 03 17:27:06   mysql/1 [allocating] waiting: waiting for machine
Feb 03 17:27:06   mysql/2 [allocating] waiting: waiting for machine
Feb 03 17:27:06   application/0 [allocating] waiting: waiting for machine
Feb 03 17:27:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:27:36   mysql/0 [allocating] waiting: waiting for machine
Feb 03 17:27:36   mysql/1 [allocating] waiting: waiting for machine
Feb 03 17:27:36   mysql/2 [allocating] waiting: waiting for machine
Feb 03 17:27:36   application/0 [allocating] waiting: waiting for machine
Feb 03 17:28:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:28:06   mysql/0 [allocating] waiting: agent initializing
Feb 03 17:28:06   mysql/1 [allocating] waiting: agent initializing
Feb 03 17:28:06   mysql/2 [allocating] waiting: agent initializing
Feb 03 17:28:06   application/0 [allocating] waiting: waiting for machine
Feb 03 17:28:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:28:36   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 17:28:36   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 17:28:36   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 17:28:36   application/0 [idle] waiting: 
Feb 03 17:29:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:29:06   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 17:29:06   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 17:29:06   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 17:29:06   application/0 [idle] waiting: 
Feb 03 17:29:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:29:36   mysql/0 [executing] waiting: Waiting to join the cluster
Feb 03 17:29:36   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 03 17:29:36   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 17:29:36   application/0 [idle] waiting: 
Feb 03 17:30:07 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:30:07   mysql/0 [idle] waiting: Waiting to join the cluster
Feb 03 17:30:07   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 17:30:07   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 17:30:37 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:30:37   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 17:30:37   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 17:30:37   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 17:31:07 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:31:07   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 17:31:07   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 17:31:07   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 17:31:07   application/0 [idle] active: 
Feb 03 17:31:29 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 03 17:31:29 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 17:31:29 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:31:53 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:31:58 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 03 17:32:19 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:32:19   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 17:32:19   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 17:32:41 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:32:45 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 03 17:32:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:32:46   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 17:32:46   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 17:32:46   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:33:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:33:16   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:33:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:33:46   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:34:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:34:16   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:34:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:34:46   mysql/3 [allocating] waiting: waiting for machine
Feb 03 17:35:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:35:16   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 17:35:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:35:46   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 17:36:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:36:16   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 17:36:16   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 17:36:16   mysql/3 [executing] waiting: Waiting to start MySQL
Feb 03 17:36:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:36:47   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 17:36:47   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 17:36:47   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 03 17:37:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 17:37:17   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 17:37:17   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 17:37:17   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 17:37:32 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 17:37:36 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 17:37:36 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:37:56 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:38:16 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 17:38:21 PASSED
Feb 03 17:38:21 ------------------------------ live log teardown -------------------------------
Feb 03 17:38:21 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 17:38:21 
Feb 03 17:38:21 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 17:38:21 test-replication-6df7  lxd         localhost/localhost  2.9.29   unsupported  17:38:21Z
Feb 03 17:38:21 
Feb 03 17:38:21 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 17:38:21 application                   active      1  application             0  no       
Feb 03 17:38:21 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 17:38:21 
Feb 03 17:38:21 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 17:38:21 application/0*  active    idle   3        10.45.7.53             
Feb 03 17:38:21 mysql/0         active    idle   0        10.45.7.227            Unit is ready: Mode: RW
Feb 03 17:38:21 mysql/1*        active    idle   1        10.45.7.50             Unit is ready: Mode: RO
Feb 03 17:38:21 mysql/3         active    idle   4        10.45.7.94             Unit is ready: Mode: RO
Feb 03 17:38:21 
Feb 03 17:38:21 Machine  State    Address      Inst id        Series  AZ  Message
Feb 03 17:38:21 0        started  10.45.7.227  juju-4f0c48-0  jammy       Running
Feb 03 17:38:21 1        started  10.45.7.50   juju-4f0c48-1  jammy       Running
Feb 03 17:38:21 3        started  10.45.7.53   juju-4f0c48-3  focal       Running
Feb 03 17:38:21 4        started  10.45.7.94   juju-4f0c48-4  jammy       Running
Feb 03 17:38:21 
Feb 03 17:38:21 
Feb 03 17:38:21 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 17:38:21 
Feb 03 17:38:21 machine-2: 17:27:46 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:38:21 machine-0: 17:27:47 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:38:21 unit-mysql-2: 17:27:48 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:38:21 unit-mysql-0: 17:27:48 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:38:21 machine-1: 17:27:50 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:38:21 unit-mysql-1: 17:27:52 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:38:21 unit-application-0: 17:28:11 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:38:21 machine-3: 17:28:11 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:38:21 machine-4: 17:34:57 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 17:38:21 unit-mysql-3: 17:34:58 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 17:38:21 
Feb 03 17:38:21 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-6df7...
Feb 03 17:38:21 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 17:38:22 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 17:38:22 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 17:38:27 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 03 17:38:28 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 17:38:30 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 17:38:31 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 17:38:33 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 17:38:34 
Feb 03 17:38:34 
Feb 03 17:38:34 ======================== 1 passed in 870.83s (0:14:30) =========================
Feb 03 17:38:34   integration: OK (872.11=setup[0.06]+cmd[872.05] seconds)
Feb 03 17:38:34   congratulations :) (872.18 seconds)

@carlcsaposs-canonical
Copy link
Contributor Author

Note that Google Cloud VM used is n2-standard-4 (4 vCPUs, 16GB ram)

GitHub Actions runners have 2 vCPUs and 7 GB ram: https://docs.github.com/en/actions/using-github-hosted-runners/about-github-hosted-runners#supported-runners-and-hardware-resources

@carlcsaposs-canonical
Copy link
Contributor Author

Results from running (while running jhack ffwd) on af46d38

juju deploy ./mysql_ubuntu-22.04-amd64.charm -n 3 --series=jammy &&
juju deploy ./tests/integration/high_availability/application_charm/application_ubuntu-20.04-amd64.charm &&
juju relate mysql:database application:database

Total time: 5 min 45 sec
Time for LXD containers to be ready: 3 min 16 sec
Time for mysql to install: 1 min 19 sec
Time for active/idle: 1 min 10 sec

Compared to total time in integration test: 6 min 53 sec

@carlcsaposs-canonical
Copy link
Contributor Author

Results with Google Cloud VM n2-standard-16 (16 vCPUs, 64GB ram):

Manual commands:
Total time: 2 min 56 sec
Time for LXD containers to be ready: 1 min 25 sec
Time for mysql to install: 41 sec
Time for active/idle: 49 sec

@carlcsaposs-canonical
Copy link
Contributor Author

carlcsaposs-canonical commented Feb 3, 2023

Results with Google Cloud VM n2-standard-16 (16 vCPUs, 64GB ram):

Multiple statements (7d68ff5)
8 min 29 sec

$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 19:29:34 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 19:29:34 ============================= test session starts ==============================
Feb 03 19:29:34 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 19:29:34 cachedir: .tox/integration/.pytest_cache
Feb 03 19:29:34 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 19:29:34 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 19:29:34 asyncio: mode=auto
Feb 03 19:29:34 collecting ... collected 1 item
Feb 03 19:29:34 
Feb 03 19:29:34 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 19:29:34 -------------------------------- live log setup --------------------------------
Feb 03 19:29:34 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-p9u1 on cloud localhost
Feb 03 19:29:38 -------------------------------- live log call ---------------------------------
Feb 03 19:29:38 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-p9u10
Feb 03 19:29:38 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 19:29:57 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 18.99s
Feb 03 19:30:01 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 19:30:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:30:02   mysql/0 [allocating] waiting: waiting for machine
Feb 03 19:30:02   mysql/1 [allocating] waiting: waiting for machine
Feb 03 19:30:02   mysql/2 [allocating] waiting: waiting for machine
Feb 03 19:30:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:30:32   mysql/0 [allocating] waiting: waiting for machine
Feb 03 19:30:32   mysql/1 [allocating] waiting: waiting for machine
Feb 03 19:30:32   mysql/2 [allocating] waiting: waiting for machine
Feb 03 19:31:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:31:02   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 19:31:02   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 19:31:02   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 19:31:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:31:32   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 19:31:32   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 19:31:32   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 19:32:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:32:02   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:32:02   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 19:32:02   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 19:32:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:32:32   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:32:32   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:32:38 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-p9u10
Feb 03 19:32:38 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 19:32:52 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 13.83s
Feb 03 19:32:57 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 19:32:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:32:58   application/0 [allocating] waiting: waiting for machine
Feb 03 19:33:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:33:28   application/0 [allocating] waiting: waiting for machine
Feb 03 19:33:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:33:58   application/0 [idle] waiting: 
Feb 03 19:34:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:34:06   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 19:34:06   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:34:06   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 03 19:34:06   application/0 [idle] waiting: 
Feb 03 19:34:26 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 19:34:26 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:34:37 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:34:39 INFO     integration.high_availability.test_replication:test_replication.py:74 Destroying leader unit
Feb 03 19:34:51 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:34:51   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 19:34:51   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 19:35:09 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:35:11 INFO     integration.high_availability.test_replication:test_replication.py:93 Scaling back to 3 units
Feb 03 19:35:11 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:35:11   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:35:11   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 19:35:11   mysql/3 [allocating] waiting: waiting for machine
Feb 03 19:35:41 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:35:41   mysql/3 [allocating] waiting: waiting for machine
Feb 03 19:36:11 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:36:11   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 19:36:41 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:36:41   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 19:36:41   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 19:36:41   mysql/3 [executing] waiting: Waiting to start MySQL
Feb 03 19:37:11 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:37:11   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:37:11   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 19:37:11   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 19:37:38 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 19:37:40 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 19:37:40 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:37:49 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:37:56 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:37:58 PASSED
Feb 03 19:37:58 ------------------------------ live log teardown -------------------------------
Feb 03 19:37:58 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 19:37:58 
Feb 03 19:37:58 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 19:37:58 test-replication-p9u1  lxd         localhost/localhost  2.9.29   unsupported  19:37:58Z
Feb 03 19:37:58 
Feb 03 19:37:58 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 19:37:58 application                   active      1  application             0  no       
Feb 03 19:37:58 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 19:37:58 
Feb 03 19:37:58 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 19:37:58 application/0*  active    idle   3        10.19.212.136          
Feb 03 19:37:58 mysql/0*        active    idle   0        10.19.212.36           Unit is ready: Mode: RO
Feb 03 19:37:58 mysql/2         active    idle   2        10.19.212.221          Unit is ready: Mode: RW
Feb 03 19:37:58 mysql/3         active    idle   4        10.19.212.160          Unit is ready: Mode: RO
Feb 03 19:37:58 
Feb 03 19:37:58 Machine  State    Address        Inst id        Series  AZ  Message
Feb 03 19:37:58 0        started  10.19.212.36   juju-cdcb8b-0  jammy       Running
Feb 03 19:37:58 2        started  10.19.212.221  juju-cdcb8b-2  jammy       Running
Feb 03 19:37:58 3        started  10.19.212.136  juju-cdcb8b-3  focal       Running
Feb 03 19:37:58 4        started  10.19.212.160  juju-cdcb8b-4  jammy       Running
Feb 03 19:37:58 
Feb 03 19:37:58 
Feb 03 19:37:58 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 19:37:58 
Feb 03 19:37:58 machine-1: 19:30:48 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:37:58 unit-mysql-1: 19:30:48 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:37:58 machine-0: 19:30:52 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:37:58 unit-mysql-0: 19:30:52 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:37:58 machine-2: 19:30:54 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:37:58 unit-mysql-2: 19:30:54 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:37:58 machine-3: 19:33:44 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:37:58 unit-application-0: 19:33:44 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:37:58 machine-4: 19:35:59 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:37:58 unit-mysql-3: 19:35:59 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:37:58 
Feb 03 19:37:58 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-p9u1...
Feb 03 19:37:58 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 19:37:58 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 19:37:59 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 19:38:00 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 03 19:38:00 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 19:38:01 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 19:38:01 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 19:38:02 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 19:38:03 
Feb 03 19:38:03 
Feb 03 19:38:03 ======================== 1 passed in 508.92s (0:08:28) =========================
Feb 03 19:38:04   integration: OK (509.74=setup[0.03]+cmd[509.70] seconds)
Feb 03 19:38:04   congratulations :) (509.78 seconds)

One statement (af46d38)
7 min 14 sec

$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 19:19:34 integration: install_deps> python -I -m pip install juju==2.9.38.1 mysql-connector-python pytest pytest-operator pyyaml -r /home/ubuntu/repos/mysql-operator/requirements.txt
Feb 03 19:19:46 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 19:19:46 ============================= test session starts ==============================
Feb 03 19:19:46 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 19:19:46 cachedir: .tox/integration/.pytest_cache
Feb 03 19:19:46 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 19:19:46 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 19:19:46 asyncio: mode=auto
Feb 03 19:19:46 collecting ... collected 1 item
Feb 03 19:19:46 
Feb 03 19:19:46 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 19:19:46 -------------------------------- live log setup --------------------------------
Feb 03 19:19:46 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-088g on cloud localhost
Feb 03 19:19:48 -------------------------------- live log call ---------------------------------
Feb 03 19:19:48 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-088g0
Feb 03 19:19:48 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 19:20:05 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 17.69s
Feb 03 19:20:05 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-088g0
Feb 03 19:20:05 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 19:20:19 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 13.49s
Feb 03 19:20:21 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 19:20:30 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 19:20:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:20:30   mysql/0 [allocating] waiting: waiting for machine
Feb 03 19:20:30   mysql/1 [allocating] waiting: waiting for machine
Feb 03 19:20:30   mysql/2 [allocating] waiting: waiting for machine
Feb 03 19:20:30   application/0 [allocating] waiting: waiting for machine
Feb 03 19:21:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:21:00   mysql/0 [allocating] waiting: waiting for machine
Feb 03 19:21:00   mysql/1 [allocating] waiting: waiting for machine
Feb 03 19:21:00   mysql/2 [allocating] waiting: waiting for machine
Feb 03 19:21:00   application/0 [allocating] waiting: waiting for machine
Feb 03 19:21:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:21:30   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 19:21:30   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 19:21:30   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 19:21:30   application/0 [allocating] waiting: agent initializing
Feb 03 19:22:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:22:00   mysql/0 [executing] waiting: Waiting to start MySQL
Feb 03 19:22:00   mysql/1 [executing] waiting: Waiting to start MySQL
Feb 03 19:22:00   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 19:22:00   application/0 [executing] waiting: 
Feb 03 19:22:31 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:22:31   mysql/0 [idle] waiting: Waiting to join the cluster
Feb 03 19:22:31   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 19:22:31   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 19:22:31   application/0 [idle] waiting: 
Feb 03 19:23:01 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:23:01   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:23:01   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:23:01   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:23:01   application/0 [idle] active: 
Feb 03 19:23:31 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:23:31   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:23:31   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:23:31   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:23:31   application/0 [idle] active: 
Feb 03 19:23:35 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 03 19:23:35 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 19:23:35 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:23:44 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:23:47 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 03 19:23:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:23:58   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 19:23:58   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 03 19:24:16 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:24:18 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 03 19:24:18 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:24:18   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 19:24:18   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:24:18   mysql/3 [allocating] waiting: waiting for machine
Feb 03 19:24:48 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:24:48   mysql/3 [allocating] waiting: waiting for machine
Feb 03 19:25:18 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:25:18   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 19:25:48 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:25:48   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 19:25:48   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 03 19:25:48   mysql/3 [executing] maintenance: Setting up cluster node
Feb 03 19:26:19 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:26:19   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 19:26:19   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:26:19   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 19:26:37 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 19:26:38 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 19:26:38 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:26:46 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:26:53 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:26:55 PASSED
Feb 03 19:26:55 ------------------------------ live log teardown -------------------------------
Feb 03 19:26:55 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 19:26:55 
Feb 03 19:26:55 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 19:26:55 test-replication-088g  lxd         localhost/localhost  2.9.29   unsupported  19:26:55Z
Feb 03 19:26:55 
Feb 03 19:26:55 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 19:26:55 application                   active      1  application             0  no       
Feb 03 19:26:55 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 19:26:55 
Feb 03 19:26:55 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 19:26:55 application/0*  active    idle   3        10.19.212.202          
Feb 03 19:26:55 mysql/0         active    idle   0        10.19.212.244          Unit is ready: Mode: RW
Feb 03 19:26:55 mysql/2*        active    idle   2        10.19.212.246          Unit is ready: Mode: RO
Feb 03 19:26:55 mysql/3         active    idle   4        10.19.212.139          Unit is ready: Mode: RO
Feb 03 19:26:55 
Feb 03 19:26:55 Machine  State    Address        Inst id        Series  AZ  Message
Feb 03 19:26:55 0        started  10.19.212.244  juju-e5b46b-0  jammy       Running
Feb 03 19:26:55 2        started  10.19.212.246  juju-e5b46b-2  jammy       Running
Feb 03 19:26:55 3        started  10.19.212.202  juju-e5b46b-3  focal       Running
Feb 03 19:26:55 4        started  10.19.212.139  juju-e5b46b-4  jammy       Running
Feb 03 19:26:55 
Feb 03 19:26:55 
Feb 03 19:26:55 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 19:26:55 
Feb 03 19:26:55 machine-1: 19:21:16 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:26:55 unit-mysql-1: 19:21:16 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:26:55 machine-0: 19:21:17 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:26:55 unit-mysql-0: 19:21:17 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:26:55 machine-2: 19:21:22 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:26:55 unit-mysql-2: 19:21:22 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:26:55 machine-3: 19:21:27 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:26:55 unit-application-0: 19:21:27 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:26:55 machine-4: 19:25:03 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:26:55 unit-mysql-3: 19:25:03 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:26:55 
Feb 03 19:26:55 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-088g...
Feb 03 19:26:55 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 19:26:55 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 19:26:55 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 19:26:57 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 03 19:26:57 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 19:26:57 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 19:26:58 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 19:26:59 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 19:27:00 
Feb 03 19:27:00 
Feb 03 19:27:00 ======================== 1 passed in 433.78s (0:07:13) =========================
Feb 03 19:27:00   integration: OK (446.52=setup[11.89]+cmd[434.63] seconds)
Feb 03 19:27:00   congratulations :) (446.56 seconds)

@carlcsaposs-canonical
Copy link
Contributor Author

Repeated
Multiple statements: 8 min 32 sec

$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 20:00:37 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 20:00:37 ============================= test session starts ==============================
Feb 03 20:00:37 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 20:00:37 cachedir: .tox/integration/.pytest_cache
Feb 03 20:00:37 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 20:00:37 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 20:00:37 asyncio: mode=auto
Feb 03 20:00:37 collecting ... collected 1 item
Feb 03 20:00:37 
Feb 03 20:00:37 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 20:00:37 -------------------------------- live log setup --------------------------------
Feb 03 20:00:37 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-v7h3 on cloud localhost
Feb 03 20:00:41 -------------------------------- live log call ---------------------------------
Feb 03 20:00:41 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-v7h30
Feb 03 20:00:41 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 20:00:56 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 14.64s
Feb 03 20:01:00 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 20:01:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:01:00   mysql/0 [allocating] waiting: waiting for machine
Feb 03 20:01:00   mysql/1 [allocating] waiting: waiting for machine
Feb 03 20:01:00   mysql/2 [allocating] waiting: waiting for machine
Feb 03 20:01:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:01:30   mysql/0 [allocating] waiting: waiting for machine
Feb 03 20:01:30   mysql/1 [allocating] waiting: waiting for machine
Feb 03 20:01:30   mysql/2 [allocating] waiting: waiting for machine
Feb 03 20:02:01 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:02:01   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 20:02:01   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 20:02:01   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 20:02:31 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:02:31   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 20:02:31   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 20:02:31   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 20:03:01 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:03:01   mysql/0 [idle] waiting: Waiting to join the cluster
Feb 03 20:03:01   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 20:03:01   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 20:03:31 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:03:31   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 03 20:03:31   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 20:03:31   mysql/2 [idle] active: Unit is ready: Mode: RW
Feb 03 20:03:41 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-v7h30
Feb 03 20:03:41 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 20:03:54 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 13.50s
Feb 03 20:04:00 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 20:04:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:04:00   application/0 [allocating] waiting: waiting for machine
Feb 03 20:04:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:04:30   application/0 [allocating] waiting: waiting for machine
Feb 03 20:05:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:05:00   application/0 [idle] waiting: 
Feb 03 20:05:05 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:05:05   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 03 20:05:05   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 20:05:05   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 03 20:05:05   application/0 [executing] waiting: 
Feb 03 20:05:26 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 20:05:26 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 20:05:37 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 20:05:39 INFO     integration.high_availability.test_replication:test_replication.py:74 Destroying leader unit
Feb 03 20:05:51 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:05:51   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 20:05:51   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 20:06:09 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 20:06:11 INFO     integration.high_availability.test_replication:test_replication.py:93 Scaling back to 3 units
Feb 03 20:06:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:06:12   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 20:06:12   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 20:06:12   mysql/3 [allocating] waiting: waiting for machine
Feb 03 20:06:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:06:42   mysql/3 [allocating] waiting: waiting for machine
Feb 03 20:07:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:07:12   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 20:07:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:07:42   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 20:07:42   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 03 20:07:42   mysql/3 [executing] maintenance: Setting up cluster node
Feb 03 20:08:12 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:08:12   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 20:08:12   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 20:08:12   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 20:08:42 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 20:08:42   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 03 20:08:42   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 20:08:42   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 20:08:45 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 20:08:47 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 20:08:47 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 20:08:55 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 20:09:02 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 20:09:04 PASSED
Feb 03 20:09:04 ------------------------------ live log teardown -------------------------------
Feb 03 20:09:04 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 20:09:04 
Feb 03 20:09:04 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 20:09:04 test-replication-v7h3  lxd         localhost/localhost  2.9.29   unsupported  20:09:04Z
Feb 03 20:09:04 
Feb 03 20:09:04 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 20:09:04 application                   active      1  application             0  no       
Feb 03 20:09:04 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 20:09:04 
Feb 03 20:09:04 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 20:09:04 application/0*  active    idle   3        10.19.212.175          
Feb 03 20:09:04 mysql/0         active    idle   0        10.19.212.25           Unit is ready: Mode: RW
Feb 03 20:09:04 mysql/1*        active    idle   1        10.19.212.203          Unit is ready: Mode: RO
Feb 03 20:09:04 mysql/3         active    idle   4        10.19.212.2            Unit is ready: Mode: RO
Feb 03 20:09:04 
Feb 03 20:09:04 Machine  State    Address        Inst id        Series  AZ  Message
Feb 03 20:09:04 0        started  10.19.212.25   juju-88eea9-0  jammy       Running
Feb 03 20:09:04 1        started  10.19.212.203  juju-88eea9-1  jammy       Running
Feb 03 20:09:04 3        started  10.19.212.175  juju-88eea9-3  focal       Running
Feb 03 20:09:04 4        started  10.19.212.2    juju-88eea9-4  jammy       Running
Feb 03 20:09:04 
Feb 03 20:09:04 
Feb 03 20:09:04 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 20:09:04 
Feb 03 20:09:04 machine-2: 20:01:50 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 20:09:04 unit-mysql-2: 20:01:50 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 20:09:04 machine-1: 20:01:51 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 20:09:04 unit-mysql-1: 20:01:52 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 20:09:04 machine-0: 20:01:53 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 20:09:04 unit-mysql-0: 20:01:53 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 20:09:04 machine-3: 20:04:43 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 20:09:04 unit-application-0: 20:04:43 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 20:09:04 machine-4: 20:06:56 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 20:09:04 unit-mysql-3: 20:06:56 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 20:09:04 
Feb 03 20:09:04 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-v7h3...
Feb 03 20:09:04 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 20:09:04 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 20:09:04 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 03 20:09:06 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 03 20:09:06 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 20:09:06 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 20:09:07 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 20:09:08 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 20:09:09 
Feb 03 20:09:09 
Feb 03 20:09:09 ======================== 1 passed in 511.92s (0:08:31) =========================
Feb 03 20:09:09   integration: OK (512.75=setup[0.04]+cmd[512.71] seconds)
Feb 03 20:09:09   congratulations :) (512.79 seconds)

One statement: 7 min 12 sec

$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 03 19:41:45 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 03 19:41:46 ============================= test session starts ==============================
Feb 03 19:41:46 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 03 19:41:46 cachedir: .tox/integration/.pytest_cache
Feb 03 19:41:46 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 03 19:41:46 plugins: operator-0.23.0, asyncio-0.20.3
Feb 03 19:41:46 asyncio: mode=auto
Feb 03 19:41:46 collecting ... collected 1 item
Feb 03 19:41:46 
Feb 03 19:41:46 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 03 19:41:46 -------------------------------- live log setup --------------------------------
Feb 03 19:41:46 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-3h84 on cloud localhost
Feb 03 19:41:47 -------------------------------- live log call ---------------------------------
Feb 03 19:41:47 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-3h840
Feb 03 19:41:47 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 03 19:42:02 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 14.63s
Feb 03 19:42:02 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-3h840
Feb 03 19:42:02 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 03 19:42:15 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 13.39s
Feb 03 19:42:20 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 03 19:42:28 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 03 19:42:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:42:28   mysql/0 [allocating] waiting: waiting for machine
Feb 03 19:42:28   mysql/1 [allocating] waiting: waiting for machine
Feb 03 19:42:28   mysql/2 [allocating] waiting: waiting for machine
Feb 03 19:42:28   application/0 [allocating] waiting: waiting for machine
Feb 03 19:42:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:42:59   mysql/0 [allocating] waiting: waiting for machine
Feb 03 19:42:59   mysql/1 [allocating] waiting: waiting for machine
Feb 03 19:42:59   mysql/2 [allocating] waiting: waiting for machine
Feb 03 19:42:59   application/0 [allocating] waiting: waiting for machine
Feb 03 19:43:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:43:29   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 19:43:29   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 19:43:29   mysql/2 [allocating] waiting: agent initializing
Feb 03 19:43:29   application/0 [allocating] waiting: waiting for machine
Feb 03 19:43:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:43:59   mysql/0 [executing] maintenance: Installing MySQL
Feb 03 19:43:59   mysql/1 [executing] maintenance: Installing MySQL
Feb 03 19:43:59   mysql/2 [executing] maintenance: Installing MySQL
Feb 03 19:43:59   application/0 [idle] waiting: 
Feb 03 19:44:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:44:29   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 19:44:29   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 03 19:44:29   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 03 19:44:29   application/0 [idle] active: 
Feb 03 19:44:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:44:59   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 03 19:44:59   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 03 19:44:59   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:44:59   application/0 [idle] active: 
Feb 03 19:45:22 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 03 19:45:22 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 19:45:22 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:45:32 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:45:34 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 03 19:45:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:45:46   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:45:46   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 03 19:46:04 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:46:06 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 03 19:46:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:46:06   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:46:06   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:46:06   mysql/3 [allocating] waiting: waiting for machine
Feb 03 19:46:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:46:36   mysql/3 [allocating] waiting: waiting for machine
Feb 03 19:47:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:47:06   mysql/3 [executing] maintenance: Installing MySQL
Feb 03 19:47:36 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:47:36   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 03 19:47:36   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 03 19:47:36   mysql/3 [executing] waiting: Waiting to start MySQL
Feb 03 19:48:06 INFO     juju.model:model.py:2530 Waiting for model:
Feb 03 19:48:06   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 03 19:48:06   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 03 19:48:06   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 03 19:48:34 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 03 19:48:35 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 03 19:48:35 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:48:44 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:48:50 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 03 19:48:53 PASSED
Feb 03 19:48:53 ------------------------------ live log teardown -------------------------------
Feb 03 19:48:53 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 03 19:48:53 
Feb 03 19:48:53 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 03 19:48:53 test-replication-3h84  lxd         localhost/localhost  2.9.29   unsupported  19:48:53Z
Feb 03 19:48:53 
Feb 03 19:48:53 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 03 19:48:53 application                   active      1  application             0  no       
Feb 03 19:48:53 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 03 19:48:53 
Feb 03 19:48:53 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 03 19:48:53 application/0*  active    idle   3        10.19.212.247          
Feb 03 19:48:53 mysql/1         active    idle   1        10.19.212.198          Unit is ready: Mode: RW
Feb 03 19:48:53 mysql/2*        active    idle   2        10.19.212.57           Unit is ready: Mode: RO
Feb 03 19:48:53 mysql/3         active    idle   4        10.19.212.29           Unit is ready: Mode: RO
Feb 03 19:48:53 
Feb 03 19:48:53 Machine  State    Address        Inst id        Series  AZ  Message
Feb 03 19:48:53 1        started  10.19.212.198  juju-845b8b-1  jammy       Running
Feb 03 19:48:53 2        started  10.19.212.57   juju-845b8b-2  jammy       Running
Feb 03 19:48:53 3        started  10.19.212.247  juju-845b8b-3  focal       Running
Feb 03 19:48:53 4        started  10.19.212.29   juju-845b8b-4  jammy       Running
Feb 03 19:48:53 
Feb 03 19:48:53 
Feb 03 19:48:53 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 03 19:48:53 
Feb 03 19:48:53 machine-0: 19:43:15 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:48:53 unit-mysql-0: 19:43:15 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:48:53 machine-1: 19:43:20 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:48:53 unit-mysql-1: 19:43:20 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:48:53 machine-2: 19:43:24 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:48:53 unit-mysql-2: 19:43:25 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:48:53 machine-3: 19:43:30 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:48:53 unit-application-0: 19:43:30 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:48:53 machine-4: 19:46:50 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 03 19:48:53 unit-mysql-3: 19:46:50 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 03 19:48:53 
Feb 03 19:48:53 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-3h84...
Feb 03 19:48:53 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 03 19:48:53 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 03 19:48:53 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 03 19:48:54 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 03 19:48:54 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 03 19:48:55 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 03 19:48:56 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 03 19:48:57 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 03 19:48:58 
Feb 03 19:48:58 
Feb 03 19:48:58 ======================== 1 passed in 431.97s (0:07:11) =========================
Feb 03 19:48:58   integration: OK (432.77=setup[0.03]+cmd[432.73] seconds)
Feb 03 19:48:58   congratulations :) (432.80 seconds)

@carlcsaposs-canonical
Copy link
Contributor Author

carlcsaposs-canonical commented Feb 7, 2023

Summary

Test run time of tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection

GitHub Actions 2vCPUs, 7GB RAM Google Cloud 4vCPUs, 16GB RAM Google Cloud 16vCPUs, 64GB RAM
Without optimizations 15 minutes 39 seconds 15 minutes 25 seconds 8 minutes 31 seconds
With minor optimizations 14 minutes 51 seconds 14 minutes 48 seconds 7 minutes 13 seconds

@carlcsaposs-canonical
Copy link
Contributor Author

CPU info:

Note that this was collected separately from the tests; if the CPU changed between VMs of the same class that is not captured below.

GitHub Actions
$ cat /proc/cpuinfo
processor	: 0
vendor_id	: GenuineIntel
cpu family	: 6
model		: 79
model name	: Intel(R) Xeon(R) CPU E5-2673 v4 @ 2.30GHz
stepping	: 1
microcode	: 0xffffffff
cpu MHz		: 2294.685
cache size	: 51200 KB
physical id	: 0
siblings	: 2
core id		: 0
cpu cores	: 2
apicid		: 0
initial apicid	: 0
fpu		: yes
fpu_exception	: yes
cpuid level	: 20
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology cpuid pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single pti fsgsbase bmi1 hle avx2 smep bmi2 erms invpcid rtm rdseed adx smap xsaveopt md_clear
bugs		: cpu_meltdown spectre_v1 spectre_v2 spec_store_bypass l1tf mds swapgs taa itlb_multihit mmio_stale_data
bogomips	: 4589.37
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:
processor	: 1
vendor_id	: GenuineIntel
cpu family	: 6
model		: 79
model name	: Intel(R) Xeon(R) CPU E5-2673 v4 @ 2.30GHz
stepping	: 1
microcode	: 0xffffffff
cpu MHz		: 2294.685
cache size	: 51200 KB
physical id	: 0
siblings	: 2
core id		: 1
cpu cores	: 2
apicid		: 1
initial apicid	: 1
fpu		: yes
fpu_exception	: yes
cpuid level	: 20
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology cpuid pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single pti fsgsbase bmi1 hle avx2 smep bmi2 erms invpcid rtm rdseed adx smap xsaveopt md_clear
bugs		: cpu_meltdown spectre_v1 spectre_v2 spec_store_bypass l1tf mds swapgs taa itlb_multihit mmio_stale_data
bogomips	: 4589.37
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:
Google Cloud 4vCPUs (n2-standard-4)
$ cat /proc/cpuinfo
processor	: 0
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.284
cache size	: 33792 KB
physical id	: 0
siblings	: 4
core id		: 0
cpu cores	: 2
apicid		: 0
initial apicid	: 0
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.56
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 1
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.284
cache size	: 33792 KB
physical id	: 0
siblings	: 4
core id		: 1
cpu cores	: 2
apicid		: 2
initial apicid	: 2
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.56
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 2
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.284
cache size	: 33792 KB
physical id	: 0
siblings	: 4
core id		: 0
cpu cores	: 2
apicid		: 1
initial apicid	: 1
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.56
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 3
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.284
cache size	: 33792 KB
physical id	: 0
siblings	: 4
core id		: 1
cpu cores	: 2
apicid		: 3
initial apicid	: 3
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.56
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:
Google Cloud 16vCPUs (n2-standard-16)
$ cat /proc/cpuinfo 
processor	: 0
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 0
cpu cores	: 8
apicid		: 0
initial apicid	: 0
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 1
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 1
cpu cores	: 8
apicid		: 2
initial apicid	: 2
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 2
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 2
cpu cores	: 8
apicid		: 4
initial apicid	: 4
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 3
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 3
cpu cores	: 8
apicid		: 6
initial apicid	: 6
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 4
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 4
cpu cores	: 8
apicid		: 8
initial apicid	: 8
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 5
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 5
cpu cores	: 8
apicid		: 10
initial apicid	: 10
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 6
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 6
cpu cores	: 8
apicid		: 12
initial apicid	: 12
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 7
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 7
cpu cores	: 8
apicid		: 14
initial apicid	: 14
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 8
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 0
cpu cores	: 8
apicid		: 1
initial apicid	: 1
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 9
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 1
cpu cores	: 8
apicid		: 3
initial apicid	: 3
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 10
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 2
cpu cores	: 8
apicid		: 5
initial apicid	: 5
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 11
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 3
cpu cores	: 8
apicid		: 7
initial apicid	: 7
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 12
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 4
cpu cores	: 8
apicid		: 9
initial apicid	: 9
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 13
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 5
cpu cores	: 8
apicid		: 11
initial apicid	: 11
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 14
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 6
cpu cores	: 8
apicid		: 13
initial apicid	: 13
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

processor	: 15
vendor_id	: GenuineIntel
cpu family	: 6
model		: 85
model name	: Intel(R) Xeon(R) CPU @ 2.80GHz
stepping	: 7
microcode	: 0xffffffff
cpu MHz		: 2800.264
cache size	: 33792 KB
physical id	: 0
siblings	: 16
core id		: 7
cpu cores	: 8
apicid		: 15
initial apicid	: 15
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ss ht syscall nx pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid tsc_known_freq pni pclmulqdq ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand hypervisor lahf_lm abm 3dnowprefetch invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm avx512f avx512dq rdseed adx smap clflushopt clwb avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves arat avx512_vnni md_clear arch_capabilities
bugs		: spectre_v1 spectre_v2 spec_store_bypass mds swapgs taa mmio_stale_data retbleed eibrs_pbrsb
bogomips	: 5600.52
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

@carlcsaposs-canonical
Copy link
Contributor Author

carlcsaposs-canonical commented Feb 8, 2023

Results from single run on Google Cloud n2 VMs on af46d38

2 vCPUs, 8GB RAM 4 vCPUS, 16 GB RAM 4 vCPUs, 32GB RAM 16 vCPUs, 32GB RAM 16 vCPUs, 64GB RAM
35 minutes 28 seconds 14 minutes 25 seconds 13 minutes 28 seconds 8 minutes 11 seconds 9 minutes 2 seconds

@carlcsaposs-canonical
Copy link
Contributor Author

Logs

2 vCPUs, 8GB RAM
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 08 17:50:51 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 08 17:50:52 ============================= test session starts ==============================
Feb 08 17:50:52 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 08 17:50:52 cachedir: .tox/integration/.pytest_cache
Feb 08 17:50:52 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 08 17:50:52 plugins: operator-0.23.0, asyncio-0.20.3
Feb 08 17:50:52 asyncio: mode=auto
Feb 08 17:50:52 collecting ... collected 1 item
Feb 08 17:50:52 
Feb 08 17:50:52 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 08 17:50:52 -------------------------------- live log setup --------------------------------
Feb 08 17:50:52 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-ukn8 on cloud localhost
Feb 08 17:50:55 -------------------------------- live log call ---------------------------------
Feb 08 17:50:55 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-ukn80
Feb 08 17:50:55 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 08 17:51:45 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 49.18s
Feb 08 17:51:45 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-ukn80
Feb 08 17:51:45 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 08 17:52:10 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 25.34s
Feb 08 17:52:16 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 08 17:52:36 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 08 17:52:37 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:37   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:52:37   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:52:37   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:52:37   application/0 [allocating] waiting: waiting for machine
Feb 08 17:53:07 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:07   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:53:07   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:53:07   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:53:07   application/0 [allocating] waiting: waiting for machine
Feb 08 17:53:38 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:38   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:53:38   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:53:38   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:53:38   application/0 [allocating] waiting: waiting for machine
Feb 08 17:54:08 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:08   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:54:08   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:54:08   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:54:08   application/0 [allocating] waiting: waiting for machine
Feb 08 17:54:38 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:38   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:54:38   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:54:38   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:54:38   application/0 [allocating] waiting: waiting for machine
Feb 08 17:55:08 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:08   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:55:08   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:55:08   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:55:08   application/0 [allocating] waiting: waiting for machine
Feb 08 17:55:38 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:38   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:55:38   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:55:38   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:55:38   application/0 [allocating] waiting: waiting for machine
Feb 08 17:56:08 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:08   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:56:08   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:56:08   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:56:08   application/0 [allocating] waiting: waiting for machine
Feb 08 17:56:38 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:38   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:56:38   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:56:38   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:56:38   application/0 [allocating] waiting: waiting for machine
Feb 08 17:57:08 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:57:08   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:57:08   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:57:08   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:57:08   application/0 [allocating] waiting: waiting for machine
Feb 08 17:57:38 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:57:38   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:57:38   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:57:38   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:57:38   application/0 [allocating] waiting: agent initializing
Feb 08 17:58:08 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:58:08   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:58:08   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:58:08   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:58:08   application/0 [executing] maintenance: installing charm software
Feb 08 17:58:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:58:39   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:58:39   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:58:39   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:58:39   application/0 [idle] waiting: 
Feb 08 17:59:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:59:09   mysql/0 [executing] waiting: agent initializing
Feb 08 17:59:09   mysql/1 [allocating] waiting: agent initializing
Feb 08 17:59:09   mysql/2 [allocating] waiting: agent initializing
Feb 08 17:59:09   application/0 [idle] waiting: 
Feb 08 17:59:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:59:39   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:59:39   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:59:39   mysql/2 [executing] maintenance: installing charm software
Feb 08 17:59:39   application/0 [idle] waiting: 
Feb 08 18:00:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:00:09   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 18:00:09   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 18:00:09   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 18:00:09   application/0 [idle] waiting: 
Feb 08 18:00:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:00:39   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 18:00:39   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 18:00:39   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 18:00:39   application/0 [idle] waiting: 
Feb 08 18:01:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:01:09   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 18:01:09   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 18:01:09   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 18:01:09   application/0 [idle] waiting: 
Feb 08 18:01:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:01:39   mysql/0 [executing] waiting: Waiting to start MySQL
Feb 08 18:01:39   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 18:01:39   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 18:01:39   application/0 [idle] waiting: 
Feb 08 18:02:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:02:09   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:02:09   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 08 18:02:09   mysql/2 [executing] maintenance: Setting up cluster node
Feb 08 18:02:09   application/0 [idle] waiting: 
Feb 08 18:02:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:02:39   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:02:39   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 08 18:02:39   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 08 18:02:39   application/0 [idle] active: 
Feb 08 18:03:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:03:10   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:03:10   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 08 18:03:10   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 18:03:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:03:40   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:03:40   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 08 18:03:40   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 18:04:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:04:10   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:04:10   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 18:04:10   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 18:04:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:04:40   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:04:40   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 18:05:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:05:10   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:05:10   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 08 18:05:10   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 08 18:05:10   application/0 [idle] active: 
Feb 08 18:05:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:05:40   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:05:40   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 18:06:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:06:10   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:06:10   application/0 [executing] active: 
Feb 08 18:06:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:06:40   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:06:40   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 18:06:40   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 18:06:40   application/0 [idle] active: 
Feb 08 18:07:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:07:10   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:07:10   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 18:07:10   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 18:07:10   application/0 [idle] active: 
Feb 08 18:07:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:07:40   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 18:07:40   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 18:07:45 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 08 18:07:45 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 18:07:46 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:08:57 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:09:16 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 08 18:10:04 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:10:04   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 18:10:04   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:10:34 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:10:34   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 18:10:43 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:10:56 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 08 18:10:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:10:58   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 18:10:58   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 18:10:58   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:11:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:11:28   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:11:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:11:58   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:12:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:12:28   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:12:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:12:58   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:13:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:13:29   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:13:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:13:59   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:14:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:14:29   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:14:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:14:59   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:15:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:15:29   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:15:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:15:59   mysql/3 [allocating] waiting: waiting for machine
Feb 08 18:16:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:16:29   mysql/3 [allocating] waiting: agent initializing
Feb 08 18:16:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:16:59   mysql/3 [executing] maintenance: installing charm software
Feb 08 18:17:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:17:29   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:17:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:17:59   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:18:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:18:29   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:18:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:18:59   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:19:29 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:19:29   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 18:19:29   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:19:29   mysql/3 [executing] waiting: Waiting to start MySQL
Feb 08 18:19:59 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:19:59   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 18:19:59   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:19:59   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 08 18:20:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:20:30   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 18:20:30   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:20:30   mysql/3 [idle] waiting: Waiting to join the cluster
Feb 08 18:21:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:21:00   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:21:00   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 08 18:21:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:21:30   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 18:21:30   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:22:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:22:00   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:22:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:22:30   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 18:22:30   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 18:22:30   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 08 18:23:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:23:00   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 18:23:02 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 08 18:23:29 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 18:23:30 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:24:51 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:25:42 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:25:53 PASSED
Feb 08 18:25:53 ------------------------------ live log teardown -------------------------------
Feb 08 18:25:53 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 08 18:25:53 
Feb 08 18:25:53 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 08 18:25:53 test-replication-ukn8  lxd         localhost/localhost  2.9.29   unsupported  18:25:53Z
Feb 08 18:25:53 
Feb 08 18:25:53 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 08 18:25:53 application                   active      1  application             0  no       
Feb 08 18:25:53 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 08 18:25:53 
Feb 08 18:25:53 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 08 18:25:53 application/0*  active    idle   3        10.252.56.65           
Feb 08 18:25:53 mysql/1         active    idle   1        10.252.56.117          Unit is ready: Mode: RW
Feb 08 18:25:53 mysql/2*        active    idle   2        10.252.56.27           Unit is ready: Mode: RO
Feb 08 18:25:53 mysql/3         active    idle   4        10.252.56.205          Unit is ready: Mode: RO
Feb 08 18:25:53 
Feb 08 18:25:53 Machine  State    Address        Inst id        Series  AZ  Message
Feb 08 18:25:53 1        started  10.252.56.117  juju-a4135f-1  jammy       Running
Feb 08 18:25:53 2        started  10.252.56.27   juju-a4135f-2  jammy       Running
Feb 08 18:25:53 3        started  10.252.56.65   juju-a4135f-3  focal       Running
Feb 08 18:25:53 4        started  10.252.56.205  juju-a4135f-4  jammy       Running
Feb 08 18:25:53 
Feb 08 18:25:53 
Feb 08 18:25:54 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 08 18:25:54 
Feb 08 18:25:54 machine-3: 17:57:20 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:25:54 unit-application-0: 17:57:21 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:25:54 machine-0: 17:58:40 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:25:54 unit-mysql-0: 17:58:42 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:25:54 machine-1: 17:58:46 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:25:54 unit-mysql-1: 17:58:48 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:25:54 machine-2: 17:58:58 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:25:54 unit-mysql-2: 17:58:58 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:25:54 unit-mysql-1: 18:08:42 ERROR unit.mysql/1.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-1: 18:12:03 ERROR unit.mysql/1.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-2: 18:12:08 ERROR unit.mysql/2.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-1: 18:12:23 ERROR unit.mysql/1.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 machine-4: 18:16:22 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:25:54 unit-mysql-3: 18:16:23 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:25:54 unit-mysql-1: 18:17:52 ERROR unit.mysql/1.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-2: 18:17:56 ERROR unit.mysql/2.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-1: 18:18:36 ERROR unit.mysql/1.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-3: 18:23:39 ERROR unit.mysql/3.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-2: 18:23:43 ERROR unit.mysql/2.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-1: 18:24:53 ERROR unit.mysql/1.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 unit-mysql-3: 18:25:03 ERROR unit.mysql/3.juju-log Failed to get member state: mysqld daemon is down
Feb 08 18:25:54 
Feb 08 18:25:54 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-ukn8...
Feb 08 18:25:54 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 08 18:25:54 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 08 18:25:54 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 08 18:26:09 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 08 18:26:12 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 08 18:26:16 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 08 18:26:18 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 08 18:26:20 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 08 18:26:21 
Feb 08 18:26:21 
Feb 08 18:26:21 ======================== 1 passed in 2128.83s (0:35:28) ========================
Feb 08 18:26:22   integration: OK (2130.68=setup[0.07]+cmd[2130.61] seconds)
Feb 08 18:26:22   congratulations :) (2130.77 seconds)
4 vCPUS, 16 GB RAM
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 08 17:48:36 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 08 17:48:37 ============================= test session starts ==============================
Feb 08 17:48:37 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 08 17:48:37 cachedir: .tox/integration/.pytest_cache
Feb 08 17:48:37 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 08 17:48:37 plugins: operator-0.23.0, asyncio-0.20.3
Feb 08 17:48:37 asyncio: mode=auto
Feb 08 17:48:37 collecting ... collected 1 item
Feb 08 17:48:37 
Feb 08 17:48:37 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 08 17:48:37 -------------------------------- live log setup --------------------------------
Feb 08 17:48:37 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-g8ny on cloud localhost
Feb 08 17:48:41 -------------------------------- live log call ---------------------------------
Feb 08 17:48:41 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-g8ny0
Feb 08 17:48:41 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 08 17:49:16 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 34.57s
Feb 08 17:49:16 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-g8ny0
Feb 08 17:49:16 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 08 17:49:35 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 19.38s
Feb 08 17:49:41 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 08 17:49:52 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 08 17:49:53 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:49:53   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:49:53   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:49:53   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:49:53   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:23 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:23   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:50:23   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:50:23   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:50:23   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:53 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:53   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:50:53   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:50:53   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:50:53   application/0 [allocating] waiting: waiting for machine
Feb 08 17:51:23 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:23   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:51:23   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:51:23   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:51:23   application/0 [allocating] waiting: waiting for machine
Feb 08 17:51:53 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:53   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:51:53   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:51:53   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:51:53   application/0 [allocating] waiting: waiting for machine
Feb 08 17:52:23 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:23   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:52:23   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:52:23   mysql/2 [allocating] waiting: agent initializing
Feb 08 17:52:23   application/0 [idle] waiting: 
Feb 08 17:52:53 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:53   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:52:53   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:52:53   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 17:52:53   application/0 [idle] waiting: 
Feb 08 17:53:24 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:24   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:53:24   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:53:24   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 17:53:24   application/0 [idle] waiting: 
Feb 08 17:53:54 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:54   mysql/0 [executing] maintenance: Setting up cluster node
Feb 08 17:53:54   mysql/1 [executing] maintenance: Setting up cluster node
Feb 08 17:53:54   mysql/2 [executing] maintenance: Setting up cluster node
Feb 08 17:53:54   application/0 [idle] waiting: 
Feb 08 17:54:24 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:24   mysql/0 [idle] waiting: Waiting to join the cluster
Feb 08 17:54:24   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 08 17:54:24   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 08 17:54:24   application/0 [idle] active: 
Feb 08 17:54:54 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:54   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 08 17:54:54   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 08 17:54:54   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 08 17:54:54   application/0 [idle] active: 
Feb 08 17:55:24 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:24   mysql/0 [executing] active: Unit is ready: Mode: RO
Feb 08 17:55:24   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 17:55:24   mysql/2 [executing] active: Unit is ready: Mode: RW
Feb 08 17:55:24   application/0 [idle] active: 
Feb 08 17:55:45 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 08 17:55:45 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 17:55:45 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:07 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:12 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 08 17:56:34 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:34   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 17:56:34   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 17:56:54 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:58 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 08 17:57:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:57:00   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:57:00   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 17:57:00   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:57:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:57:30   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:58:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:58:00   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:58:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:58:30   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:59:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:59:00   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:59:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:59:30   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:00:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:00:00   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:00:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:00:30   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:00:30   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 18:00:30   mysql/3 [executing] maintenance: Setting up cluster node
Feb 08 18:01:00 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:01:00   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:01:00   mysql/3 [idle] waiting: Waiting to join the cluster
Feb 08 18:01:30 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:01:30   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 18:01:30   mysql/1 [executing] active: Unit is ready: Mode: RO
Feb 08 18:01:30   mysql/3 [executing] active: Unit is ready: Mode: RO
Feb 08 18:01:58 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 08 18:02:02 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 18:02:02 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:02:24 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:02:45 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:02:50 PASSED
Feb 08 18:02:50 ------------------------------ live log teardown -------------------------------
Feb 08 18:02:50 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 08 18:02:50 
Feb 08 18:02:50 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 08 18:02:50 test-replication-g8ny  lxd         localhost/localhost  2.9.29   unsupported  18:02:50Z
Feb 08 18:02:50 
Feb 08 18:02:50 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 08 18:02:50 application                   active      1  application             0  no       
Feb 08 18:02:50 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 08 18:02:50 
Feb 08 18:02:50 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 08 18:02:50 application/0*  active    idle   3        10.147.23.74           
Feb 08 18:02:50 mysql/0*        active    idle   0        10.147.23.79           Unit is ready: Mode: RW
Feb 08 18:02:50 mysql/1         active    idle   1        10.147.23.10           Unit is ready: Mode: RO
Feb 08 18:02:50 mysql/3         active    idle   4        10.147.23.240          Unit is ready: Mode: RO
Feb 08 18:02:50 
Feb 08 18:02:50 Machine  State    Address        Inst id        Series  AZ  Message
Feb 08 18:02:50 0        started  10.147.23.79   juju-3e05ac-0  jammy       Running
Feb 08 18:02:50 1        started  10.147.23.10   juju-3e05ac-1  jammy       Running
Feb 08 18:02:50 3        started  10.147.23.74   juju-3e05ac-3  focal       Running
Feb 08 18:02:50 4        started  10.147.23.240  juju-3e05ac-4  jammy       Running
Feb 08 18:02:50 
Feb 08 18:02:50 
Feb 08 18:02:51 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 08 18:02:51 
Feb 08 18:02:51 machine-3: 17:51:53 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:02:51 unit-application-0: 17:51:53 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:02:51 machine-2: 17:52:22 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:02:51 unit-mysql-2: 17:52:23 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:02:51 machine-0: 17:52:31 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:02:51 unit-mysql-0: 17:52:31 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:02:51 machine-1: 17:52:33 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:02:51 unit-mysql-1: 17:52:34 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:02:51 machine-4: 17:59:08 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:02:51 unit-mysql-3: 17:59:09 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:02:51 
Feb 08 18:02:51 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-g8ny...
Feb 08 18:02:51 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 08 18:02:51 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 08 18:02:51 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 08 18:02:56 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 08 18:02:58 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 08 18:02:59 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 08 18:03:01 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 08 18:03:02 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 08 18:03:03 
Feb 08 18:03:03 
Feb 08 18:03:03 ======================== 1 passed in 865.75s (0:14:25) =========================
Feb 08 18:03:03   integration: OK (867.15=setup[0.08]+cmd[867.07] seconds)
Feb 08 18:03:03   congratulations :) (867.28 seconds)
4 vCPUs, 32GB RAM
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 08 17:48:32 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 08 17:48:33 ============================= test session starts ==============================
Feb 08 17:48:33 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 08 17:48:33 cachedir: .tox/integration/.pytest_cache
Feb 08 17:48:33 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 08 17:48:33 plugins: operator-0.23.0, asyncio-0.20.3
Feb 08 17:48:33 asyncio: mode=auto
Feb 08 17:48:33 collecting ... collected 1 item
Feb 08 17:48:33 
Feb 08 17:48:33 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 08 17:48:33 -------------------------------- live log setup --------------------------------
Feb 08 17:48:33 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-k4qj on cloud localhost
Feb 08 17:48:36 -------------------------------- live log call ---------------------------------
Feb 08 17:48:36 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-k4qj0
Feb 08 17:48:36 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 08 17:49:11 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 35.31s
Feb 08 17:49:11 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-k4qj0
Feb 08 17:49:11 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 08 17:49:29 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 17.65s
Feb 08 17:49:34 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 08 17:49:45 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 08 17:49:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:49:46   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:49:46   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:49:46   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:49:46   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:16   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:50:16   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:50:16   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:50:16   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:46   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:50:46   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:50:46   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:50:46   application/0 [allocating] waiting: waiting for machine
Feb 08 17:51:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:16   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:51:16   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:51:16   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:51:16   application/0 [allocating] waiting: waiting for machine
Feb 08 17:51:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:46   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:51:46   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:51:46   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:51:46   application/0 [allocating] waiting: agent initializing
Feb 08 17:52:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:16   mysql/0 [allocating] waiting: agent initializing
Feb 08 17:52:16   mysql/1 [allocating] waiting: installing agent
Feb 08 17:52:16   mysql/2 [allocating] waiting: agent initializing
Feb 08 17:52:16   application/0 [idle] waiting: 
Feb 08 17:52:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:46   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:52:46   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:52:46   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 17:52:46   application/0 [idle] waiting: 
Feb 08 17:53:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:16   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:53:16   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:53:16   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 17:53:16   application/0 [idle] waiting: 
Feb 08 17:53:46 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:46   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 17:53:46   mysql/1 [executing] waiting: Waiting to join the cluster
Feb 08 17:53:46   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 08 17:53:46   application/0 [idle] waiting: 
Feb 08 17:54:16 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:16   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 17:54:16   mysql/1 [idle] waiting: Waiting to join the cluster
Feb 08 17:54:16   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 17:54:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:47   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 17:54:47   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 17:55:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:17   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:55:17   mysql/1 [idle] active: Unit is ready: Mode: RO
Feb 08 17:55:17   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:55:28 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 08 17:55:28 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 17:55:28 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:55:47 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:55:56 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 08 17:56:15 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:15   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 17:56:15   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 17:56:34 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:38 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 08 17:56:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:39   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 17:56:39   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:56:39   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:57:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:57:09   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:57:39 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:57:39   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:58:09 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:58:09   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:58:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:58:40   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:59:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:59:10   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 17:59:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:59:40   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 18:00:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:00:10   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 18:00:10   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:00:10   mysql/3 [executing] maintenance: Setting up cluster node
Feb 08 18:00:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 18:00:40   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 18:00:40   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 08 18:01:06 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 08 18:01:10 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 18:01:10 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:01:31 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:01:46 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 18:01:50 PASSED
Feb 08 18:01:50 ------------------------------ live log teardown -------------------------------
Feb 08 18:01:50 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 08 18:01:50 
Feb 08 18:01:50 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 08 18:01:50 test-replication-k4qj  lxd         localhost/localhost  2.9.29   unsupported  18:01:50Z
Feb 08 18:01:50 
Feb 08 18:01:50 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 08 18:01:50 application                   active      1  application             0  no       
Feb 08 18:01:50 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 08 18:01:50 
Feb 08 18:01:50 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 08 18:01:50 application/0*  active    idle   3        10.23.75.120           
Feb 08 18:01:50 mysql/1         active    idle   1        10.23.75.165           Unit is ready: Mode: RW
Feb 08 18:01:50 mysql/2*        active    idle   2        10.23.75.5             Unit is ready: Mode: RO
Feb 08 18:01:50 mysql/3         active    idle   4        10.23.75.203           Unit is ready: Mode: RO
Feb 08 18:01:50 
Feb 08 18:01:50 Machine  State    Address       Inst id        Series  AZ  Message
Feb 08 18:01:50 1        started  10.23.75.165  juju-3ff915-1  jammy       Running
Feb 08 18:01:50 2        started  10.23.75.5    juju-3ff915-2  jammy       Running
Feb 08 18:01:50 3        started  10.23.75.120  juju-3ff915-3  focal       Running
Feb 08 18:01:50 4        started  10.23.75.203  juju-3ff915-4  jammy       Running
Feb 08 18:01:50 
Feb 08 18:01:50 
Feb 08 18:01:50 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 08 18:01:50 
Feb 08 18:01:50 machine-3: 17:51:37 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:01:50 unit-application-0: 17:51:38 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:01:50 machine-0: 17:52:12 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:01:50 unit-mysql-0: 17:52:12 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:01:50 unit-mysql-2: 17:52:14 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:01:50 machine-2: 17:52:14 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:01:50 machine-1: 17:52:16 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:01:50 unit-mysql-1: 17:52:16 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:01:50 machine-4: 17:58:42 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 18:01:50 unit-mysql-3: 17:58:42 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 18:01:50 
Feb 08 18:01:50 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-k4qj...
Feb 08 18:01:50 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 08 18:01:51 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 08 18:01:51 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 1
Feb 08 18:01:56 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 08 18:01:57 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 08 18:01:58 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 08 18:02:00 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 08 18:02:01 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 08 18:02:02 
Feb 08 18:02:02 
Feb 08 18:02:02 ======================== 1 passed in 808.75s (0:13:28) =========================
Feb 08 18:02:02   integration: OK (809.88=setup[0.05]+cmd[809.83] seconds)
Feb 08 18:02:02   congratulations :) (809.93 seconds)
16 vCPUs, 32GB RAM
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 08 17:48:27 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 08 17:48:27 ============================= test session starts ==============================
Feb 08 17:48:27 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 08 17:48:27 cachedir: .tox/integration/.pytest_cache
Feb 08 17:48:27 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 08 17:48:27 plugins: operator-0.23.0, asyncio-0.20.3
Feb 08 17:48:27 asyncio: mode=auto
Feb 08 17:48:27 collecting ... collected 1 item
Feb 08 17:48:27 
Feb 08 17:48:27 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 08 17:48:27 -------------------------------- live log setup --------------------------------
Feb 08 17:48:27 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-f47a on cloud localhost
Feb 08 17:48:28 -------------------------------- live log call ---------------------------------
Feb 08 17:48:28 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-f47a0
Feb 08 17:48:28 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 08 17:49:02 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 33.38s
Feb 08 17:49:02 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-f47a0
Feb 08 17:49:02 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 08 17:49:17 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 15.74s
Feb 08 17:49:23 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 08 17:49:31 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 08 17:49:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:49:32   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:49:32   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:49:32   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:49:32   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:02   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:50:02   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:50:02   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:50:02   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:32   mysql/0 [allocating] waiting: agent initializing
Feb 08 17:50:32   mysql/1 [executing] waiting: agent initializing
Feb 08 17:50:32   mysql/2 [allocating] waiting: agent initializing
Feb 08 17:50:32   application/0 [idle] waiting: 
Feb 08 17:51:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:02   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:51:02   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:51:02   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 17:51:02   application/0 [idle] waiting: 
Feb 08 17:51:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:32   mysql/0 [executing] waiting: Waiting to join the cluster
Feb 08 17:51:32   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 17:51:32   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 08 17:51:32   application/0 [idle] active: 
Feb 08 17:52:02 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:02   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 08 17:52:02   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 17:52:02   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 17:52:02   application/0 [idle] active: 
Feb 08 17:52:32 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:32   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 08 17:52:32   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 17:52:40 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 08 17:52:40 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 17:52:40 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:52:50 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:52:52 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 08 17:53:05 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:05   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:53:05   mysql/2 [executing] active: Unit is ready: Mode: RO
Feb 08 17:53:23 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:53:27 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 08 17:53:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:27   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:53:27   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:53:27   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:53:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:57   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:54:27 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:27   mysql/3 [allocating] waiting: agent initializing
Feb 08 17:54:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:57   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 17:55:28 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:28   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:55:28   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:55:28   mysql/3 [executing] waiting: Waiting to join the cluster
Feb 08 17:55:58 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:58   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:55:58   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:55:58   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 08 17:56:11 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 08 17:56:14 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 17:56:14 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:24 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:30 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:56:33 PASSED
Feb 08 17:56:33 ------------------------------ live log teardown -------------------------------
Feb 08 17:56:33 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 08 17:56:33 
Feb 08 17:56:33 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 08 17:56:33 test-replication-f47a  lxd         localhost/localhost  2.9.29   unsupported  17:56:33Z
Feb 08 17:56:33 
Feb 08 17:56:33 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 08 17:56:33 application                   active      1  application             0  no       
Feb 08 17:56:33 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 08 17:56:33 
Feb 08 17:56:33 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 08 17:56:33 application/0*  active    idle   3        10.146.110.40          
Feb 08 17:56:33 mysql/0         active    idle   0        10.146.110.131         Unit is ready: Mode: RW
Feb 08 17:56:33 mysql/2*        active    idle   2        10.146.110.144         Unit is ready: Mode: RO
Feb 08 17:56:33 mysql/3         active    idle   4        10.146.110.185         Unit is ready: Mode: RO
Feb 08 17:56:33 
Feb 08 17:56:33 Machine  State    Address         Inst id        Series  AZ  Message
Feb 08 17:56:33 0        started  10.146.110.131  juju-9bb8f3-0  jammy       Running
Feb 08 17:56:33 2        started  10.146.110.144  juju-9bb8f3-2  jammy       Running
Feb 08 17:56:33 3        started  10.146.110.40   juju-9bb8f3-3  focal       Running
Feb 08 17:56:33 4        started  10.146.110.185  juju-9bb8f3-4  jammy       Running
Feb 08 17:56:33 
Feb 08 17:56:33 
Feb 08 17:56:33 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 08 17:56:33 
Feb 08 17:56:33 machine-3: 17:50:16 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:56:33 unit-application-0: 17:50:16 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:56:33 machine-1: 17:50:26 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:56:33 unit-mysql-1: 17:50:26 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:56:33 machine-0: 17:50:27 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:56:33 unit-mysql-0: 17:50:27 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:56:33 machine-2: 17:50:29 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:56:33 unit-mysql-2: 17:50:30 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:56:33 machine-4: 17:54:22 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:56:33 unit-mysql-3: 17:54:22 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:56:33 
Feb 08 17:56:33 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-f47a...
Feb 08 17:56:33 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 08 17:56:33 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 08 17:56:33 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 08 17:56:34 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 08 17:56:35 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 08 17:56:36 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 08 17:56:36 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 08 17:56:37 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 08 17:56:38 
Feb 08 17:56:38 
Feb 08 17:56:38 ======================== 1 passed in 491.01s (0:08:11) =========================
Feb 08 17:56:39   integration: OK (492.11=setup[0.04]+cmd[492.06] seconds)
Feb 08 17:56:39   congratulations :) (492.15 seconds)
16 vCPUs, 64GB RAM
$ tox run -e integration -- pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection | ts
Feb 08 17:48:23 integration: commands[0]> pytest -v --tb native --log-cli-level=INFO -s tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection
Feb 08 17:48:24 ============================= test session starts ==============================
Feb 08 17:48:24 platform linux -- Python 3.10.6, pytest-7.2.1, pluggy-1.0.0 -- /home/ubuntu/repos/mysql-operator/.tox/integration/bin/python
Feb 08 17:48:24 cachedir: .tox/integration/.pytest_cache
Feb 08 17:48:24 rootdir: /home/ubuntu/repos/mysql-operator, configfile: pyproject.toml
Feb 08 17:48:24 plugins: operator-0.23.0, asyncio-0.20.3
Feb 08 17:48:24 asyncio: mode=auto
Feb 08 17:48:24 collecting ... collected 1 item
Feb 08 17:48:24 
Feb 08 17:48:24 tests/integration/high_availability/test_replication.py::test_kill_primary_check_reelection 
Feb 08 17:48:24 -------------------------------- live log setup --------------------------------
Feb 08 17:48:24 INFO     pytest_operator.plugin:plugin.py:618 Adding model lxd:test-replication-d6sk on cloud localhost
Feb 08 17:48:24 -------------------------------- live log call ---------------------------------
Feb 08 17:48:24 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-d6sk0
Feb 08 17:48:24 INFO     pytest_operator.plugin:plugin.py:941 Building charm mysql
Feb 08 17:48:57 INFO     pytest_operator.plugin:plugin.py:946 Built charm mysql in 33.03s
Feb 08 17:48:57 INFO     pytest_operator.plugin:plugin.py:497 Using tmp_path: /home/ubuntu/repos/mysql-operator/.tox/integration/tmp/pytest/test-replication-d6sk0
Feb 08 17:48:57 INFO     pytest_operator.plugin:plugin.py:941 Building charm application
Feb 08 17:49:25 INFO     pytest_operator.plugin:plugin.py:946 Built charm application in 27.94s
Feb 08 17:49:30 INFO     juju.model:model.py:1928 Deploying local:jammy/mysql-0
Feb 08 17:49:39 INFO     juju.model:model.py:1928 Deploying local:focal/application-0
Feb 08 17:49:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:49:40   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:49:40   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:49:40   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:49:40   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:10   mysql/0 [allocating] waiting: waiting for machine
Feb 08 17:50:10   mysql/1 [allocating] waiting: waiting for machine
Feb 08 17:50:10   mysql/2 [allocating] waiting: waiting for machine
Feb 08 17:50:10   application/0 [allocating] waiting: waiting for machine
Feb 08 17:50:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:50:40   mysql/0 [allocating] waiting: agent initializing
Feb 08 17:50:40   mysql/1 [allocating] waiting: agent initializing
Feb 08 17:50:40   mysql/2 [allocating] waiting: agent initializing
Feb 08 17:50:40   application/0 [idle] waiting: 
Feb 08 17:51:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:10   mysql/0 [executing] maintenance: Installing MySQL
Feb 08 17:51:10   mysql/1 [executing] maintenance: Installing MySQL
Feb 08 17:51:10   mysql/2 [executing] maintenance: Installing MySQL
Feb 08 17:51:10   application/0 [idle] waiting: 
Feb 08 17:51:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:51:40   mysql/0 [executing] waiting: Waiting to join the cluster
Feb 08 17:51:40   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 17:51:40   mysql/2 [executing] waiting: Waiting to join the cluster
Feb 08 17:51:40   application/0 [idle] waiting: 
Feb 08 17:52:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:10   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 08 17:52:10   mysql/1 [executing] active: Unit is ready: Mode: RW
Feb 08 17:52:10   mysql/2 [idle] waiting: Waiting to join the cluster
Feb 08 17:52:10   application/0 [idle] waiting: 
Feb 08 17:52:40 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:52:40   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 08 17:52:40   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 17:52:40   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:52:40   application/0 [idle] active: 
Feb 08 17:53:10 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:10   mysql/0 [idle] active: Unit is ready: Mode: RO
Feb 08 17:53:10   mysql/1 [idle] active: Unit is ready: Mode: RW
Feb 08 17:53:10   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:53:10   application/0 [idle] active: 
Feb 08 17:53:31 ERROR    integration.high_availability.test_replication:test_replication.py:97 SETUP COMPLETE
Feb 08 17:53:31 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 17:53:31 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:53:41 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:53:44 INFO     integration.high_availability.test_replication:test_replication.py:106 Destroying leader unit
Feb 08 17:53:57 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:53:57   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 17:53:57   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:54:15 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:54:17 INFO     integration.high_availability.test_replication:test_replication.py:125 Scaling back to 3 units
Feb 08 17:54:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:17   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:54:17   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:54:17   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:54:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:54:47   mysql/3 [allocating] waiting: waiting for machine
Feb 08 17:55:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:17   mysql/3 [executing] waiting: agent initializing
Feb 08 17:55:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:55:47   mysql/3 [executing] maintenance: Installing MySQL
Feb 08 17:56:17 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:17   mysql/0 [executing] active: Unit is ready: Mode: RW
Feb 08 17:56:17   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:56:17   mysql/3 [idle] waiting: Waiting to join the cluster
Feb 08 17:56:47 INFO     juju.model:model.py:2530 Waiting for model:
Feb 08 17:56:47   mysql/0 [idle] active: Unit is ready: Mode: RW
Feb 08 17:56:47   mysql/2 [idle] active: Unit is ready: Mode: RO
Feb 08 17:56:47   mysql/3 [idle] active: Unit is ready: Mode: RO
Feb 08 17:56:58 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:92 Ensure 3 units are online
Feb 08 17:57:00 INFO     integration.high_availability.high_availability_helpers:high_availability_helpers.py:371 Ensure continuous writes are incrementing
Feb 08 17:57:00 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:57:12 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:57:18 INFO     integration.helpers:helpers.py:552 Retrieving primary unit
Feb 08 17:57:21 PASSED
Feb 08 17:57:21 ------------------------------ live log teardown -------------------------------
Feb 08 17:57:21 INFO     pytest_operator.plugin:plugin.py:761 Model status:
Feb 08 17:57:21 
Feb 08 17:57:21 Model                  Controller  Cloud/Region         Version  SLA          Timestamp
Feb 08 17:57:21 test-replication-d6sk  lxd         localhost/localhost  2.9.29   unsupported  17:57:21Z
Feb 08 17:57:21 
Feb 08 17:57:21 App          Version          Status  Scale  Charm        Channel  Rev  Exposed  Message
Feb 08 17:57:21 application                   active      1  application             0  no       
Feb 08 17:57:21 mysql        8.0.32-0ubun...  active      3  mysql                   0  no       
Feb 08 17:57:21 
Feb 08 17:57:21 Unit            Workload  Agent  Machine  Public address  Ports  Message
Feb 08 17:57:21 application/0*  active    idle   3        10.67.169.229          
Feb 08 17:57:21 mysql/0*        active    idle   0        10.67.169.34           Unit is ready: Mode: RW
Feb 08 17:57:21 mysql/2         active    idle   2        10.67.169.203          Unit is ready: Mode: RO
Feb 08 17:57:21 mysql/3         active    idle   4        10.67.169.35           Unit is ready: Mode: RO
Feb 08 17:57:21 
Feb 08 17:57:21 Machine  State    Address        Inst id        Series  AZ  Message
Feb 08 17:57:21 0        started  10.67.169.34   juju-ab924c-0  jammy       Running
Feb 08 17:57:21 2        started  10.67.169.203  juju-ab924c-2  jammy       Running
Feb 08 17:57:21 3        started  10.67.169.229  juju-ab924c-3  focal       Running
Feb 08 17:57:21 4        started  10.67.169.35   juju-ab924c-4  jammy       Running
Feb 08 17:57:21 
Feb 08 17:57:21 
Feb 08 17:57:21 INFO     pytest_operator.plugin:plugin.py:767 Juju error logs:
Feb 08 17:57:21 
Feb 08 17:57:21 machine-3: 17:50:22 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:57:21 unit-application-0: 17:50:23 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:57:21 machine-1: 17:50:35 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:57:21 unit-mysql-1: 17:50:35 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:57:21 machine-0: 17:50:37 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:57:21 unit-mysql-0: 17:50:37 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:57:21 machine-2: 17:50:39 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:57:21 unit-mysql-2: 17:50:39 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:57:21 machine-4: 17:55:11 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
Feb 08 17:57:21 unit-mysql-3: 17:55:11 ERROR juju.worker.meterstatus error running "meter-status-changed": charm missing from disk
Feb 08 17:57:21 
Feb 08 17:57:21 INFO     pytest_operator.plugin:plugin.py:854 Resetting model test-replication-d6sk...
Feb 08 17:57:21 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications mysql
Feb 08 17:57:21 INFO     pytest_operator.plugin:plugin.py:843    Destroying applications application
Feb 08 17:57:21 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 0
Feb 08 17:57:22 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 2
Feb 08 17:57:23 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 3
Feb 08 17:57:23 INFO     pytest_operator.plugin:plugin.py:843    Destroying machines 4
Feb 08 17:57:24 INFO     pytest_operator.plugin:plugin.py:859 Not waiting on reset to complete.
Feb 08 17:57:25 INFO     pytest_operator.plugin:plugin.py:832 Forgetting main...
Feb 08 17:57:26 
Feb 08 17:57:26 
Feb 08 17:57:26 ======================== 1 passed in 542.56s (0:09:02) =========================
Feb 08 17:57:26   integration: OK (543.58=setup[0.06]+cmd[543.52] seconds)
Feb 08 17:57:26   congratulations :) (543.63 seconds)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant