Incidents/2022-09-08 codfw appservers degradation
document status: in-review
Summary
| Incident ID | 2022-09-08 codfw appservers degradation | Start | 2022-09-08 15:18:18 |
|---|---|---|---|
| Task | T317340 | End | 2022-09-08 15:51:18 |
| People paged | 1 | Responder count | 3 |
| Coordinators | claime | Affected metrics/SLOs | Response time and 5xx rate |
| Impact | For 2 minutes, appserver and api_appserver and in Codfw were in a degraded state.
For 16 minutes, parsoid in codfw was in a degraded state. | ||
An Nginx server restart (RC) triggered an etcdmirror outage that started affecting end-users during a subsequent MediaWiki deployment. The etcd outage led to php-fpm not being able to contact its configuration server and failing to restart for the deployment. The appservers got depooled because of the failure until pybal depool protection kicked in. When etcdmirror was restarted to resolve the restart issue, the configuration state with the depooled servers was synchronized, which triggered the depooling of 50% of codfw api-https, api_appserver, appserver, and parsoid servers.
Timeline
All times in UTC.
- 15:11: <wikibugs> (Merged) jenkins-bot [mediawiki-config] - https://gerrit.wikimedia.org/r/830803 (T317025)
- 15:17:21: moritzm updates nginx-light on conf1009, the update triggers a daemon restart (port 4001 on the conf* hosts serves the etcd tlsproxy which is accessed by etcdmirror)
- 15:17:24: conf2005 systemd[1]: etcdmirror-conftool-eqiad-wmnet.service crashes
- 15:17: scap@deploy1002: Start sync-common
- scap.poolcounter.client: "[WARNING] lvs2009:9090 reports pool api-https_443/mw2306.codfw.wmnet as
enabled/up/pooled, should bedisabled/*/not pooled. [ERROR] Error depooling the servers: enabled/up/pooled. [ERROR] Error running command with poolcounter: Failed executing ServiceRunner.run, return code 127"
- scap.poolcounter.client: "[WARNING] lvs2009:9090 reports pool api-https_443/mw2306.codfw.wmnet as
- 15:18:18: claime launches scap sync-file and notices errors
- 15:22:02: <icinga-wm> PROBLEM - etcdmirror-conftool-eqiad-wmnet service on conf2005 is CRITICAL: CRITICAL - Expecting active but unit etcdmirror-conftool-eqiad-wmnet is failed
- 15:23:45: <jinxer-wm> (JobUnavailable) firing: Reduced availability for job etcdmirror in ops@codfw.
- 15:28: scap@deploy1002: End of sync-common (duration: 12m 48s).
- WARNING: 58 hosts had failures restarting php-fpm, 58 hosts had failures restarting php-fpm, 18 hosts had failures restarting php-fpm).
- 15:28:36: jayme notices issues with conf2005/etcdmirror
- 15:33:29: akosiaris restarts etcdmirror
- 15:34:00~: Start of degradation for clients
- 15:38:16: <icinga-wm> PROBLEM - High average GET latency for mw requests on appserver in codfw:
cluster=appserver code=200 handler=proxy:unix:/run/php/fpm-www-7.2.sockhttps://grafana.wikimedia.org/d/RIA1lzDZk/application-servers-red-dashboard?panelId=9&fullscreen&orgId=1&from=now-3h&to=now&var-datasource=codfw+prometheus/ops&var-cluster=appserver&var-method=GET - 15:34:42: _joe_ notices https://config-master.wikimedia.org/pybal/codfw/api-https
- 15:35:36: _joe_ repools api-https
- 15:36:32: _joe_ repools api_appserver
- 15:36:42: _joe_ repools appserver
- 15:36:42~: End of degradation for clients
- 15:50:32: claime repools parsoid
Detection
Write how the issue was first detected. Was automated monitoring first to detect it? Or a human reporting an error?
claime reports errors during scap sync-file, jayme picks up on conf2005/etcdmirror being in a CRITICAL state
Copy the relevant alerts that fired in this section.
15:22:02 +icinga-wm | PROBLEM - etcdmirror-conftool-eqiad-wmnet service on conf2005 is CRITICAL: CRITICAL - Expecting active but unit etcdmirror-conftool-eqiad-wmnet is failed
Did the appropriate alert(s) fire? Was the alert volume manageable? Did they point to the problem with as much accuracy as possible?
Alert fired on IRC but no page went out.
TODO: If human only, an actionable should probably be to "add alerting".
Conclusions
OPTIONAL: General conclusions (bullet points or narrative)
What went well?
- RC very quickly identified due to akosiaris, _joe_, moritzm and jayme being around and correlating very quickly
OPTIONAL: (Use bullet points) for example: automated monitoring detected the incident, outage was root-caused quickly, etc
What went poorly?
- Scap continues deployment even in the face of rising failure rates once canaries are passed.
- Scap doesn't check the status of etcdmirrors before deployment.
- No documentation on what to do with scap deployment in the face of rising failure rates.
- The etcdmirror alert didn't page.
OPTIONAL: (Use bullet points) for example: documentation on the affected service was unhelpful, communication difficulties, etc
Where did we get lucky?
- _joe_ thought to check the pybal config after the etcdmirror restart which allowed very rapid response to the depooling
- pybal depooling protection kicked in
- 5 persons were online to assist and quickly correlated RCA
OPTIONAL: (Use bullet points) for example: user's error report was exceptionally detailed, incident occurred when the most people were online to assist, etc
Links to relevant documentation
- …
Add links to information that someone responding to this alert should have (runbook, plus supporting docs). If that documentation does not exist, add an action item to create it.
Actionables
- Page on etcdmirror alert
- Add etcdmirror connection retry on etcd-tls-proxy unavailability
- Update Etcd/Main cluster#Replication with safe restart conditions and information
- Add etcdmirror status check to scap
- Add failure rate triggered rollback to scap
Create a list of action items that will help prevent this from happening again as much as possible. Link to or create a Phabricator task for every step.
Add the #Sustainability (Incident Followup) and the #SRE-OnFIRE (Pending Review & Scorecard) Phabricator tag to these tasks.
Scorecard
| Question | Answer
(yes/no) |
Notes | |
|---|---|---|---|
| People | Were the people responding to this incident sufficiently different than the previous five incidents? | no | |
| Were the people who responded prepared enough to respond effectively | yes | got lucky | |
| Were fewer than five people paged? | no | no pages -- but we wanted one | |
| Were pages routed to the correct sub-team(s)? | no | ||
| Were pages routed to online (business hours) engineers? Answer “no” if engineers were paged after business hours. | no | no pages | |
| Process | Was the incident status section actively updated during the incident? | no | |
| Was the public status page updated? | no | not warranted | |
| Is there a phabricator task for the incident? | yes | ||
| Are the documented action items assigned? | no | ||
| Is this incident sufficiently different from earlier incidents so as not to be a repeat occurrence? | yes | ||
| Tooling | To the best of your knowledge was the open task queue free of any tasks that would have prevented this incident? Answer “no” if there are
open tasks that would prevent this incident or make mitigation easier if implemented. |
yes | |
| Were the people responding able to communicate effectively during the incident with the existing tooling? | yes | ||
| Did existing monitoring notify the initial responders? | no | irc alert only | |
| Were the engineering tools that were to be used during the incident, available and in service? | yes | ||
| Were the steps taken to mitigate guided by an existing runbook? | no | etcdmirror documentation is spooky | |
| Total score (count of all “yes” answers above) | 6 | ||