From 335674c310f87a6343de189b2dd6c1d1c8ef98cb Mon Sep 17 00:00:00 2001 From: shayancanonical <99665202+shayancanonical@users.noreply.github.com> Date: Wed, 4 Sep 2024 08:08:45 -0400 Subject: [PATCH] Attempt to stabilize failing integration tests (#496) * Attempt to stabilize failing integration tests * Run format * Address PR feedback + move log rotation test to separate file --- tests/integration/helpers.py | 35 ++++- .../high_availability/test_log_rotation.py | 127 ++++++++++++++++++ tests/integration/juju_.py | 2 +- tests/integration/test_charm.py | 100 -------------- 4 files changed, 156 insertions(+), 108 deletions(-) create mode 100644 tests/integration/high_availability/test_log_rotation.py diff --git a/tests/integration/helpers.py b/tests/integration/helpers.py index 432f5641d..056616056 100644 --- a/tests/integration/helpers.py +++ b/tests/integration/helpers.py @@ -347,7 +347,7 @@ def is_connection_possible(credentials: Dict, **extra_opts) -> bool: async def get_process_pid( - ops_test: OpsTest, unit_name: str, container_name: str, process: str + ops_test: OpsTest, unit_name: str, container_name: str, process: str, full_match: bool = False ) -> Optional[int]: """Return the pid of a process running in a given unit. @@ -356,6 +356,7 @@ async def get_process_pid( unit_name: The name of the unit container_name: The name of the container in the unit process: The process name to search for + full_match: Whether to fully match the process name Returns: A integer for the process id @@ -366,7 +367,7 @@ async def get_process_pid( container_name, unit_name, "pgrep", - "-x", + "-f" if full_match else "-x", process, ] return_code, pid, _ = await ops_test.juju(*get_pid_commands) @@ -621,8 +622,12 @@ async def read_contents_from_file_in_unit( return contents -async def ls_la_in_unit( - ops_test: OpsTest, unit_name: str, directory: str, container_name: str = CONTAINER_NAME +async def ls_in_unit( + ops_test: OpsTest, + unit_name: str, + directory: str, + container_name: str = CONTAINER_NAME, + exclude_files: list[str] = [], ) -> list[str]: """Returns the output of ls -la in unit. @@ -631,21 +636,22 @@ async def ls_la_in_unit( unit_name: The name of unit in which to run ls -la directory: The directory from which to run ls -la container_name: The container where to run ls -la + exclude_files: Files to exclude from the output of ls -la Returns: a list of files returned by ls -la """ return_code, output, _ = await ops_test.juju( - "ssh", "--container", container_name, unit_name, "ls", "-la", directory + "ssh", "--container", container_name, unit_name, "ls", "-1", directory ) assert return_code == 0 - ls_output = output.split("\n")[1:] + ls_output = output.split("\n") return [ line.strip("\r") for line in ls_output - if len(line.strip()) > 0 and line.split()[-1] not in [".", ".."] + if len(line.strip()) > 0 and line.strip() not in exclude_files ] @@ -666,6 +672,21 @@ async def stop_running_log_rotate_dispatcher(ops_test: OpsTest, unit_name: str): "/usr/bin/python3 scripts/log_rotate_dispatcher.py", ) + # hold execution until process is stopped + try: + for attempt in Retrying(stop=stop_after_attempt(45), wait=wait_fixed(2)): + with attempt: + if await get_process_pid( + ops_test, + unit_name, + "charm", + "/usr/bin/python3 scripts/log_rotate_dispatcher.py", + full_match=True, + ): + raise Exception + except RetryError: + raise Exception("Failed to stop the log_rotate_dispatcher process") + async def stop_running_flush_mysql_job( ops_test: OpsTest, unit_name: str, container_name: str = CONTAINER_NAME diff --git a/tests/integration/high_availability/test_log_rotation.py b/tests/integration/high_availability/test_log_rotation.py new file mode 100644 index 000000000..67bfdc2b0 --- /dev/null +++ b/tests/integration/high_availability/test_log_rotation.py @@ -0,0 +1,127 @@ +#!/usr/bin/env python3 +# Copyright 2024 Canonical Ltd. +# See LICENSE file for licensing details. + +import logging +from pathlib import Path + +import pytest +import yaml +from pytest_operator.plugin import OpsTest + +from ..helpers import ( + delete_file_or_directory_in_unit, + dispatch_custom_event_for_logrotate, + ls_in_unit, + read_contents_from_file_in_unit, + stop_running_flush_mysql_job, + stop_running_log_rotate_dispatcher, + write_content_to_file_in_unit, +) + +logger = logging.getLogger(__name__) + +METADATA = yaml.safe_load(Path("./metadata.yaml").read_text()) +APP_NAME = METADATA["name"] + + +@pytest.mark.group(1) +@pytest.mark.abort_on_fail +async def test_log_rotation( + ops_test: OpsTest, highly_available_cluster, continuous_writes +) -> None: + """Test the log rotation of text files. + + Run continuous writes to ensure that audit log plugin is loaded and active + when mysql-test-app runs start-continuous-writes (by logging into mysql). + """ + unit = ops_test.model.applications[APP_NAME].units[0] + + logger.info("Extending update-status-hook-interval to 60m") + await ops_test.model.set_config({"update-status-hook-interval": "60m"}) + + # Exclude slowquery log files as slowquery logs are not enabled by default + log_types = ["error", "general", "audit"] + log_files = ["error.log", "general.log", "audit.log"] + archive_directories = [ + "archive_error", + "archive_general", + "archive_slowquery", + "archive_audit", + ] + + logger.info("Overwriting the log rotate dispatcher script") + unit_label = unit.name.replace("/", "-") + await write_content_to_file_in_unit( + ops_test, + unit, + f"/var/lib/juju/agents/unit-{unit_label}/charm/scripts/log_rotate_dispatcher.py", + "exit(0)\n", + container_name="charm", + ) + + logger.info("Stopping the log rotate dispatcher") + await stop_running_log_rotate_dispatcher(ops_test, unit.name) + + logger.info("Stopping any running logrotate jobs") + await stop_running_flush_mysql_job(ops_test, unit.name) + + logger.info("Removing existing archive directories") + for archive_directory in archive_directories: + await delete_file_or_directory_in_unit( + ops_test, + unit.name, + f"/var/log/mysql/{archive_directory}/", + ) + + logger.info("Writing some data to the text log files") + for log in log_types: + log_path = f"/var/log/mysql/{log}.log" + await write_content_to_file_in_unit(ops_test, unit, log_path, f"test {log} content\n") + + logger.info("Ensuring only log files exist") + # Exclude archive directories, as handling any event would restart the + # log_rotate_dispatcher (by the log_rotate_manager) + ls_output = await ls_in_unit( + ops_test, unit.name, "/var/log/mysql/", exclude_files=archive_directories + ) + + for file in log_files: + # audit.log can be rotated and new file not created until access to db + assert ( + file in ls_output or file == "audit.log" + ), f"❌ files other than log files exist {ls_output}" + + logger.info("Dispatching custom event to rotate logs") + await dispatch_custom_event_for_logrotate(ops_test, unit.name) + + logger.info("Ensuring log files and archive directories exist") + ls_output = await ls_in_unit(ops_test, unit.name, "/var/log/mysql/") + + for file in log_files + archive_directories: + # audit.log can be rotated and new file not created until access to db + assert ( + file in ls_output or file == "audit.log" + ), f"❌ unexpected files/directories in log directory: {ls_output}" + + logger.info("Ensuring log files were rotated") + # Exclude checking slowquery log rotation as slowquery logs are disabled by default + for log in set(log_types): + file_contents = await read_contents_from_file_in_unit( + ops_test, unit, f"/var/log/mysql/{log}.log" + ) + assert f"test {log} content" not in file_contents, f"❌ log file {log}.log not rotated" + + ls_output = await ls_in_unit(ops_test, unit.name, f"/var/log/mysql/archive_{log}/") + assert len(ls_output) != 0, f"❌ archive directory is empty: {ls_output}" + + rotated_file_content_exists = False + for filename in ls_output: + file_contents = await read_contents_from_file_in_unit( + ops_test, + unit, + f"/var/log/mysql/archive_{log}/{filename}", + ) + if f"test {log} content" in file_contents: + rotated_file_content_exists = True + assert rotated_file_content_exists, f"❌ log file {log}.log not rotated" diff --git a/tests/integration/juju_.py b/tests/integration/juju_.py index b140e3e71..ddc47aa85 100644 --- a/tests/integration/juju_.py +++ b/tests/integration/juju_.py @@ -14,7 +14,7 @@ juju_major_version = int(_libjuju_version.split(".")[0]) -async def run_action(unit: juju.unit.Unit, action_name, **params): +async def run_action(unit: juju.unit.Unit, action_name: str, **params): action = await unit.run_action(action_name=action_name, **params) result = await action.wait() # Syntax changed across libjuju major versions diff --git a/tests/integration/test_charm.py b/tests/integration/test_charm.py index a3ba4274f..fc44a0e4e 100644 --- a/tests/integration/test_charm.py +++ b/tests/integration/test_charm.py @@ -15,8 +15,6 @@ from utils import generate_random_password from .helpers import ( - delete_file_or_directory_in_unit, - dispatch_custom_event_for_logrotate, execute_queries_on_unit, fetch_credentials, generate_random_string, @@ -24,15 +22,10 @@ get_primary_unit, get_server_config_credentials, get_unit_address, - ls_la_in_unit, - read_contents_from_file_in_unit, retrieve_database_variable_value, rotate_credentials, scale_application, start_mysqld_exporter, - stop_running_flush_mysql_job, - stop_running_log_rotate_dispatcher, - write_content_to_file_in_unit, ) logger = logging.getLogger(__name__) @@ -336,96 +329,3 @@ async def test_custom_variables(ops_test: OpsTest) -> None: logger.info(f"Checking that {k} is set to {v} on {unit.name}") value = await retrieve_database_variable_value(ops_test, unit, k) assert int(value) == v, f"Variable {k} is not set to {v}" - - -@pytest.mark.group(1) -@pytest.mark.abort_on_fail -async def test_log_rotation(ops_test: OpsTest) -> None: - """Test the log rotation of text files.""" - unit = ops_test.model.applications[APP_NAME].units[0] - - logger.info("Extending update-status-hook-interval to 60m") - await ops_test.model.set_config({"update-status-hook-interval": "60m"}) - - # Exclude slowquery log files as slowquery logs are not enabled by default - log_types = ["error", "general", "audit"] - log_files = ["error.log", "general.log", "audit.log"] - archive_directories = [ - "archive_error", - "archive_general", - "archive_slowquery", - "archive_audit", - ] - - logger.info("Overwriting the log rotate dispatcher script") - unit_label = unit.name.replace("/", "-") - await write_content_to_file_in_unit( - ops_test, - unit, - f"/var/lib/juju/agents/unit-{unit_label}/charm/scripts/log_rotate_dispatcher.py", - "exit(0)\n", - container_name="charm", - ) - - logger.info("Stopping the log rotate dispatcher") - await stop_running_log_rotate_dispatcher(ops_test, unit.name) - - logger.info("Stopping any running logrotate jobs") - await stop_running_flush_mysql_job(ops_test, unit.name) - - logger.info("Removing existing archive directories") - for archive_directory in archive_directories: - await delete_file_or_directory_in_unit( - ops_test, - unit.name, - f"/var/log/mysql/{archive_directory}/", - ) - - logger.info("Writing some data to the text log files") - for log in log_types: - log_path = f"/var/log/mysql/{log}.log" - await write_content_to_file_in_unit(ops_test, unit, log_path, f"test {log} content\n") - - logger.info("Ensuring only log files exist") - ls_la_output = await ls_la_in_unit(ops_test, unit.name, "/var/log/mysql/") - - assert len(ls_la_output) == len( - log_files - ), f"❌ files other than log files exist {ls_la_output}" - directories = [line.split()[-1] for line in ls_la_output] - assert sorted(directories) == sorted( - log_files - ), f"❌ file other than logs files exist: {ls_la_output}" - - logger.info("Dispatching custom event to rotate logs") - await dispatch_custom_event_for_logrotate(ops_test, unit.name) - - logger.info("Ensuring log files and archive directories exist") - ls_la_output = await ls_la_in_unit(ops_test, unit.name, "/var/log/mysql/") - - assert len(ls_la_output) == len( - log_files + archive_directories - ), f"❌ unexpected files/directories in log directory: {ls_la_output}" - directories = [line.split()[-1] for line in ls_la_output] - assert sorted(directories) == sorted( - log_files + archive_directories - ), f"❌ unexpected files/directories in log directory: {ls_la_output}" - - logger.info("Ensuring log files were rotated") - # Exclude checking slowquery log rotation as slowquery logs are disabled by default - for log in set(log_types): - file_contents = await read_contents_from_file_in_unit( - ops_test, unit, f"/var/log/mysql/{log}.log" - ) - assert f"test {log} content" not in file_contents, f"❌ log file {log}.log not rotated" - - ls_la_output = await ls_la_in_unit(ops_test, unit.name, f"/var/log/mysql/archive_{log}/") - assert len(ls_la_output) == 1, f"❌ more than 1 file in archive directory: {ls_la_output}" - - filename = ls_la_output[0].split()[-1] - file_contents = await read_contents_from_file_in_unit( - ops_test, - unit, - f"/var/log/mysql/archive_{log}/{filename}", - ) - assert f"test {log} content" in file_contents, f"❌ log file {log}.log not rotated"