private object ProcessNotification(IMessage <EventNotification> message)
{
int emailsSent = 0;
EventNotification data = message.GetBody();
Log.Trace().Message("Process notification: project={0} event={1} stack={2}", data.Event.ProjectId, data.Event.Id, data.Event.StackId).Write();
var project = _projectRepository.GetByIdCached(data.Event.ProjectId);
if (project == null)
{
Log.Error().Message("Could not load project {0}.", data.Event.ProjectId).Write();
return(null);
}
Log.Trace().Message("Loaded project: name={0}", project.Name).Write();
var organization = _organizationRepository.GetByIdCached(project.OrganizationId);
if (organization == null)
{
Log.Error().Message("Could not load organization {0}.", project.OrganizationId).Write();
return(null);
}
Log.Trace().Message("Loaded organization: name={0}", organization.Name).Write();
var stack = _stackRepository.GetById(data.Event.StackId);
if (stack == null)
{
Log.Error().Message("Could not load stack {0}.", data.Event.StackId).Write();
return(null);
}
if (!organization.HasPremiumFeatures)
{
Log.Trace().Message("Skipping because organization does not have premium features.").Write();
return(null);
}
if (stack.DisableNotifications || stack.IsHidden)
{
Log.Trace().Message("Skipping because stack notifications are disabled or it's hidden.").Write();
return(null);
}
Log.Trace().Message("Loaded stack: title={0}", stack.Title).Write();
int totalOccurrences = stack.TotalOccurrences;
// after the first 5 occurrences, don't send a notification for the same stack more then once every 15 minutes
var lastTimeSent = _cacheClient.Get <DateTime>(String.Concat("NOTIFICATION_THROTTLE_", data.Event.StackId));
if (totalOccurrences > 5 && !data.IsRegression && lastTimeSent != DateTime.MinValue &&
lastTimeSent > DateTime.Now.AddMinutes(-15))
{
Log.Info().Message("Skipping message because of throttling: last sent={0} occurrences={1}", lastTimeSent, totalOccurrences).Write();
return(null);
}
foreach (var kv in project.NotificationSettings)
{
var settings = kv.Value;
Log.Trace().Message("Processing notification: user={0}", kv.Key).Write();
var user = _userRepository.GetById(kv.Key);
if (user == null || String.IsNullOrEmpty(user.EmailAddress))
{
Log.Error().Message("Could not load user {0} or blank email address {1}.", kv.Key, user != null ? user.EmailAddress : "").Write();
continue;
}
if (!user.IsEmailAddressVerified)
{
Log.Info().Message("User {0} with email address {1} has not been verified.", kv.Key, user != null ? user.EmailAddress : "").Write();
continue;
}
if (!user.EmailNotificationsEnabled)
{
Log.Trace().Message("User {0} with email address {1} has email notifications disabled.", kv.Key, user != null ? user.EmailAddress : "").Write();
continue;
}
if (!user.OrganizationIds.Contains(project.OrganizationId))
{
// TODO: Should this notification setting be deleted?
Log.Error().Message("Unauthorized user: project={0} user={1} organization={2} event={3}", project.Id, kv.Key,
project.OrganizationId, data.Event.Id).Write();
continue;
}
Log.Trace().Message("Loaded user: email={0}", user.EmailAddress).Write();
bool shouldReportOccurrence = settings.Mode != NotificationMode.None;
bool shouldReportCriticalError = settings.ReportCriticalErrors && data.IsCritical;
bool shouldReportRegression = settings.ReportRegressions && data.IsRegression;
Log.Trace().Message("Settings: mode={0} critical={1} regression={2} 404={3} bots={4}",
settings.Mode, settings.ReportCriticalErrors,
settings.ReportRegressions, settings.Report404Errors,
settings.ReportKnownBotErrors).Write();
Log.Trace().Message("Should process: occurrence={0} critical={1} regression={2}",
shouldReportOccurrence, shouldReportCriticalError,
shouldReportRegression).Write();
if (settings.Mode == NotificationMode.New && !data.IsNew)
{
shouldReportOccurrence = false;
Log.Trace().Message("Skipping because message is not new.").Write();
}
// check for 404s if the user has elected to not report them
if (shouldReportOccurrence && settings.Report404Errors == false && data.Event.IsNotFound)
{
shouldReportOccurrence = false;
Log.Trace().Message("Skipping because message is 404.").Write();
}
var requestInfo = data.Event.GetRequestInfo();
// check for known bots if the user has elected to not report them
if (shouldReportOccurrence && settings.ReportKnownBotErrors == false &&
requestInfo != null && !String.IsNullOrEmpty(requestInfo.UserAgent))
{
ClientInfo info = null;
try {
info = Parser.GetDefault().Parse(requestInfo.UserAgent);
} catch (Exception ex) {
Log.Warn().Project(data.Event.ProjectId).Message("Unable to parse user agent {0}. Exception: {1}",
requestInfo.UserAgent, ex.Message).Write();
}
if (info != null && info.Device.IsSpider)
{
shouldReportOccurrence = false;
Log.Trace().Message("Skipping because message is bot.").Write();
}
}
// stack being set to send all will override all other settings
if (!shouldReportOccurrence && !shouldReportCriticalError && !shouldReportRegression)
{
continue;
}
// don't send notifications in non-production mode to email addresses that are not on the outbound email list.
if (Settings.Current.WebsiteMode != WebsiteMode.Production &&
!Settings.Current.AllowedOutboundAddresses.Contains(v => user.EmailAddress.ToLowerInvariant().Contains(v)))
{
Log.Trace().Message("Skipping because email is not on the outbound list and not in production mode.").Write();
continue;
}
Log.Trace().Message("Sending email to {0}...", user.EmailAddress).Write();
_mailer.SendNotice(user.EmailAddress, data);
emailsSent++;
Log.Trace().Message("Done sending email.").Write();
}
// if we sent any emails, mark the last time a notification for this stack was sent.
if (emailsSent > 0)
{
_cacheClient.Set(String.Concat("NOTIFICATION_THROTTLE_", data.Event.StackId), DateTime.Now, DateTime.Now.AddMinutes(15));
}
return(null);
}
protected async override Task <JobResult> RunInternalAsync(CancellationToken token)
{
QueueEntry <EventNotification> queueEntry = null;
try {
queueEntry = _queue.Dequeue();
} catch (Exception ex) {
if (!(ex is TimeoutException))
{
return(JobResult.FromException(ex, "An error occurred while trying to dequeue the next EventNotification: {0}", ex.Message));
}
}
if (queueEntry == null)
{
return(JobResult.Success);
}
var eventNotification = queueEntry.Value;
bool shouldLog = eventNotification.Event.ProjectId != Settings.Current.InternalProjectId;
int emailsSent = 0;
Log.Trace().Message("Process notification: project={0} event={1} stack={2}", eventNotification.Event.ProjectId, eventNotification.Event.Id, eventNotification.Event.StackId).WriteIf(shouldLog);
var project = _projectRepository.GetById(eventNotification.Event.ProjectId, true);
if (project == null)
{
queueEntry.Abandon();
return(JobResult.FailedWithMessage("Could not load project {0}.", eventNotification.Event.ProjectId));
}
Log.Trace().Message("Loaded project: name={0}", project.Name).WriteIf(shouldLog);
var organization = _organizationRepository.GetById(project.OrganizationId, true);
if (organization == null)
{
queueEntry.Abandon();
return(JobResult.FailedWithMessage("Could not load organization {0}.", project.OrganizationId));
}
Log.Trace().Message("Loaded organization: name={0}", organization.Name).WriteIf(shouldLog);
var stack = _stackRepository.GetById(eventNotification.Event.StackId);
if (stack == null)
{
queueEntry.Abandon();
return(JobResult.FailedWithMessage("Could not load stack {0}.", eventNotification.Event.StackId));
}
if (!organization.HasPremiumFeatures)
{
queueEntry.Complete();
Log.Info().Message("Skipping \"{0}\" because organization \"{1}\" does not have premium features.", eventNotification.Event.Id, eventNotification.Event.OrganizationId).WriteIf(shouldLog);
return(JobResult.Success);
}
if (stack.DisableNotifications || stack.IsHidden)
{
queueEntry.Complete();
Log.Info().Message("Skipping \"{0}\" because stack \"{1}\" notifications are disabled or stack is hidden.", eventNotification.Event.Id, eventNotification.Event.StackId).WriteIf(shouldLog);
return(JobResult.Success);
}
if (token.IsCancellationRequested)
{
queueEntry.Abandon();
return(JobResult.Cancelled);
}
Log.Trace().Message("Loaded stack: title={0}", stack.Title).WriteIf(shouldLog);
int totalOccurrences = stack.TotalOccurrences;
// after the first 2 occurrences, don't send a notification for the same stack more then once every 30 minutes
var lastTimeSent = _cacheClient.Get <DateTime>(String.Concat("notify:stack-throttle:", eventNotification.Event.StackId));
if (totalOccurrences > 2 &&
!eventNotification.IsRegression &&
lastTimeSent != DateTime.MinValue &&
lastTimeSent > DateTime.Now.AddMinutes(-30))
{
queueEntry.Complete();
Log.Info().Message("Skipping message because of stack throttling: last sent={0} occurrences={1}", lastTimeSent, totalOccurrences).WriteIf(shouldLog);
return(JobResult.Success);
}
// don't send more than 10 notifications for a given project every 30 minutes
var projectTimeWindow = TimeSpan.FromMinutes(30);
string cacheKey = String.Concat("notify:project-throttle:", eventNotification.Event.ProjectId, "-", DateTime.UtcNow.Floor(projectTimeWindow).Ticks);
long notificationCount = _cacheClient.Increment(cacheKey, 1, projectTimeWindow);
if (notificationCount > 10 && !eventNotification.IsRegression)
{
queueEntry.Complete();
Log.Info().Project(eventNotification.Event.ProjectId).Message("Skipping message because of project throttling: count={0}", notificationCount).WriteIf(shouldLog);
return(JobResult.Success);
}
if (token.IsCancellationRequested)
{
queueEntry.Abandon();
return(JobResult.Cancelled);
}
foreach (var kv in project.NotificationSettings)
{
var settings = kv.Value;
Log.Trace().Message("Processing notification: user={0}", kv.Key).WriteIf(shouldLog);
var user = _userRepository.GetById(kv.Key);
if (user == null || String.IsNullOrEmpty(user.EmailAddress))
{
Log.Error().Message("Could not load user {0} or blank email address {1}.", kv.Key, user != null ? user.EmailAddress : "").Write();
continue;
}
if (!user.IsEmailAddressVerified)
{
Log.Info().Message("User {0} with email address {1} has not been verified.", kv.Key, user != null ? user.EmailAddress : "").WriteIf(shouldLog);
continue;
}
if (!user.EmailNotificationsEnabled)
{
Log.Info().Message("User {0} with email address {1} has email notifications disabled.", kv.Key, user != null ? user.EmailAddress : "").WriteIf(shouldLog);
continue;
}
if (!user.OrganizationIds.Contains(project.OrganizationId))
{
Log.Error().Message("Unauthorized user: project={0} user={1} organization={2} event={3}", project.Id, kv.Key, project.OrganizationId, eventNotification.Event.Id).Write();
continue;
}
Log.Trace().Message("Loaded user: email={0}", user.EmailAddress).WriteIf(shouldLog);
bool shouldReportNewError = settings.ReportNewErrors && eventNotification.IsNew && eventNotification.Event.IsError();;
bool shouldReportCriticalError = settings.ReportCriticalErrors && eventNotification.IsCritical && eventNotification.Event.IsError();;
bool shouldReportRegression = settings.ReportEventRegressions && eventNotification.IsRegression;
bool shouldReportNewEvent = settings.ReportNewEvents && eventNotification.IsNew;
bool shouldReportCriticalEvent = settings.ReportCriticalEvents && eventNotification.IsCritical;
bool shouldReport = shouldReportNewError || shouldReportCriticalError || shouldReportRegression || shouldReportNewEvent || shouldReportCriticalEvent;
Log.Trace().Message("Settings: newerror={0} criticalerror={1} regression={2} new={3} critical={4}",
settings.ReportNewErrors, settings.ReportCriticalErrors,
settings.ReportEventRegressions, settings.ReportNewEvents, settings.ReportCriticalEvents).WriteIf(shouldLog);
Log.Trace().Message("Should process: newerror={0} criticalerror={1} regression={2} new={3} critical={4}",
shouldReportNewError, shouldReportCriticalError,
shouldReportRegression, shouldReportNewEvent, shouldReportCriticalEvent).WriteIf(shouldLog);
var requestInfo = eventNotification.Event.GetRequestInfo();
// check for known bots if the user has elected to not report them
if (shouldReport && requestInfo != null && !String.IsNullOrEmpty(requestInfo.UserAgent))
{
ClientInfo info = null;
try {
info = Parser.GetDefault().Parse(requestInfo.UserAgent);
} catch (Exception ex) {
Log.Warn().Project(eventNotification.Event.ProjectId).Message("Unable to parse user agent {0}. Exception: {1}",
requestInfo.UserAgent, ex.Message).Write();
}
var botPatterns = project.Configuration.Settings.ContainsKey(SettingsDictionary.KnownKeys.UserAgentBotPatterns)
? project.Configuration.Settings.GetStringCollection(SettingsDictionary.KnownKeys.UserAgentBotPatterns).ToList()
: new List <string>();
if (info != null && info.Device.IsSpider || requestInfo.UserAgent.AnyWildcardMatches(botPatterns))
{
shouldReport = false;
Log.Info().Message("Skipping because event is from a bot \"{0}\".", requestInfo.UserAgent).WriteIf(shouldLog);
}
}
if (!shouldReport)
{
continue;
}
var model = new EventNotificationModel(eventNotification)
{
ProjectName = project.Name,
TotalOccurrences = totalOccurrences
};
// don't send notifications in non-production mode to email addresses that are not on the outbound email list.
if (Settings.Current.WebsiteMode != WebsiteMode.Production &&
!Settings.Current.AllowedOutboundAddresses.Contains(v => user.EmailAddress.ToLowerInvariant().Contains(v)))
{
Log.Info().Message("Skipping because email is not on the outbound list and not in production mode.").WriteIf(shouldLog);
continue;
}
Log.Trace().Message("Sending email to {0}...", user.EmailAddress).Write();
_mailer.SendNotice(user.EmailAddress, model);
emailsSent++;
Log.Trace().Message("Done sending email.").WriteIf(shouldLog);
}
// if we sent any emails, mark the last time a notification for this stack was sent.
if (emailsSent > 0)
{
_cacheClient.Set(String.Concat("notify:stack-throttle:", eventNotification.Event.StackId), DateTime.Now, DateTime.Now.AddMinutes(15));
Log.Info().Message("Notifications sent: event={0} stack={1} count={2}", eventNotification.Event.Id, eventNotification.Event.StackId, emailsSent).WriteIf(shouldLog);
}
queueEntry.Complete();
return(JobResult.Success);
}
