Page MenuHomePhabricator

[WD-ORG] [TECH] Max Lag alerts misfire with a DataSource error
Closed, ResolvedPublic

Description

For some time now (since August 30th 2023), alerts related to Max Lag have been firing once every couple of days with the following message:

image.png (617×639 px, 73 KB)

Error = [plugin.downstreamError] failed to query data: request failed, status: 503 Service Unavailable

These alerts are then resolved after a few minutes. However, this poses a problem since these false positives can detract from actual issues, as seen in September 27th when an actual alert was missed.

Acceptance Criteria

Event Timeline

ItamarWMDE renamed this task from [WD-ORG] Max Lag alerts misfire with a DataSource error to [WD-ORG] [TECH] Max Lag alerts misfire with a DataSource error.Oct 13 2023, 7:02 AM
  • Task review notes:**
  • As mentioned in T349178, these two issues might be related.

Task Prio Notes:

  • Does not affect end users /production
  • Affects monitoring
  • Does not affect development efforts
  • Does not affect onboarding efforts
  • Might affect additional stakeholders (Rest of LOD, SREs, General spam)
ItamarWMDE renamed this task from [WD-ORG] [TECH] Max Lag alerts misfire with a DataSource error to [SW] [WD-ORG] [TECH] Max Lag alerts misfire with a DataSource error.Oct 24 2023, 1:56 PM
ItamarWMDE moved this task from [DOT] By Project to [DOT] Prioritized on the wmde-wikidata-tech board.
Lucas_Werkmeister_WMDE updated the task description. (Show Details)

(from duplicate task T350255 which I filed because this one wasn’t findable via search)

Thank you for reaching out @Lucas_Werkmeister_WMDE ! Yes indeed known issue, we (o11y) recommend turning off notifications for datasource errors (full rationale in https://phabricator.wikimedia.org/T347221#9264101) and the instructions being at https://wikitech.wikimedia.org/wiki/Grafana#DatasourceError_notification_spam

Sounds promising, thanks @fgiunchedi!

ItamarWMDE renamed this task from [SW] [WD-ORG] [TECH] Max Lag alerts misfire with a DataSource error to [WD-ORG] [TECH] Max Lag alerts misfire with a DataSource error.Nov 8 2023, 11:46 AM
ItamarWMDE updated the task description. (Show Details)

Done based on the instructions at https://wikitech.wikimedia.org/wiki/Grafana#DatasourceError_notification_spam: Go to https://grafana.wikimedia.org/alerting/grafana/WF0KICJVz/view based on one of the alert emails, and manually edit the URL to -rw (https://grafana-rw.wikimedia.org/alerting/grafana/WF0KICJVz/view); edit; scroll up to step 3; unfold “Configure no data and error handling”; set “Alert state if execution error or timeout” from “Error” to “OK”; save and exit.

Let’s see if it works… I guess we just leave this in tech verification for a while and then see how many alerts we got over a few weeks or so?

I’ve also gone ahead and applied this change to DispatchChanges Normal job backlog time (where the “Alert state if execution error or timeout” was previously set to “Alerting” rather than “Error” as above, no idea if that’s significant).

Just got another email about DispatchChanges Normal job backlog time (p50, 15min).

grafana_state_reason = NoData
message = DispatchChanges job p50 backlog is over 10 minutes! Normal values are between 0.5s and 1s

@fgiunchedi: should “Alert state if no data or all values are null” also be changed to “OK”?

image.png (357×145 px, 9 KB)

For most cases I think alerting on "no data" and "values are all null" is sensible, in other words you expect to have data returned by the query at all times.

In this case I can't quite figure out why the alert went "no data"; I've searched grafana logs for the rule uid though

Nov 23 16:10:07 grafana1002 grafana[18790]: logger=ngalert.sender.router rule_uid=MF0FSjJ4z org_id=1 t=2023-11-23T16:10:06.999230004Z level=info msg="Sending alerts to local notifier" count=1
Nov 23 16:12:07 grafana1002 grafana[18790]: logger=ngalert.sender.router rule_uid=MF0FSjJ4z org_id=1 t=2023-11-23T16:12:07.2677782Z level=info msg="Sending alerts to local notifier" count=1
Nov 23 16:14:04 grafana1002 grafana[18790]: logger=ngalert.state.manager rule_uid=MF0FSjJ4z org_id=1 t=2023-11-23T16:14:04.878943734Z level=info msg="Detected stale state entry" cacheID="[[\"__alert_rule_namespace_uid__\",\"k0zbgDsik\"],[\"__alert_rule_uid__\",\"MF0FSjJ4z\"],[\"__contacts__\",\"\\\"AlertManager\\\"\"],[\"alertname\",\"DispatchChanges Normal job backlog time (p50, 15min) alert\"],[\"datasource_uid\",\"000000026\"],[\"grafana_folder\",\"Wikidata\"],[\"ref_id\",\"A\"],[\"rule_uid\",\"MF0FSjJ4z\"],[\"severity\",\"critical\"],[\"team\",\"wikidata\"]]" state=Alerting reason=NoData
Nov 23 16:14:04 grafana1002 grafana[18790]: logger=ngalert.sender.router rule_uid=MF0FSjJ4z org_id=1 t=2023-11-23T16:14:04.904922823Z level=info msg="Sending alerts to local notifier" count=1

It fired (and resolved) four times yesterday afternoon btw: ca. 13:47, 14:47, 14:52 and 16:10 (all UTC; grafana_state_reason = NoData each time).

I wonder if it would make sense to change the query from “now-5m to now” to “now-6m to now-1m”? I don’t think we usually respond within a minute anyway. (But I don’t know if that would make NoData conditions less likely.)

If we can’t figure out how to fix this, then IMHO we should change the alert state if no data, because otherwise this still contributes to training Wikidata developers to ignore the alerts.

It fired (and resolved) four times yesterday afternoon btw: ca. 13:47, 14:47, 14:52 and 16:10 (all UTC; grafana_state_reason = NoData each time).

I wonder if it would make sense to change the query from “now-5m to now” to “now-6m to now-1m”? I don’t think we usually respond within a minute anyway. (But I don’t know if that would make NoData conditions less likely.)

Maybe even more, this recommends 15 minutes: https://wikitech.wikimedia.org/wiki/Grafana/Best_practices#Alert_rules

And given that we actually alert when the delay is over 1 hour, it means that this is already ongoing for a while. Whether we are informed about it at 1:05 or 1:15 after the problems started should not make a big difference.

Also, this is now tackling T349178: [C-DIS] [TECH] "DispatchChanges Normal job backlog time (p50, 15min)" alert misfires with "No Data", right?

I guess so, yeah – I didn’t realize these were different. Perhaps we can move the discussion there, then.

FWIW I agree with testing the different boundaries, especially as you pointed out the alert is lax in terms of "reactivity"

Let’s see if it works… I guess we just leave this in tech verification for a while and then see how many alerts we got over a few weeks or so?

Yeah, It's already been about three weeks, I'll give it until I'm back in mid-January to be extra sure, but so far so good.