"""Datadog monitor logging utils.""" from datetime import datetime from garcon_contrib.dynamo_feed_status.garcon_feed_status import \ STATUS_DOWNLOADED, STATUS_INGESTED, STATUS_NOT_AVAILABLE, \ STATUS_NOT_INGESTED, STATUS_POPULATED_RAW_TABLE DATADOG_LOG_PREFIX = 'DATADOG_MONITOR' LOG_NOT_COMPLETED_FOR_EXPECTED_TIME = '{DATADOG_LOG_PREFIX} {status} NOT COMPLETED FOR EXPECTED TIME: {feed_name}, {report_date}, {now}' # noqa LOG_COMPLETED_WITH_DELAY = '{DATADOG_LOG_PREFIX} {status} COMPLETED WITH DELAY: {feed_name}, {report_date}, {now}' # noqa LOG_COMPLETED_IN_TIME = '{DATADOG_LOG_PREFIX} {status} COMPLETED IN TIME: {feed_name}, {report_date}, {now}' # noqa completed_statuses = [STATUS_DOWNLOADED, STATUS_INGESTED, STATUS_POPULATED_RAW_TABLE] uncompleted_statuses = [STATUS_NOT_INGESTED, STATUS_NOT_AVAILABLE] feed_name_status_ingested_remapping = { # see apple_music.bootstrap.feed_name_for_fact_analytics 'apple_music_sme_amStreamsSummary': 'apple_sme', 'apple_music_theorchard_amStreamsSummary': 'apple_theorchard' } config = { 'spotify_sme': {'backfill_days_threshold': 3, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{24 + 16}:30', STATUS_NOT_AVAILABLE: f'{24 + 16}:30', STATUS_NOT_INGESTED: f'{24 + 17}:30', STATUS_INGESTED: f'{24 + 17}:30', }}, 'spotify_theorchard': {'backfill_days_threshold': 3, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{24 + 16}:30', STATUS_NOT_AVAILABLE: f'{24 + 16}:30', STATUS_NOT_INGESTED: f'{24 + 17}:30', STATUS_INGESTED: f'{24 + 17}:30', }}, 'apple_sme': {'backfill_days_threshold': 3, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{24 + 16}:30', STATUS_NOT_AVAILABLE: f'{24 + 16}:30', STATUS_NOT_INGESTED: f'{24 + 17}:30', STATUS_INGESTED: f'{24 + 17}:30', }}, 'apple_theorchard': {'backfill_days_threshold': 3, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{24 + 16}:30', STATUS_NOT_AVAILABLE: f'{24 + 16}:30', STATUS_NOT_INGESTED: f'{24 + 17}:30', STATUS_INGESTED: f'{24 + 17}:30', }}, 'amazon_music_sme_adsupported': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 1}:00', STATUS_NOT_AVAILABLE: f'{2 * 24 + 1}:00', STATUS_NOT_INGESTED: f'{2 * 24 + 1}:20', STATUS_INGESTED: f'{2 * 24 + 1}:20', }}, 'amazon_music_theorchard_adsupported': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 1}:00', STATUS_NOT_AVAILABLE: f'{2 * 24 + 1}:00', STATUS_NOT_INGESTED: f'{2 * 24 + 1}:20', STATUS_INGESTED: f'{2 * 24 + 1}:20', }}, 'amazon_music_sme_prime': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 1}:00', STATUS_NOT_AVAILABLE: f'{2 * 24 + 1}:00', STATUS_NOT_INGESTED: f'{2 * 24 + 1}:20', STATUS_INGESTED: f'{2 * 24 + 1}:20', }}, 'amazon_music_theorchard_prime': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 1}:00', STATUS_NOT_AVAILABLE: f'{2 * 24 + 1}:00', STATUS_NOT_INGESTED: f'{2 * 24 + 1}:20', STATUS_INGESTED: f'{2 * 24 + 1}:20', }}, 'amazon_music_sme_unlimited': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 1}:00', STATUS_NOT_AVAILABLE: f'{2 * 24 + 1}:00', STATUS_NOT_INGESTED: f'{2 * 24 + 1}:20', STATUS_INGESTED: f'{2 * 24 + 1}:20', }}, 'amazon_music_theorchard_unlimited': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 1}:00', STATUS_NOT_AVAILABLE: f'{2 * 24 + 1}:00', STATUS_NOT_INGESTED: f'{2 * 24 + 1}:20', STATUS_INGESTED: f'{2 * 24 + 1}:20', }}, 'tiktok_sme': {'backfill_days_threshold': 3, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 2}:30', STATUS_NOT_AVAILABLE: f'{2 * 24 + 2}:30', STATUS_NOT_INGESTED: f'{2 * 24 + 2}:40', STATUS_INGESTED: f'{2 * 24 + 2}:40', }}, 'tiktok_theorchard': {'backfill_days_threshold': 3, 'step_expected_time_delay': { STATUS_DOWNLOADED: f'{2 * 24 + 2}:30', STATUS_NOT_AVAILABLE: f'{2 * 24 + 2}:30', STATUS_NOT_INGESTED: f'{2 * 24 + 2}:40', STATUS_INGESTED: f'{2 * 24 + 2}:40', }}, # testing configs 'qq_sme': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: '02:00', STATUS_NOT_AVAILABLE: '02:00', STATUS_INGESTED: '02:20', STATUS_NOT_INGESTED: '02:20' }}, 'qq_theorchard': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: '12:00', STATUS_NOT_AVAILABLE: '12:00', STATUS_INGESTED: '12:20', STATUS_NOT_INGESTED: '12:20' }}, 'kugou_sme': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: '08:00', STATUS_NOT_AVAILABLE: '08:00', STATUS_INGESTED: '08:20', STATUS_NOT_INGESTED: '08:20' }}, 'kugou_theorchard': {'backfill_days_threshold': 5, 'step_expected_time_delay': { STATUS_DOWNLOADED: '08:00', STATUS_NOT_AVAILABLE: '08:00', STATUS_INGESTED: '08:20', STATUS_NOT_INGESTED: '09:20' }} } def log_feed_ingestion_status(activity, feed_name, report_date, status): """Log status to datadog based expected time for specific feed.""" if status == STATUS_INGESTED and \ feed_name in feed_name_status_ingested_remapping: feed_name = feed_name_status_ingested_remapping[feed_name] if status in uncompleted_statuses: log_feed_ingestion_uncompleted_status(activity, feed_name, report_date, status) elif status in completed_statuses: log_feed_ingestion_completed_status(activity, feed_name, report_date, status) else: activity.logger.info( f'Unknown status {status} feed_name : {feed_name}') def log_feed_ingestion_uncompleted_status(activity, feed_name, report_date, status): """Log uncompleated to datadog based expected time for specific feed.""" report_date_obj = datetime.strptime(report_date, '%Y-%m-%d') if feed_name in config: feed_config = config[feed_name] now = datetime.now() if (now - report_date_obj).days < \ config[feed_name]['backfill_days_threshold']: if status not in feed_config['step_expected_time_delay']: activity.logger.info( f'No timing configuration for {feed_name}/{status}') return if _is_delayed(report_date, feed_config['step_expected_time_delay'][status]): activity.logger.info( LOG_NOT_COMPLETED_FOR_EXPECTED_TIME.format( DATADOG_LOG_PREFIX=DATADOG_LOG_PREFIX, status=status, feed_name=feed_name, report_date=report_date, now=now)) else: activity.logger.info( f'{feed_name} completed within expected time') else: activity.logger.info(f'Backfill {feed_name} {report_date}') else: activity.logger.info( f'{feed_name} is not configured for notifications') def log_feed_ingestion_completed_status(activity, feed_name, report_date, status): """Log with monitory prefix in case status set after expected time. Dates outside configured dataq range are considered as a backfill. """ report_date_obj = datetime.strptime(report_date, '%Y-%m-%d') if feed_name in config: feed_config = config[feed_name] now = datetime.now() if (now - report_date_obj).days < \ config[feed_name]['backfill_days_threshold']: if status not in feed_config['step_expected_time_delay']: activity.logger.info( f'No timing configuration for {feed_name}/{status}') return if _is_delayed(report_date, feed_config['step_expected_time_delay'][status]): activity.logger.info( LOG_COMPLETED_WITH_DELAY.format( DATADOG_LOG_PREFIX=DATADOG_LOG_PREFIX, status=status, feed_name=feed_name, report_date=report_date, now=now)) else: activity.logger.info( LOG_COMPLETED_IN_TIME.format( DATADOG_LOG_PREFIX=DATADOG_LOG_PREFIX, status=status, feed_name=feed_name, report_date=report_date, now=now)) else: activity.logger.info(f'Backfill {feed_name} {report_date}') else: activity.logger.info( f'{feed_name} is not configured for notifications') def _is_delayed(report_date, expected_delay): report_date_object = datetime.strptime(report_date, '%Y-%m-%d') now = datetime.now() expected_hours_delay = int(expected_delay.split(':')[0]) expected_min_delay = int(expected_delay.split(':')[1]) expected_minutes_delay = expected_hours_delay * 60 + expected_min_delay time_difference = now - report_date_object actual_difference_in_minutes = time_difference.total_seconds() / 60 return actual_difference_in_minutes > expected_minutes_delay