"""Unit tests for test_log_status.""" from unittest.mock import MagicMock, patch from freezegun import freeze_time from garcon_contrib.dynamo_feed_status.garcon_feed_status import \ STATUS_DOWNLOADED, STATUS_NOT_AVAILABLE, STATUS_INGESTED, \ STATUS_NOT_INGESTED import pytest from feed_ingestion.util.log_status import log_feed_ingestion_status, \ _is_delayed test_config = { 'test_1_sme': {'backfill_days_threshold': 2, 'step_expected_time_delay': { STATUS_DOWNLOADED: '19:00', STATUS_INGESTED: '20:00', STATUS_NOT_AVAILABLE: '20:00', }}, 'test_1_theorchard': {'backfill_days_threshold': 2, 'step_expected_time_delay': { STATUS_DOWNLOADED: '19:00', STATUS_INGESTED: '20:00', STATUS_NOT_AVAILABLE: '20:00', }} } @pytest.mark.parametrize( 'now, report_date, expected_delay, result', [ ('2025-10-01 19:00:10', '2025-10-01', '18:50', True), ('2025-10-01 19:00:10', '2025-10-01', '19:20', False), ('2025-10-02 00:00:00', '2025-10-01', '23:00', True), ('2025-10-02 00:00:00', '2025-10-01', '24:01', False), ('2025-10-03 06:00:00', '2025-10-02', '30:01', False), ('2025-10-03 06:00:00', '2025-10-02', '30:00', False), ('2025-10-04 06:00:00', '2025-10-03', '29:59', True), ('2025-10-04 10:00:00', '2025-10-03', '33:01', True), ('2025-10-05 10:06:00', '2025-10-04', '34:05', True), # 3 days + 10 h = (3 * 24 + 10) * 60 = 82 ('2025-10-06 10:13:00', '2025-10-03', '82:14', False), ('2025-10-06 10:13:00', '2025-10-03', '80:00', True), ] ) def test_is_delayed(now, report_date, expected_delay, result): """Test is delayed.""" with freeze_time(now): assert _is_delayed(report_date, expected_delay) == result @pytest.mark.parametrize( 'now, report_date, status', [ ('2025-10-12 00:00:10', '2025-08-10', STATUS_DOWNLOADED), ('2025-10-12 00:00:10', '2025-10-09', STATUS_NOT_AVAILABLE), ] ) @patch('feed_ingestion.util.log_status.config', test_config) def test_log_feed_ingestion_status_do_nothing_for_backfill_dates(now, report_date, status): """Test that there is no monitor logs for backfill dates.""" feed_name = 'test_1_sme' with freeze_time(now): activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock log_feed_ingestion_status(activity_mock, feed_name, report_date, status) logger_mock.info.assert_called_with( f'Backfill test_1_sme {report_date}') def test_log_feed_ingestion_status_do_nothing_for_unknown_status(): """Test that there is no monitor logs for unkinfigured sttuses.""" feed_name = 'test_1_sme' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock log_feed_ingestion_status(activity_mock, feed_name, '2025-01-01', 'TEST_UNKNOWN_STATUS') logger_mock.info.assert_called_with( 'Unknown status TEST_UNKNOWN_STATUS feed_name : test_1_sme') @patch('feed_ingestion.util.log_status.config', { 'test_1_unconfigured_status': {'backfill_days_threshold': 2, 'step_expected_time_delay': { STATUS_DOWNLOADED: '19:00', }}, }) def test_log_feed_ingestion_status_do_nothing_for_unconfigured_status(): """Test that there is no monitor logs for unconfigured sttuses.""" feed_name = 'test_1_unconfigured_status' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock with freeze_time('2025-01-01'): log_feed_ingestion_status(activity_mock, feed_name, '2025-01-01', STATUS_NOT_AVAILABLE) logger_mock.info.assert_called_with( 'No timing configuration for test_1_unconfigured_status/NOT_AVAILABLE') def test_log_feed_ingestion_status_for_unconfigured_feed(): """Test that there is no monitor logs for unconfigured feeds.""" feed_name = 'unconfigured_feed' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock log_feed_ingestion_status(activity_mock, feed_name, '2025-01-01', STATUS_DOWNLOADED) logger_mock.info.assert_called_with( 'unconfigured_feed is not configured for notifications') @pytest.mark.parametrize( 'now, report_date, status, expected_log', [ ('2025-10-11 18:59:10', '2025-10-11', STATUS_DOWNLOADED, 'COMPLETED IN TIME'), ('2025-10-12 19:01:10', '2025-10-12', STATUS_DOWNLOADED, 'COMPLETED WITH DELAY'), ('2025-10-13 19:50:10', '2025-10-13', STATUS_INGESTED, 'COMPLETED IN TIME'), ] ) @patch('feed_ingestion.util.log_status.config', { 'test_log_compleated': {'backfill_days_threshold': 2, 'step_expected_time_delay': { STATUS_DOWNLOADED: '19:00', STATUS_INGESTED: '20:00', }}, }) def test_log_completed_with_and_without_delay(now, report_date, status, expected_log): """Test that log sends correct status completed monitor log.""" feed_name = 'test_log_compleated' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock with freeze_time(now): log_feed_ingestion_status(activity_mock, feed_name, report_date, status) logger_mock.info.assert_called_with( f'DATADOG_MONITOR {status} {expected_log}: {feed_name},' f' {report_date}, {now}') @pytest.mark.parametrize( 'now, report_date, status, expected_log', [ ('2025-10-11 18:59:10', '2025-10-11', STATUS_NOT_AVAILABLE, 'test_log_uncompleated completed within expected time'), ('2025-10-12 19:01:10', '2025-10-12', STATUS_NOT_AVAILABLE, 'DATADOG_MONITOR NOT_AVAILABLE NOT COMPLETED FOR EXPECTED TIME: ' 'test_log_uncompleated, 2025-10-12, 2025-10-12 19:01:10'), ('2025-10-13 19:50:10', '2025-10-13', STATUS_NOT_INGESTED, 'test_log_uncompleated completed within expected time'), ] ) @patch('feed_ingestion.util.log_status.config', { 'test_log_uncompleated': {'backfill_days_threshold': 2, 'step_expected_time_delay': { STATUS_NOT_AVAILABLE: '19:00', STATUS_NOT_INGESTED: '20:00', }}, }) def test_log_uncompleted_with_and_without_delay(now, report_date, status, expected_log): """Test that log sends correct status uncompleated monitor log.""" feed_name = 'test_log_uncompleated' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock with freeze_time(now): log_feed_ingestion_status(activity_mock, feed_name, report_date, status) logger_mock.info.assert_called_with(expected_log) @patch('feed_ingestion.util.log_status.config', { 'test_custom_status': {'backfill_days_threshold': 2, 'step_expected_time_delay': { 'ATHENA_DATA_UPDATED': '19:00', }}, }) @patch('feed_ingestion.util.log_status.completed_statuses', ['ATHENA_DATA_UPDATED']) def test_custom_status(): """Test custom status monitor logging.""" feed_name = 'test_custom_status' custom_status = 'ATHENA_DATA_UPDATED' report_date = '2025-10-11' now = '2025-10-11 18:59:10' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock with freeze_time(now): log_feed_ingestion_status(activity_mock, feed_name, report_date, custom_status) logger_mock.info.assert_called_with( f'DATADOG_MONITOR {custom_status} COMPLETED IN TIME: {feed_name},' f' {report_date}, {now}') def test_feed_name_remapping(): """Test feed name mapping.""" feed_name = 'apple_music_sme_amStreamsSummary' remapped_feed_name = 'apple_sme' status = STATUS_INGESTED report_date = '2025-10-11' now = '2025-10-11 18:59:10' activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock with freeze_time(now): log_feed_ingestion_status(activity_mock, feed_name, report_date, status) logger_mock.info.assert_called_with( f'DATADOG_MONITOR {status} COMPLETED IN TIME: ' f'{remapped_feed_name}, {report_date}, {now}') @pytest.mark.parametrize( 'now, report_date, feed_name, status, expected_log', [ ('2025-11-23 17:57:02', '2025-11-22', 'spotify_sme', STATUS_DOWNLOADED, 'DATADOG_MONITOR DOWNLOADED COMPLETED WITH DELAY: spotify_sme,' ' 2025-11-22, 2025-11-23 17:57:02'), ('2025-11-23 14:57:18', '2025-11-22', 'spotify_sme', STATUS_DOWNLOADED, 'DATADOG_MONITOR DOWNLOADED COMPLETED IN TIME: spotify_sme,' ' 2025-11-22, 2025-11-23 14:57:18'), ('2025-11-17 17:51:30', '2025-11-16', 'spotify_sme', STATUS_INGESTED, 'DATADOG_MONITOR INGESTED COMPLETED WITH DELAY: spotify_sme,' ' 2025-11-16, 2025-11-17 17:51:30'), ('2025-11-12 13:43:42', '2025-11-07', 'amazon_music_theorchard_prime', STATUS_DOWNLOADED, 'Backfill amazon_music_theorchard_prime 2025-11-07'), ('2025-11-07 06:27:27', '2025-11-05', 'amazon_music_theorchard_prime', STATUS_DOWNLOADED, 'DATADOG_MONITOR DOWNLOADED COMPLETED WITH DELAY:' ' amazon_music_theorchard_prime, 2025-11-05, 2025-11-07 06:27:27'), ('2025-11-09 21:59:33', '2025-11-08', 'amazon_music_sme_prime', STATUS_DOWNLOADED, 'DATADOG_MONITOR DOWNLOADED COMPLETED IN TIME:' ' amazon_music_sme_prime, 2025-11-08, 2025-11-09 21:59:33'), ('2025-11-07 06:27:27', '2025-11-05', 'amazon_music_theorchard_adsupported', STATUS_DOWNLOADED, 'DATADOG_MONITOR DOWNLOADED COMPLETED WITH DELAY: ' 'amazon_music_theorchard_adsupported,' ' 2025-11-05, 2025-11-07 06:27:27'), ('2025-11-08 00:28:40', '2025-11-06', 'amazon_music_theorchard_adsupported', STATUS_DOWNLOADED, 'DATADOG_MONITOR DOWNLOADED COMPLETED IN TIME: ' 'amazon_music_theorchard_adsupported,' ' 2025-11-06, 2025-11-08 00:28:40'), ] ) # https://www.notion.so/Etl-completions-thresholds-2b197177520f80b78b94eac06bebbb4f def test_config_on_real_examples(now, report_date, feed_name, status, expected_log): """Test that log sends correct status for amazon config.""" activity_mock = MagicMock() logger_mock = MagicMock() activity_mock.logger = logger_mock with freeze_time(now): log_feed_ingestion_status(activity_mock, feed_name, report_date, status) logger_mock.info.assert_called_with( expected_log)