diff --git a/itou/approvals/management/commands/send_approvals_to_pe.py b/itou/approvals/management/commands/send_approvals_to_pe.py index e97007cfced..f9ed0db16f0 100644 --- a/itou/approvals/management/commands/send_approvals_to_pe.py +++ b/itou/approvals/management/commands/send_approvals_to_pe.py @@ -62,12 +62,15 @@ def handle(self, *, wet_run, delay, **options): ).order_by("-start_at") nb_approvals = queryset.count() - self.stdout.write(f"approvals needing to be sent count={nb_approvals}, batch count={MAX_APPROVALS_PER_RUN}") + self.logger.info("approvals needing to be sent count=%s, batch count=%s", nb_approvals, MAX_APPROVALS_PER_RUN) nb_approvals_to_send = min(nb_approvals, MAX_APPROVALS_PER_RUN) for approval in queryset[:nb_approvals_to_send]: - self.stdout.write( - f"approvals={approval} start_at={approval.start_at} pe_state={approval.pe_notification_status}" + self.logger.info( + "approvals=%s start_at=%s pe_state=%s", + approval, + approval.start_at, + approval.pe_notification_status, ) if wet_run: approval.notify_pole_emploi() @@ -81,13 +84,17 @@ def handle(self, *, wet_run, delay, **options): api_enums.PEApiNotificationStatus.SHOULD_RETRY, ], ).order_by("-start_at") - self.stdout.write( - f"cancelled approvals needing to be sent count={cancelled_queryset.count()}, batch count={batch_left}" + self.logger.info( + "cancelled approvals needing to be sent count=%s, batch count=%s", + cancelled_queryset.count(), + batch_left, ) for cancelled_approval in cancelled_queryset[:batch_left]: - self.stdout.write( - f"cancelled_approval={cancelled_approval} start_at={cancelled_approval.start_at} " - f"pe_state={cancelled_approval.pe_notification_status}" + self.logger.info( + "cancelled_approval=%s start_at=%s pe_state=%s", + cancelled_approval, + cancelled_approval.start_at, + cancelled_approval.pe_notification_status, ) if wet_run: cancelled_approval.notify_pole_emploi() diff --git a/tests/approvals/test_notify_pole_emploi.py b/tests/approvals/test_notify_pole_emploi.py index c91edb04f49..9aa3b944cca 100644 --- a/tests/approvals/test_notify_pole_emploi.py +++ b/tests/approvals/test_notify_pole_emploi.py @@ -1,5 +1,4 @@ import datetime -import io import json from unittest.mock import patch @@ -556,8 +555,7 @@ class TestApprovalsSendToPeManagement: @patch("itou.approvals.management.commands.send_approvals_to_pe.sleep") # smaller batch to ease testing @patch("itou.approvals.management.commands.send_approvals_to_pe.MAX_APPROVALS_PER_RUN", 10) - def test_invalid_job_seeker_for_pole_emploi(self, sleep_mock, notify_mock, cancelled_notify_mock): - stdout = io.StringIO() + def test_invalid_job_seeker_for_pole_emploi(self, sleep_mock, notify_mock, cancelled_notify_mock, caplog): # create ignored Approvals, will not even be counted in the batch. the cron will wait for # the database to have the necessary job application, nir, or start date to fetch them. no_jobapp = ApprovalFactory(with_jobapplication=False) @@ -598,9 +596,8 @@ def test_invalid_job_seeker_for_pole_emploi(self, sleep_mock, notify_mock, cance "send_approvals_to_pe", wet_run=True, delay=3, - stdout=stdout, ) - assert stdout.getvalue().split("\n") == [ + assert caplog.messages[:-1] == [ "approvals needing to be sent count=3, batch count=10", f"approvals={pending_approval} start_at={pending_approval.start_at.isoformat()} " "pe_state=notification_ready", @@ -613,9 +610,11 @@ def test_invalid_job_seeker_for_pole_emploi(self, sleep_mock, notify_mock, cance f"cancelled_approval={cancelled_approval} start_at={cancelled_approval.start_at.isoformat()} " "pe_state=notification_ready" for cancelled_approval in cancelled_approvals[:7] - ] + [ - "", ] + # Last log shows the timing: use startswith + assert caplog.messages[-1].startswith( + "Management command itou.approvals.management.commands.send_approvals_to_pe succeeded in " + ) sleep_mock.assert_called_with(3) assert sleep_mock.call_count == 10 assert notify_mock.call_count == 3