Merge pull request #4762 from mozilla/allow-statsd-debug

Update tests for `STATSD_DEBUG=True`

emails/tests/mgmt_process_emails_from_sqs_tests.py

@@ -18,7 +18,7 @@
 from pytest_django.fixtures import SettingsWrapper
 
 from emails.tests.views_tests import EMAIL_SNS_BODIES
-from privaterelay.tests.utils import log_extra
+from privaterelay.tests.utils import log_extra, omit_markus_logs
 
 if TYPE_CHECKING:
     from botocore.exceptions import _ClientErrorResponseTypeDef
@@ -252,7 +252,7 @@ def test_no_messages(caplog: LogCaptureFixture, test_settings: SettingsWrapper)
     """The command can exit after the max time and processing no messages."""
     call_command(COMMAND_NAME)
 
-    rec1, rec2, rec3, rec4 = caplog.records
+    rec1, rec2, rec3, rec4 = omit_markus_logs(caplog)
     assert rec1.getMessage() == "Starting process_emails_from_sqs"
     assert log_extra(rec1) == {
         "aws_region": "us-east-1",
@@ -319,7 +319,7 @@ def test_one_message(
     mock_sqs_client.return_value = fake_queue([msg], [])
     call_command(COMMAND_NAME)
 
-    msg_log = caplog.records[1]
+    msg_log = omit_markus_logs(caplog)[1]
     assert msg_log.getMessage() == "Message processed"
     msg_extra = log_extra(msg_log)
     assert set(msg_extra.keys()) == {
@@ -437,7 +437,7 @@ def test_ses_python_error(
     assert summary["total_messages"] == 1
     assert summary["failed_messages"] == 1
     msg.delete.assert_not_called()
-    rec2 = caplog.records[1]
+    rec2 = omit_markus_logs(caplog)[1]
     assert rec2.msg == "Message processed"
     rec2_extra = log_extra(rec2)
     assert rec2_extra["success"] is False
@@ -460,7 +460,7 @@ def test_ses_slow(
     summary = summary_from_exit_log(caplog)
     assert summary["total_messages"] == 1
     msg.delete.assert_called()
-    rec2 = caplog.records[1]
+    rec2 = omit_markus_logs(caplog)[1]
     assert rec2.msg == "Message processed"
     rec2_extra = log_extra(rec2)
     assert rec2_extra["success"] is True
@@ -486,7 +486,7 @@ def test_ses_timeout(
     assert summary["total_messages"] == 1
     assert summary["failed_messages"] == 1
     msg.delete.assert_not_called()
-    rec2 = caplog.records[1]
+    rec2 = omit_markus_logs(caplog)[1]
     assert rec2.msg == "Message processed"
     rec2_extra = log_extra(rec2)
     assert rec2_extra["success"] is False
@@ -507,7 +507,7 @@ def test_db_is_unusable_is_closed(
     summary = summary_from_exit_log(caplog)
     assert summary["total_messages"] == 1
     msg.delete.assert_called()
-    rec2 = caplog.records[1]
+    rec2 = omit_markus_logs(caplog)[1]
     assert rec2.msg == "Message processed"
     rec2_extra = log_extra(rec2)
     assert rec2_extra["success"] is True

phones/tests/models_tests.py

@@ -18,6 +18,7 @@
 from twilio.base.exceptions import TwilioRestException
 
 from emails.models import Profile
+from privaterelay.tests.utils import omit_markus_logs
 
 if settings.PHONES_ENABLED:
     from ..models import (
@@ -391,8 +392,11 @@ def test_create_relaynumber_already_registered_with_service(
         phone_number_sid=twilio_number_sid
     )
     mock_twilio_client.messages.create.assert_called_once()
-    assert caplog.messages == ["twilio_messaging_service"]
-    assert caplog.records[0].code == 21710
+    records = omit_markus_logs(caplog)
+    assert len(records) == 1
+    record = records[0]
+    assert record.msg == "twilio_messaging_service"
+    assert getattr(record, "code") == 21710
 
 
 def test_create_relaynumber_fail_if_all_services_are_full(
@@ -423,8 +427,11 @@ def test_create_relaynumber_fail_if_all_services_are_full(
         phone_number_sid=twilio_number_sid
     )
     mock_twilio_client.messages.create.assert_not_called()
-    assert caplog.messages == ["twilio_messaging_service"]
-    assert caplog.records[0].code == 21714
+    records = omit_markus_logs(caplog)
+    assert len(records) == 1
+    record = records[0]
+    assert record.msg == "twilio_messaging_service"
+    assert getattr(record, "code") == 21714
 
 
 def test_create_relaynumber_no_service(
@@ -438,10 +445,13 @@ def test_create_relaynumber_no_service(
     mock_services = mock_twilio_client.messaging.v1.services
     mock_services.return_value.phone_numbers.create.assert_not_called()
     mock_twilio_client.messages.create.assert_called_once()
-    assert caplog.messages == [
+    records = omit_markus_logs(caplog)
+    assert len(records) == 1
+    record = records[0]
+    assert record.msg == (
         "Skipping Twilio Messaging Service registration, since"
         " TWILIO_MESSAGING_SERVICE_SID is empty."
-    ]
+    )
 
 
 def test_create_relaynumber_fallback_to_second_service(
@@ -486,8 +496,11 @@ def test_create_relaynumber_fallback_to_second_service(
     mock_twilio_client.messages.create.assert_called_once()
 
     assert django_cache.get("twilio_messaging_service_closed") == twilio_service1_sid
-    assert caplog.messages == ["twilio_messaging_service"]
-    assert caplog.records[0].code == 21714
+    records = omit_markus_logs(caplog)
+    assert len(records) == 1
+    record = records[0]
+    assert record.msg == "twilio_messaging_service"
+    assert getattr(record, "code") == 21714
 
 
 def test_create_relaynumber_skip_known_full_service(
@@ -514,7 +527,7 @@ def test_create_relaynumber_skip_known_full_service(
     )
     mock_twilio_client.messages.create.assert_called_once()
     assert django_cache.get("twilio_messaging_service_closed") == twilio_service1_sid
-    assert caplog.messages == []
+    assert len(omit_markus_logs(caplog)) == 0
 
 
 def test_create_relaynumber_other_messaging_error_raised(

privaterelay/tests/utils.py

@@ -10,6 +10,15 @@
 import pytest
 
 
+def omit_markus_logs(caplog: pytest.LogCaptureFixture) -> list[LogRecord]:
+    """
+    Return log records that are not markus debug logs.
+
+    Markus debug logs are enabled at Django setup with STATSD_DEBUG=True
+    """
+    return [rec for rec in caplog.records if rec.name != "markus"]
+
+
 def log_extra(log_record: LogRecord) -> dict[str, Any]:
     """Reconstruct the "extra" argument to the log call"""
     omit_log_record_keys = {