🧑‍💻(tests) improve tests on logged info

Tests on log order make test maintenance difficult. They are useless and make developers crazy each time a log information is added :D
2025-03-06 08:05:18 +01:00
parent 54df9af179
commit c90a74b362
5 changed files with 101 additions and 95 deletions
--- a/src/backend/core/tests/test_utils_webhooks_scim_client.py
+++ b/src/backend/core/tests/test_utils_webhooks_scim_client.py
@@ -73,13 +73,16 @@ def test_utils_webhooks_add_user_to_group_success(mock_info):
            }

    # Logger
-    assert mock_info.call_count == 2
-    for i, webhook in enumerate(webhooks):
-        assert mock_info.call_args_list[i][0] == (
-            "%s synchronization succeeded with %s",
-            "add_user_to_group",
-            webhook.url,
-        )
+    for webhook in webhooks:
+        expected_messages = {
+            (
+                "%s synchronization succeeded with %s",
+                "add_user_to_group",
+                webhook.url,
+            )
+        }
+        actual_messages = {args for args, _ in mock_info.call_args_list}
+        assert expected_messages.issubset(actual_messages)

    # Status
    for webhook in webhooks:
@@ -130,13 +133,16 @@ def test_utils_webhooks_remove_user_from_group_success(mock_info):
            }

    # Logger
-    assert mock_info.call_count == 2
-    for i, webhook in enumerate(webhooks):
-        assert mock_info.call_args_list[i][0] == (
-            "%s synchronization succeeded with %s",
-            "remove_user_from_group",
-            webhook.url,
-        )
+    for webhook in webhooks:
+        expected_messages = {
+            (
+                "%s synchronization succeeded with %s",
+                "remove_user_from_group",
+                webhook.url,
+            )
+        }
+        actual_messages = {args for args, _ in mock_info.call_args_list}
+        assert expected_messages.issubset(actual_messages)

    # Status
    for webhook in webhooks:
@@ -145,8 +151,7 @@ def test_utils_webhooks_remove_user_from_group_success(mock_info):


@mock.patch.object(Logger, "error")
-@mock.patch.object(Logger, "info")
-def test_utils_webhooks_add_user_to_group_failure(mock_info, mock_error):
+def test_utils_webhooks_add_user_to_group_failure(mock_error):
    """The logger should be called on webhook call failure."""
    user = factories.UserFactory()
    access = factories.TeamAccessFactory(user=user)
@@ -188,14 +193,16 @@ def test_utils_webhooks_add_user_to_group_failure(mock_info, mock_error):
            }

    # Logger
-    assert not mock_info.called
-    assert mock_error.call_count == 2
-    for i, webhook in enumerate(webhooks):
-        assert mock_error.call_args_list[i][0] == (
-            "%s synchronization failed with %s",
-            "add_user_to_group",
-            webhook.url,
-        )
+    for webhook in webhooks:
+        expected_messages = {
+            (
+                "%s synchronization failed with %s",
+                "add_user_to_group",
+                webhook.url,
+            )
+        }
+        actual_messages = {args for args, _ in mock_error.call_args_list}
+        assert expected_messages.issubset(actual_messages)

    # Status
    for webhook in webhooks:
@@ -246,12 +253,15 @@ def test_utils_webhooks_add_user_to_group_retries(mock_info, mock_error):

    # Logger
    assert not mock_error.called
-    assert mock_info.call_count == 1
-    assert mock_info.call_args_list[0][0] == (
-        "%s synchronization succeeded with %s",
-        "add_user_to_group",
-        webhook.url,
-    )
+    expected_messages = {
+        (
+            "%s synchronization succeeded with %s",
+            "add_user_to_group",
+            webhook.url,
+        )
+    }
+    actual_messages = {args for args, _ in mock_info.call_args_list}
+    assert expected_messages.issubset(actual_messages)

    # Status
    webhook.refresh_from_db()
@@ -259,8 +269,7 @@ def test_utils_webhooks_add_user_to_group_retries(mock_info, mock_error):


@mock.patch.object(Logger, "error")
-@mock.patch.object(Logger, "info")
-def test_utils_synchronize_course_runs_max_retries_exceeded(mock_info, mock_error):
+def test_utils_synchronize_course_runs_max_retries_exceeded(mock_error):
    """Webhooks synchronization has exceeded max retries and should get logged."""
    user = factories.UserFactory()
    access = factories.TeamAccessFactory(user=user)
@@ -299,13 +308,15 @@ def test_utils_synchronize_course_runs_max_retries_exceeded(mock_info, mock_erro
        }

    # Logger
-    assert not mock_info.called
-    assert mock_error.call_count == 1
-    assert mock_error.call_args_list[0][0] == (
-        "%s synchronization failed due to max retries exceeded with url %s",
-        "add_user_to_group",
-        webhook.url,
-    )
+    expected_messages = {
+        (
+            "%s synchronization failed due to max retries exceeded with url %s",
+            "add_user_to_group",
+            webhook.url,
+        )
+    }
+    actual_messages = {args for args, _ in mock_error.call_args_list}
+    assert expected_messages.issubset(actual_messages)

    # Status
    webhook.refresh_from_db()
--- a/src/backend/mailbox_manager/tests/api/mail_domain/test_api_mail_domains_create.py
+++ b/src/backend/mailbox_manager/tests/api/mail_domain/test_api_mail_domains_create.py
@@ -335,18 +335,15 @@ def test_api_mail_domains__create_dimail_domain(caplog):
    assert response.status_code == status.HTTP_201_CREATED

    # Logger
-    assert len(caplog.records) == 4  # should be 3. Last empty info still here.
+    log_messages = [msg.message for msg in caplog.records]
    assert (
-        caplog.records[0].message
-        == f"Domain {domain_name} successfully created on dimail by user {user.sub}"
+        f"Domain {domain_name} successfully created on dimail by user {user.sub}"
+        in log_messages
    )
+    assert f'[DIMAIL] User "{user.sub}" successfully created on dimail' in log_messages
    assert (
-        caplog.records[1].message
-        == f'[DIMAIL] User "{user.sub}" successfully created on dimail'
-    )
-    assert (
-        caplog.records[2].message
-        == f'[DIMAIL] Permissions granted for user "{user.sub}" on domain {domain_name}.'
+        f'[DIMAIL] Permissions granted for user "{user.sub}" on domain {domain_name}.'
+        in log_messages
    )


--- a/src/backend/mailbox_manager/tests/api/mail_domain_accesses/test_api_mail_domain_accesses_create.py
+++ b/src/backend/mailbox_manager/tests/api/mail_domain_accesses/test_api_mail_domain_accesses_create.py
@@ -272,20 +272,20 @@ def test_api_mail_domains_accesses__create_dimail_allows(caplog):

    assert response.status_code == status.HTTP_201_CREATED

+    log_messages = [msg.message for msg in caplog.records]
    # check logs
    assert (
-        caplog.records[0].message
-        == f'[DIMAIL] User "{allowed_user.sub}" successfully created on dimail'
+        f'[DIMAIL] User "{allowed_user.sub}" successfully created on dimail'
+        in log_messages
    )
    assert (
-        caplog.records[1].message
-        == f'[DIMAIL] Permissions granted for user "{allowed_user.sub}" on domain {domain.name}.'
+        f'[DIMAIL] Permissions granted for user "{allowed_user.sub}" on domain {domain.name}.'
+        in log_messages
    )


-def test_api_mail_domains_accesses__dont_create_dimail_allows_for_viewer(caplog):
+def test_api_mail_domains_accesses__dont_create_dimail_allows_for_viewer():
    """Dimail should not be called when creating an access to a simple viewer."""
-    caplog.set_level(logging.INFO)

    authenticated_user = core_factories.UserFactory()
    domain = factories.MailDomainFactory(status="enabled")
@@ -309,9 +309,6 @@ def test_api_mail_domains_accesses__dont_create_dimail_allows_for_viewer(caplog)

    assert response.status_code == status.HTTP_201_CREATED

-    # check logs
-    assert len(caplog.records) == 1  # should be 0, investigate this damn empty message
-

 def test_api_mail_domains_accesses__user_already_on_dimail(caplog):
    """The expected allow should be created when an user already exists on dimail
@@ -358,12 +355,12 @@ def test_api_mail_domains_accesses__user_already_on_dimail(caplog):
    assert response.status_code == status.HTTP_201_CREATED

    # check logs
-    assert len(caplog.records) == 3  # should be 2, investigate this damn empty message
+    log_messages = [msg.message for msg in caplog.records]
    assert (
-        caplog.records[0].message
-        == f'[DIMAIL] Attempt to create user "{allowed_user.sub}" which already exists.'
+        f'[DIMAIL] Attempt to create user "{allowed_user.sub}" which already exists.'
+        in log_messages
    )
    assert (
-        caplog.records[1].message
-        == f'[DIMAIL] Permissions granted for user "{allowed_user.sub}" on domain {domain.name}.'
+        f'[DIMAIL] Permissions granted for user "{allowed_user.sub}" on domain {domain.name}.'
+        in log_messages
    )
--- a/src/backend/mailbox_manager/tests/api/mailboxes/test_api_mailboxes_create.py
+++ b/src/backend/mailbox_manager/tests/api/mailboxes/test_api_mailboxes_create.py
@@ -617,11 +617,11 @@ def test_api_mailboxes__dimail_token_permission_denied(caplog):
        assert mailbox.status == enums.MailboxStatusChoices.PENDING

        # Check error logger was called
-        assert caplog.records[0].levelname == "ERROR"
+        log_messages = [msg.message for msg in caplog.records]
        assert (
-            caplog.records[0].message
-            == "[DIMAIL] 403 Forbidden: Could not retrieve a token,"
-            "please check 'MAIL_PROVISIONING_API_CREDENTIALS' setting."
+            "[DIMAIL] 403 Forbidden: Could not retrieve a token,\
+please check 'MAIL_PROVISIONING_API_CREDENTIALS' setting."
+            in log_messages
        )


@@ -771,16 +771,17 @@ def test_api_mailboxes__send_correct_logger_infos(mock_info, mock_error):

    # Logger
    assert not mock_error.called
-    assert mock_info.call_count == 4
-    # a new empty error has been added. To be investigated
-    assert mock_info.call_args_list[0][0] == (
-        "Token succesfully granted by mail-provisioning API.",
-    )
-    assert mock_info.call_args_list[1][0] == (
-        "Mailbox successfully created on domain %s by user %s",
-        str(access.domain),
-        access.user.sub,
-    )
+    # Check all expected log messages are present, order doesn't matter
+    expected_messages = {
+        ("Token succesfully granted by mail-provisioning API.",),
+        (
+            "Mailbox successfully created on domain %s by user %s",
+            str(access.domain),
+            access.user.sub,
+        ),
+    }
+    actual_messages = {args for args, _ in mock_info.call_args_list}
+    assert expected_messages.issubset(actual_messages)


@mock.patch.object(Logger, "info")
@@ -826,9 +827,12 @@ def test_api_mailboxes__sends_new_mailbox_notification(mock_info):
        assert mock_send.mock_calls[0][1][0] == "Your new mailbox information"
        assert mock_send.mock_calls[0][1][3][0] == mailbox_data["secondary_email"]

-    assert mock_info.call_count == 4
-    assert mock_info.call_args_list[2][0] == (
-        "Information for mailbox %s sent to %s.",
-        f"{mailbox_data['local_part']}@{access.domain.name}",
-        mailbox_data["secondary_email"],
-    )
+    expected_messages = {
+        (
+            "Information for mailbox %s sent to %s.",
+            f"{mailbox_data['local_part']}@{access.domain.name}",
+            mailbox_data["secondary_email"],
+        )
+    }
+    actual_messages = {args for args, _ in mock_info.call_args_list}
+    assert expected_messages.issubset(actual_messages)
--- a/src/backend/mailbox_manager/tests/test_utils_dimail_client.py
+++ b/src/backend/mailbox_manager/tests/test_utils_dimail_client.py
@@ -387,24 +387,21 @@ def test_dimail__enable_pending_mailboxes(caplog):
    assert mailbox1.status == enums.MailboxStatusChoices.ENABLED
    assert mailbox2.status == enums.MailboxStatusChoices.ENABLED

-    assert len(caplog.records) == 6
+    log_messages = [msg.message for msg in caplog.records]
+    assert "Token succesfully granted by mail-provisioning API." in log_messages
    assert (
-        caplog.records[0].message
-        == "Token succesfully granted by mail-provisioning API."
+        f"Mailbox successfully created on domain {domain.name} by user None"
+        in log_messages
    )
    assert (
-        caplog.records[1].message
-        == f"Mailbox successfully created on domain {domain.name} by user None"
+        f"Information for mailbox mock@{domain.name} sent to {mailbox2.secondary_email}."
+        in log_messages
    )
    assert (
-        caplog.records[2].message
-        == f"Information for mailbox mock@{domain.name} sent to {mailbox2.secondary_email}."
+        f"Mailbox successfully created on domain {domain.name} by user None"
+        in log_messages
    )
    assert (
-        caplog.records[4].message
-        == f"Mailbox successfully created on domain {domain.name} by user None"
-    )
-    assert (
-        caplog.records[5].message
-        == f"Information for mailbox mock@{domain.name} sent to {mailbox1.secondary_email}."
+        f"Information for mailbox mock@{domain.name} sent to {mailbox1.secondary_email}."
+        in log_messages
    )