diff --git a/openedx/core/djangoapps/schedules/resolvers.py b/openedx/core/djangoapps/schedules/resolvers.py index 5899ebf50b..b2ace23c44 100644 --- a/openedx/core/djangoapps/schedules/resolvers.py +++ b/openedx/core/djangoapps/schedules/resolvers.py @@ -136,13 +136,13 @@ class BinnedSchedulesBaseResolver(PrefixedDebugLoggerMixin, RecipientResolver): if "read_replica" in settings.DATABASES: schedules = schedules.using("read_replica") - LOG.debug('Query = %r', schedules.query.sql_with_params()) + LOG.info('Query = %r', schedules.query.sql_with_params()) with function_trace('schedule_query_set_evaluation'): # This will run the query and cache all of the results in memory. num_schedules = len(schedules) - LOG.debug('Number of schedules = %d', num_schedules) + LOG.info('Number of schedules = %d', num_schedules) # This should give us a sense of the volume of data being processed by each task. set_custom_metric('num_schedules', num_schedules) @@ -356,7 +356,11 @@ class CourseUpdateResolver(BinnedSchedulesBaseResolver): try: week_highlights = get_week_highlights(user, enrollment.course_id, week_num) except CourseUpdateDoesNotExist: - continue + LOG.exception( + 'Weekly highlights for user {} in week {} of course {} does not exist or is disabled'.format( + user, week_num, enrollment.course_id + ) + ) template_context.update({ 'course_name': schedule.enrollment.course.display_name, diff --git a/openedx/core/djangoapps/schedules/tasks.py b/openedx/core/djangoapps/schedules/tasks.py index dda2237dd1..2ac8db78cb 100644 --- a/openedx/core/djangoapps/schedules/tasks.py +++ b/openedx/core/djangoapps/schedules/tasks.py @@ -64,18 +64,28 @@ class ScheduleMessageBaseTask(Task): @classmethod def log_debug(cls, message, *args, **kwargs): + """ + Wrapper around LOG.debug that prefixes the message. + """ LOG.debug(cls.log_prefix + ': ' + message, *args, **kwargs) + @classmethod + def log_info(cls, message, *args, **kwargs): + """ + Wrapper around LOG.info that prefixes the message. + """ + LOG.info(cls.log_prefix + ': ' + message, *args, **kwargs) + @classmethod def enqueue(cls, site, current_date, day_offset, override_recipient_email=None): current_date = resolvers._get_datetime_beginning_of_day(current_date) if not cls.is_enqueue_enabled(site): - cls.log_debug('Message queuing disabled for site %s', site.domain) + cls.log_info('Message queuing disabled for site %s', site.domain) return target_date = current_date + datetime.timedelta(days=day_offset) - cls.log_debug('Target date = %s', target_date.isoformat()) + cls.log_info('Target date = %s', target_date.isoformat()) for bin in range(cls.num_bins): task_args = ( site.id, @@ -84,7 +94,7 @@ class ScheduleMessageBaseTask(Task): bin, override_recipient_email, ) - cls.log_debug('Launching task with args = %r', task_args) + cls.log_info('Launching task with args = %r', task_args) cls.apply_async( task_args, retry=False, @@ -218,7 +228,7 @@ def _is_delivery_enabled(site, delivery_config_var, log_prefix): if getattr(ScheduleConfig.current(site), delivery_config_var, False): return True else: - LOG.debug('%s: Message delivery disabled for site %s', log_prefix, site.domain) + LOG.info('%s: Message delivery disabled for site %s', log_prefix, site.domain) def _annotate_for_monitoring(message_type, site, bin_num, target_day_str, day_offset): diff --git a/openedx/core/djangoapps/schedules/tests/test_tasks.py b/openedx/core/djangoapps/schedules/tests/test_tasks.py index bebd81689d..ad2bf113ac 100644 --- a/openedx/core/djangoapps/schedules/tests/test_tasks.py +++ b/openedx/core/djangoapps/schedules/tests/test_tasks.py @@ -29,7 +29,7 @@ class TestScheduleMessageBaseTask(CacheIsolationTestCase): with patch.multiple( self.basetask, is_enqueue_enabled=Mock(return_value=False), - log_debug=DEFAULT, + log_info=DEFAULT, run=send, ) as patches: self.basetask.enqueue( @@ -37,7 +37,7 @@ class TestScheduleMessageBaseTask(CacheIsolationTestCase): current_date=datetime.datetime.now(), day_offset=2 ) - patches['log_debug'].assert_called_once_with( + patches['log_info'].assert_called_once_with( 'Message queuing disabled for site %s', self.site.domain) send.apply_async.assert_not_called() @@ -48,7 +48,7 @@ class TestScheduleMessageBaseTask(CacheIsolationTestCase): with patch.multiple( self.basetask, is_enqueue_enabled=Mock(return_value=True), - log_debug=DEFAULT, + log_info=DEFAULT, run=send, ) as patches: self.basetask.enqueue( @@ -58,8 +58,7 @@ class TestScheduleMessageBaseTask(CacheIsolationTestCase): ) target_date = current_date.replace(hour=0, minute=0, second=0, microsecond=0) + \ datetime.timedelta(day_offset) - print(patches['log_debug'].mock_calls) - patches['log_debug'].assert_any_call( + patches['log_info'].assert_any_call( 'Target date = %s', target_date.isoformat()) assert send.call_count == DEFAULT_NUM_BINS diff --git a/openedx/core/djangoapps/schedules/utils.py b/openedx/core/djangoapps/schedules/utils.py index 1364cebb2a..ee8b70725c 100644 --- a/openedx/core/djangoapps/schedules/utils.py +++ b/openedx/core/djangoapps/schedules/utils.py @@ -14,4 +14,13 @@ class PrefixedDebugLoggerMixin(object): self.log_prefix = self.__class__.__name__ def log_debug(self, message, *args, **kwargs): + """ + Wrapper around LOG.debug that prefixes the message. + """ LOG.debug(self.log_prefix + ': ' + message, *args, **kwargs) + + def log_info(self, message, *args, **kwargs): + """ + Wrapper around LOG.info that prefixes the message. + """ + LOG.info(self.log_prefix + ': ' + message, *args, **kwargs)