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); }