Skip to content

Commit 34b0d3f

Browse files
committed
Enable info logging of instant email alerts in production on demand.
* Added a boolean livesetting DEBUG_EMAIL_ALERTS in askbot/conf/email.py: * Added instant email alert utilities askbot/utils/debug_logging.py: - log_instant_email: function logs conditionally, if the above setting is True - log_instant_email_error: logs this error unconditionally * Added askbot.const.get_activity_type_display method * Added email alert logging using log_instant_email in askbot/models/post.py: - Post.issue_update_notifications - Post.get_global_instant_notification_subscribers - Post._qa__get_instant_notification_subscribers - Post._comment__get_instant_notification_subscribers - Post.get_instant_notification_subscribers - Post.get_notify_sets * Added email alert logging using log_instant_email in askbot/tasks.py - record_post_update_celery_task - this method creates uuid and passes it along as run_id - send_instant_notifications_about_activity_in_post - this is the secondary task dispatched indirectly by record_post_update_celery_task * Added test coverage for this functionality in askbot.tests.test_email_alerts:DebugEmailAlertsLoggingTests - test_debug_logging_emits_info_when_enabled - test_debug_logging_includes_run_id - test_debug_logging_includes_verbose_activity_type - test_no_debug_logging_when_disabled - test_debug_logging_delivery_summary
1 parent accc558 commit 34b0d3f

7 files changed

Lines changed: 302 additions & 31 deletions

File tree

askbot/conf/email.py

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -130,6 +130,20 @@ def get_default_admin_email():
130130
)
131131
)
132132

133+
settings.register(
134+
livesettings.BooleanValue(
135+
EMAIL,
136+
'DEBUG_EMAIL_ALERTS',
137+
default=False,
138+
description=_('Log debug info for instant email alerts'),
139+
help_text=_(
140+
'When enabled, logs detailed information about email '
141+
'notification processing at INFO level. '
142+
'Use for production debugging.'
143+
)
144+
)
145+
)
146+
133147
settings.register(
134148
livesettings.BooleanValue(
135149
EMAIL,

askbot/const/__init__.py

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -301,6 +301,9 @@
301301
),
302302
)
303303

304+
def get_activity_type_display(activity_type_key):
305+
return dict(TYPE_ACTIVITY).get(activity_type_key)
306+
304307
TYPE_ACTIVITY_BY_USER = (
305308
TYPE_ACTIVITY_ASK_QUESTION,
306309
TYPE_ACTIVITY_ANSWER,

askbot/doc/source/changelog.rst

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,8 @@ Development (not yet released)
1515
task timeout issues
1616
* Similarly, optimized ``send_email_alerts`` query performance
1717
* Improved test coverage for the instant email alerts sending functionalities
18+
* Added optional live info-level logging of instant email alerts,
19+
via a new boolean livesetting DEBUG_EMAIL_ALERTS
1820

1921
0.12.8 (Mar 15, 2026)
2022
---------------------

askbot/models/post.py

Lines changed: 113 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -35,13 +35,16 @@
3535
moderate_tags, sanitize_html,
3636
site_url)
3737
from askbot.utils.celery_utils import defer_celery_task
38+
from askbot.utils.debug_logging import log_instant_email
3839
from askbot.models.base import (AnonymousContent, BaseQuerySetManager,
3940
DraftContent)
4041

4142
# TODO: maybe merge askbot.utils.markup and forum.utils.html
4243
from askbot.utils.diff import textDiff as htmldiff
4344
#from askbot.search import mysql
4445

46+
logger = logging.getLogger(__name__)
47+
4548

4649
def default_html_moderator(post):
4750
"""Moderates inline HTML items: images and/or links
@@ -813,7 +816,7 @@ def remove_from_groups(self, groups):
813816

814817
def issue_update_notifications(self, updated_by=None, notify_sets=None,
815818
activity_type=None, suppress_email=False,
816-
timestamp=None, diff=None):
819+
timestamp=None, diff=None, run_id=None):
817820
"""Called when a post is updated. Arguments:
818821
819822
* ``notify_sets`` - result of ``Post.get_notify_sets()`` method
@@ -824,6 +827,12 @@ def issue_update_notifications(self, updated_by=None, notify_sets=None,
824827
* sends email alerts to all subscribers to the post
825828
"""
826829
assert(activity_type is not None)
830+
activity_label = const.get_activity_type_display(activity_type)
831+
log_instant_email(logger, run_id,
832+
'issue_update_notifications for post %d, '
833+
'activity_type=%s, updated_by=%d',
834+
self.id, activity_label, updated_by.id)
835+
827836
if diff:
828837
summary = diff
829838
else:
@@ -856,29 +865,50 @@ def issue_update_notifications(self, updated_by=None, notify_sets=None,
856865
user.update_response_counts()
857866

858867
# shortcircuit if the email alerts are disabled
859-
if suppress_email or not askbot_settings.ENABLE_EMAIL_ALERTS:
868+
if suppress_email:
869+
log_instant_email(logger, run_id,
870+
'email suppressed by caller for post %d', self.id)
871+
return
872+
if not askbot_settings.ENABLE_EMAIL_ALERTS:
873+
log_instant_email(logger, run_id, 'email alerts globally disabled')
860874
return
861875

862876
if not askbot_settings.INSTANT_EMAIL_ALERT_ENABLED:
877+
log_instant_email(logger, run_id, 'instant email alerts disabled')
863878
return
864879

865880
# TODO: fix this temporary spam protection plug
866881
if askbot_settings.MIN_REP_TO_TRIGGER_EMAIL:
867882
if not (updated_by.is_administrator() or updated_by.is_moderator()):
868883
if updated_by.reputation < askbot_settings.MIN_REP_TO_TRIGGER_EMAIL:
884+
original_count = len(notify_sets['for_email'])
869885
for_email = [u for u in notify_sets['for_email'] if u.is_administrator()]
870886
notify_sets['for_email'] = for_email
887+
log_instant_email(logger, run_id,
888+
'MIN_REP filter reduced recipients '
889+
'from %d to %d for post %d',
890+
original_count, len(for_email), self.id)
871891

872892
if not getattr(django_settings, 'CELERY_TASK_ALWAYS_EAGER', False):
873893
cache_key = 'instant-notification-%d-%d' % (self.thread.id, updated_by.id)
874894
if cache.cache.get(cache_key):
895+
log_instant_email(logger, run_id,
896+
'notification throttled by cache for thread %d',
897+
self.thread.id)
875898
return
876899
cache.cache.set(cache_key, True, django_settings.NOTIFICATION_DELAY_TIME)
877900

878901
from askbot.tasks import send_instant_notifications_about_activity_in_post
879902
from askbot.utils.lists import batch_size as make_batches
880903
recipient_ids = [user.id for user in notify_sets['for_email']]
904+
log_instant_email(logger, run_id, '%d email recipients for post %d',
905+
len(recipient_ids), self.id)
881906
id_batches = make_batches(recipient_ids, const.CELERY_TASK_EMAIL_BATCH_SIZE) if recipient_ids else [[]]
907+
if askbot_settings.DEBUG_EMAIL_ALERTS:
908+
batch_sizes = [len(b) for b in id_batches]
909+
log_instant_email(logger, run_id,
910+
'dispatching %d batches (sizes: %s) for post %d',
911+
len(id_batches), batch_sizes, self.id)
882912
for i, batch in enumerate(id_batches):
883913
defer_celery_task(
884914
send_instant_notifications_about_activity_in_post,
@@ -888,9 +918,14 @@ def issue_update_notifications(self, updated_by=None, notify_sets=None,
888918
batch
889919
),
890920
#include invited mods only in the first batch, to avoid multiple emails to mods
891-
kwargs={'include_invited_moderators': (i == 0)},
921+
kwargs={
922+
'include_invited_moderators': (i == 0),
923+
'run_id': run_id
924+
},
892925
countdown=django_settings.NOTIFICATION_DELAY_TIME
893926
)
927+
log_instant_email(logger, run_id, 'all %d batches dispatched for post %d',
928+
len(id_batches), self.id)
894929

895930
def delete_update_notifications(self, keep_activity):
896931
"""reverse of issue update notifications
@@ -1333,7 +1368,7 @@ def get_global_tag_based_subscribers(self, tag_mark_reason=None,
13331368

13341369
return subscribers
13351370

1336-
def get_global_instant_notification_subscribers(self):
1371+
def get_global_instant_notification_subscribers(self, run_id=None):
13371372
"""returns a set of subscribers to post according to tag filters
13381373
both - subscribers who ignore tags or who follow only
13391374
specific tags
@@ -1378,11 +1413,14 @@ def get_global_instant_notification_subscribers(self):
13781413
tag_mark_reason='bad'
13791414
)
13801415
)
1416+
log_instant_email(logger, run_id,
1417+
'%d global instant notification subscribers for post %d',
1418+
len(subscriber_set), self.id)
13811419
return subscriber_set
13821420

13831421
def _qa__get_instant_notification_subscribers(
13841422
self, potential_subscribers=None, mentioned_users=None,
1385-
exclude_list=None):
1423+
exclude_list=None, run_id=None):
13861424
"""get list of users who have subscribed to
13871425
receive instant notifications for a given post
13881426
@@ -1422,6 +1460,9 @@ def _qa__get_instant_notification_subscribers(
14221460
frequency='i'
14231461
)
14241462
subscriber_set.update(mention_subscribers)
1463+
log_instant_email(logger, run_id,
1464+
'%d mention subscribers for post %d',
1465+
len(mention_subscribers), self.id)
14251466

14261467
origin_post = self.get_origin_post()
14271468

@@ -1437,10 +1478,17 @@ def _qa__get_instant_notification_subscribers(
14371478
frequency='i'
14381479
)
14391480
subscriber_set.update(selective_subscribers)
1481+
log_instant_email(logger, run_id,
1482+
'%d selective subscribers for post %d',
1483+
len(selective_subscribers), self.id)
14401484

14411485
# 3) whole forum subscribers
1442-
global_subscribers = origin_post.get_global_instant_notification_subscribers()
1486+
global_subscribers = origin_post.get_global_instant_notification_subscribers(
1487+
run_id=run_id)
14431488
subscriber_set.update(global_subscribers)
1489+
log_instant_email(logger, run_id,
1490+
'%d global subscribers for post %d',
1491+
len(global_subscribers), self.id)
14441492

14451493
# 4) question asked by me (todo: not "edited_by_me" ???)
14461494
question_author = origin_post.author
@@ -1450,6 +1498,9 @@ def _qa__get_instant_notification_subscribers(
14501498
feed_type='q_ask'
14511499
).exists():
14521500
subscriber_set.add(question_author)
1501+
log_instant_email(logger, run_id,
1502+
'added question author %d as subscriber for post %d',
1503+
question_author.id, self.id)
14531504

14541505
# 4) questions answered by me -make sure is that people
14551506
# are authors of the answers to this question
@@ -1466,12 +1517,19 @@ def _qa__get_instant_notification_subscribers(
14661517
feed_type='q_ans',
14671518
)
14681519
subscriber_set.update(answer_subscribers)
1469-
1470-
return subscriber_set - set(exclude_list)
1520+
log_instant_email(logger, run_id,
1521+
'%d answer-author subscribers for post %d',
1522+
len(answer_subscribers), self.id)
1523+
1524+
result = subscriber_set - set(exclude_list)
1525+
log_instant_email(logger, run_id,
1526+
'%d total qa subscribers for post %d (excluded %d)',
1527+
len(result), self.id, len(exclude_list))
1528+
return result
14711529

14721530
def _comment__get_instant_notification_subscribers(
14731531
self, potential_subscribers=None, mentioned_users=None,
1474-
exclude_list=None):
1532+
exclude_list=None, run_id=None):
14751533
"""get list of users who want instant notifications about comments
14761534
14771535
argument potential_subscribers is required as it saves on db hits
@@ -1504,6 +1562,9 @@ def _comment__get_instant_notification_subscribers(
15041562
feed_type='m_and_c',
15051563
frequency='i')
15061564
subscriber_set.update(comment_subscribers)
1565+
log_instant_email(logger, run_id,
1566+
'%d comment subscribers for post %d',
1567+
len(comment_subscribers), self.id)
15071568

15081569
origin_post = self.get_origin_post()
15091570
# TODO: The line below works only if origin_post is Question !
@@ -1518,26 +1579,43 @@ def _comment__get_instant_notification_subscribers(
15181579
subscriber_set.add(subscriber)
15191580

15201581
subscriber_set.update(selective_subscribers)
1582+
log_instant_email(logger, run_id,
1583+
'%d selective subscribers for comment %d',
1584+
len(selective_subscribers), self.id)
15211585

1522-
global_subscribers = origin_post.get_global_instant_notification_subscribers()
1586+
global_subscribers = origin_post.get_global_instant_notification_subscribers(
1587+
run_id=run_id)
15231588
subscriber_set.update(global_subscribers)
1524-
1525-
return subscriber_set - set(exclude_list)
1589+
log_instant_email(logger, run_id,
1590+
'%d global subscribers for comment %d',
1591+
len(global_subscribers), self.id)
1592+
1593+
result = subscriber_set - set(exclude_list)
1594+
log_instant_email(logger, run_id,
1595+
'%d total comment subscribers for post %d',
1596+
len(result), self.id)
1597+
return result
15261598

15271599
def get_instant_notification_subscribers(
15281600
self, potential_subscribers=None, mentioned_users=None,
1529-
exclude_list=None):
1601+
exclude_list=None, run_id=None):
1602+
log_instant_email(logger, run_id,
1603+
'collecting subscribers for %s post %d',
1604+
self.post_type, self.id)
1605+
15301606
if self.is_question() or self.is_answer():
15311607
subscribers = self._qa__get_instant_notification_subscribers(
15321608
potential_subscribers=potential_subscribers,
15331609
mentioned_users=mentioned_users,
1534-
exclude_list=exclude_list
1610+
exclude_list=exclude_list,
1611+
run_id=run_id
15351612
)
15361613
elif self.is_comment():
15371614
subscribers = self._comment__get_instant_notification_subscribers(
15381615
potential_subscribers=potential_subscribers,
15391616
mentioned_users=mentioned_users,
1540-
exclude_list=exclude_list
1617+
exclude_list=exclude_list,
1618+
run_id=run_id
15411619
)
15421620
elif self.is_tag_wiki() or self.is_reject_reason():
15431621
return set()
@@ -1546,7 +1624,12 @@ def get_instant_notification_subscribers(
15461624

15471625
# if askbot_settings.GROUPS_ENABLED and self.is_effectively_private():
15481626
# for subscriber in subscribers:
1627+
pre_filter_count = len(subscribers)
15491628
subscribers = self.filter_authorized_users(subscribers)
1629+
log_instant_email(logger, run_id,
1630+
'%d subscribers after authorization filter '
1631+
'(was %d) for post %d',
1632+
len(subscribers), pre_filter_count, self.id)
15501633

15511634
# filter subscribers by language
15521635
if askbot.is_multilingual():
@@ -1556,11 +1639,17 @@ def get_instant_notification_subscribers(
15561639
subscriber_languages = subscriber.get_languages()
15571640
if language in subscriber_languages:
15581641
filtered_subscribers.append(subscriber)
1642+
if askbot_settings.DEBUG_EMAIL_ALERTS:
1643+
removed = len(subscribers) - len(filtered_subscribers)
1644+
log_instant_email(logger, run_id,
1645+
'filtered %d of %d subscribers by language %r for post %d',
1646+
removed, len(subscribers), language, self.id)
15591647
return filtered_subscribers
15601648
else:
15611649
return subscribers
15621650

1563-
def get_notify_sets(self, mentioned_users=None, exclude_list=None):
1651+
def get_notify_sets(self, mentioned_users=None, exclude_list=None,
1652+
run_id=None):
15641653
"""returns three lists of users in a dictionary with keys:
15651654
* 'for_inbox' - users for which to add inbox items
15661655
* 'for_mentions' - for whom mentions are added
@@ -1583,7 +1672,14 @@ def get_notify_sets(self, mentioned_users=None, exclude_list=None):
15831672
result['for_email'] = self.get_instant_notification_subscribers(
15841673
potential_subscribers=result['for_inbox'],
15851674
mentioned_users=result['for_mentions'],
1586-
exclude_list=exclude_list)
1675+
exclude_list=exclude_list,
1676+
run_id=run_id)
1677+
log_instant_email(logger, run_id,
1678+
'notify sets for post %d — inbox: %d, mentions: %d, email: %d',
1679+
self.id,
1680+
len(result['for_inbox']),
1681+
len(result['for_mentions']),
1682+
len(result['for_email']))
15871683
return result
15881684

15891685
def cache_latest_revision(self, rev):

0 commit comments

Comments
 (0)