<!-- ISSUE TITLING: use the form "YYYY-MM-DD: briefly describe problem" --> <!-- ISSUE LABELING: Don't forget to add labels for severity (severity::1 - severity::4) and service. if the incident relates to sensitive data, or is security related use the label ~security and mark it confidential. --> ## Summary Current State: GitLab.com is up. Database load spiked and this has dramatically increased error rates and degraded times on responses. [Automatic re-indexing](https://gitlab.com/gitlab-com/gl-infra/production/-/issues/2849) was enabled over the weekend. A re-index of the routes table changed the statistics on the table. This resulted in much less efficient queries there. A manual re-analyze of the table fixed the issue. The automatic re-indexing has been disabled. Outage from 2020-10-24 09:16 to 10:25. ## Timeline All times UTC. 2020-10-24 - 09:12 - starting to [reindex](https://gitlab.com/gitlab-com/gl-infra/production/-/issues/2849) `index_on_routes_lower_path` - 09:14 - swapped old and new index by name, deleting old index. This is causing table statistics to be off and makes queries slow. - 09:15 - starting to get alerts and pages all over the place - 09:19 - hphilipps declares incident in Slack using `/incident declare` command, paging IMOC and CMOC. - 09:32 - Escalated to IMOC again. - 09:32 - graphs https://dashboards.gitlab.net/d/patroni-main/patroni-overview?orgId=1 - 09:46 - looking at https://log.gprd.gitlab.net/goto/50cd8288ecda46c79ddf7b605795cbeb Looks like a hug of death, not an attack. A user is deleting a large number of tags - 09:51 - started by trying to block particular URL deleting tags, but now blocking entire identified network which is sending troublesome requests. (Turns out as not related later.) - 10:05 - DB load is low, but pg_bouncer_sync_replica_pool saturation is 100% - Looking into pg_bouncer - https://dashboards.gitlab.net/d/pgbouncer-main/pgbouncer-overview?orgId=1 - jwtController - main stage has a lot of timeouts - looking at blocking - Will affect registry - 10:19 - the block to jwt_auth appears to have made a difference. - Things in pg_bouncer/patroni appear to be recovering. - 10:21 - removing initial project and IP block as they did not appear to make a difference. Leaving block on jwt_auth - 10:54 - suspecting automatic reindexing to have caused the issue, disabling the feature flag: `/chatops run feature set database_reindexing false` - 11:08 - found that a rerun of statistics on the route table changed the query plan - 11:12 - removed the temporary blocks of request paths that were related to the issues. - 11:20 - all traffic is operating normally <!-- THE BELOW IS TO BE CONDUCTED ONCE THE ABOVE INCIDENT IS MITIGATED. TRANSFER DATA FROM THE ABOVE INTO THE INCIDENT REVIEW SECTIONS BELOW. --> <br/> <h2>Incident Review</h2> </summary> <!-- The purpose of this Incident Review is to serve as a classroom to help us better understand the root causes of an incident. Treating it as a classroom allows us to create the space to let us focus on devising the mechanisms needed to prevent a similar incident from recurring in the future. A root cause can **never be a person** and this Incident Review should be written to refer to the system and the context rather than the specific actors. As placeholders for names, consider the usage of nouns like "technician", "engineer on-call", "developer", etc.. --> ## Summary <!-- _A brief summary of what happened. Try to make it as executive-friendly as possible._ _example: For a period of 19 minutes (between 2020-05-01 12:00 UTC and 2020-05-01 12:19 UTC), GitLab.com experienced a drop in traffic to the database. 507 customers saw 2,342 503 errors over this 19 minute period. The underlying cause has been determined to be a change to the PgBouncer configuration (https://gitlab.com/gitlab-com/gl-infra/production/-/issues/XXXX) which caused the total number of connections to be reduced to 50. This incident was then mitigated by rolling back this PgBouncer configuration change. --> An automatic [DB re-indexing cronjob](https://gitlab.com/gitlab-org/gitlab/-/issues/249662), which [was enabled this weekend](https://gitlab.com/gitlab-com/gl-infra/production/-/issues/2849), lead to missing table statistics for an important index which made all queries related to that index very inefficient, slowing down the whole database. This caused an APDEX drop to around 50% for most services between 09:16 to 10:25 UTC (69 minutes) and for the container registry service until 11:20 (124 minutes). 1. Service(s) affected: **All services depending on the DB** 1. Team attribution: @gitlab-org/database-team 1. Minutes downtime or degradation: 69 minutes (124 minutes for container registry) <!-- _For calculating duration of event, use the [Platform Metrics Dashboard](https://dashboards.gitlab.net/d/general-triage/general-platform-triage?orgId=1) to look at appdex and SLO violations._ --> ## Metrics <!-- _Provide any relevant graphs that could help understand the impact of the incident and its dynamics._ -->  [Grafana](https://dashboards.gitlab.net/d/general-triage/general-platform-triage?orgId=1&from=1603524815214&to=1603541673893) For Container Registry:  [Grafana](https://dashboards.gitlab.net/d/registry-main/registry-overview?viewPanel=7&orgId=1&from=1603524815000&to=1603541673000&var-PROMETHEUS_DS=Global&var-environment=gprd&var-stage=main&var-sigma=2) ## Customer Impact 1. Who was impacted by this incident? 1. All users 2. What was the customer experience during the incident? 1. Very slow response or 500 errors 3. How many customers were affected? 4. If a precise customer impact number is unknown, what is the estimated potential impact? 1. API requests dropped to 50% ([Grafana](https://dashboards.gitlab.net/d/api-main/api-overview?orgId=1&viewPanel=7&from=1603522441127&to=1603548135244&var-PROMETHEUS_DS=Global&var-environment=gprd&var-stage=main&var-sigma=2)), Web requests dropped by 75% ([Grafana](https://dashboards.gitlab.net/d/web-main/web-overview?orgId=1&viewPanel=7&from=1603523055599&to=1603544620305&var-PROMETHEUS_DS=Global&var-environment=gprd&var-stage=main&var-sigma=2)), CI [job requests](https://dashboards.gitlab.net/d/000000159/ci?orgId=1&from=1603515571930&to=1603550324405&var-runner_type=All&var-runner_managers=All&var-gitlab_env=gprd&var-gl_monitor_fqdn=All&var-has_minutes=yes&var-runner_job_failure_reason=All&var-jobs_running_for_project=0&var-runner_request_endpoint_status=All&viewPanel=91) dropped by 50% and [job durations](https://dashboards.gitlab.net/d/000000159/ci?orgId=1&from=1603515571930&to=1603550324405&var-runner_type=All&var-runner_managers=All&var-gitlab_env=gprd&var-gl_monitor_fqdn=All&var-has_minutes=yes&var-runner_job_failure_reason=All&var-jobs_running_for_project=0&var-runner_request_endpoint_status=All&viewPanel=143) got very high. ## Incident Response Analysis 1. How was the event detected? 1. EOC got paged for increased backend error rates and Pingdom check failing. 2. How could detection time be improved? 1. Detection worked well. 3. How did we reach the point where we knew how to mitigate the impact? 1. After checking CloudFlare traffic and if we had a DB failover we started spending time looking for abusive requests and identifying responsible controllers. The pgbouncer dashboard [controller panel](https://dashboards.gitlab.net/d/pgbouncer-main/pgbouncer-overview?orgId=1&viewPanel=62&from=1603530600000&to=1603531800000&var-PROMETHEUS_DS=Global&var-environment=gprd&var-sigma=2) and analysis of the dominating slow queries by OnGres helped us to identify and block the `/jwt/auth` endpoint as the main producer of DB load as a first mitigation. As @abrandl had informed the EOC about enabling the re-indexing cronjob the prior day (and it was mentioned in the oncall handover), we started to suspect a possible correlation and started looking into that. Checking the re-indexing cron job logs, @ahegyi and @jacobvosmaer-gitlab found that the index `index_on_routes_lower_path` just had been re-indexed when the incident started and OnGres confirmed that the query plan for the slow query stopped using the index because of missing statistics which made those queries very inefficient. OnGres finally fixed that by running `ANALYZE` on the index and we disabled the re-index feature flag to prevent further events. 4. How could time to mitigation be improved? 1. Better documentation on how to page OnGres. 1. Improvements and training on how to interpret slow queries and connect them to controllers and endpoints. 1. Alert if only a few queries are dominating the DB request times ## Post Incident Analysis 1. How was the root cause diagnosed? 1. See above. 2. How could time to diagnosis be improved? 1. See above. 3. Do we have an existing backlog item that would've prevented or greatly reduced the impact of this incident? 1. https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/9354 4. Was this incident triggered by a change (deployment of code or change to infrastructure. _If yes, have you linked the issue which represents the change?_)? 1. Yes, https://gitlab.com/gitlab-com/gl-infra/production/-/issues/2849 ## 5 Whys 1. GitLab.com was down, why? - DB requests have been very slow. 1. Why were DB requests so slow? - Because a functional index had missing statistics leading to a bad query plan. 1. Why was the index missing statistics? - Because an [automatic re-indexing job](https://gitlab.com/gitlab-com/gl-infra/production/-/issues/2849) was re-creating the index and swapping the new with the old index, but for functional indices this is leading to missing statistics without running `ANALYZE` immediately. 1. Why didn't we run `ANALYZE` during the automated re-indexing? - Because for normal indices (the majority) this isn't needed - only for functional indices (we have very few of them) and this [isn't documented in the postgres documentation](https://www.postgresql.org/message-id/flat/CAFcNs%2BqpFPmiHd1oTXvcPdvAHicJDA9qBUSujgAhUMJyUMb%2BSA%40mail.gmail.com) and so was [overlooked by all reviewers](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/39245). 1. Why didn't we catch this in tests? - The reindexing job in staging was running without issues for a few days already, but as indices are selected randomly, there is a high chance that it didn't hit a functional index so far and going through all indices would have taken many weeks. We all had the assumption that if it works for some indices, that it also will work for the rest. <!-- _This section is meant to dig into lessons learned and corrective actions, it is not limited to 5 and consider how you may dive deeper into each why_ _example:_ 1. Customers experienced an inability to create new projects on GitLab.com, why? - A code change was deployed which contained an escaped bug. 1. Why did this bug not get noticed in staging? - The integration test for this use case is missing. 1. Why is an integration test for this use case missing? - It was inadvertently removed during a refactoring of our test suite. 1. Why was the test suite being refactored? - As part of our efforts to decrease MTTP. 1. Why did it take 2 hours to notice this issue in production? - The initial alert was supressed as a false alarm. 1. Why was this alert suppressed - The system which dedupes alerts inadvertently suppressed this alarm as a duplicate. 1. Why did it take 4 hours to resolve the issue in production? - The change which carried this escaped bug also contained a database schema change which made rolling the change back impossible. Engineering was engaged immediately by the oncall SRE and conducted a forward fix. --> ## Lessons Learned <!-- _Be explicit about what lessons we learned and should carry forward. These usually inform what our corrective actions should be._ _example:_ 1. The results of refactoring activites around our integration tests should be reviewed. (i.e we had 619 tests before refactor but 618 after.) 2. Our tooling to dedupe alarms should have integration tests to ensure it works against existing and newly added alarms. --> 1. Technical: Functional ("expression") indexes require explicitly building statistics, which is a relevant learning for both reindexing https://gitlab.com/gitlab-org/gitlab/-/issues/272997 and regular database migrations https://gitlab.com/gitlab-org/gitlab/-/issues/272992. ## Corrective Actions <!-- - _Use Lessons Learned as a guideline for creation of Corrective Actions - _List issues that have been created as corrective actions from this incident._ - _For each issue, include the following:_ - _<Bare Issue link> - Issue labeled as ~"corrective action"._ - _Include an estimated date of completion of the corrective action._ - _Include the named individual who owns the delivery of the corrective action._ --> 1. [x] Update change management to increase the criticality of SQL scripts (via cron or manually) from C4 to C2. - https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11723 1. [ ] Make it easier to find documentation on how to page OnGres: https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11770 1. [ ] Improvements and training on how to interpret slow queries and connect them to controllers and endpoints. https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11787 1. [ ] Have DB re-index cron job add annotations to grafana when it has finished a re-index on a table. https://gitlab.com/gitlab-org/gitlab/-/issues/273198 1. [ ] Alert if small set of queries dominates postgres. https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11794 1. [ ] Include statements in elastic postgres logs for better debugging. https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11795 1. [ ] production-like test-env for DB performance regressions. https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11797 1. [ ] For discussion: When enabling a new higher risk(DB or new feature), set up a shadow rotation https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11802 1. [ ] Remove extra and temporary index in staging to better align envs https://gitlab.com/gitlab-com/gl-infra/infrastructure/-/issues/11868 ## Guidelines - [Blameless RCA Guideline](https://about.gitlab.com/handbook/customer-success/professional-services-engineering/workflows/internal/root-cause-analysis.html#meeting-purpose)