{"id":"IL-0311","org":"BattleMetrics","date":"2022-03-27","docs":["https://blog.sentry.io/2015/07/23/transaction-id-wraparound-in-postgres","https://devcenter.heroku.com/articles/postgresql-concurrency","https://dataegret.com/2017/10/deep-dive-into-postgres-stats-pg_stat_progress_vacuum/","https://blog.crunchydata.com/blog/managing-transaction-id-wraparound-in-postgresql","https://cloud.google.com/sql/docs/postgres/txid-wraparound"],"title":{"en":"BattleMetrics' primary PostgreSQL went read-only at transaction ID wraparound, breaking the website and RCON updates","ko":"주 PostgreSQL 데이터베이스가 트랜잭션 ID wraparound 보호로 읽기 전용이 되어 웹사이트와 백엔드 서비스가 멈췄다"},"domain":["database"],"impact":{"scope":"The website, API and backend services that need Postgres, including RCON updates and queries; RCON updates ran heavily delayed for hours after the database was repaired","users":"BattleMetrics users; most servers kept RCON delay below 5 minutes on average, larger servers saw up to two hours","region":"unknown"},"review":{"written_by":"session","reviewed_at":null,"reviewed_by":null},"lessons":{"en":"BattleMetrics names skipping health checks on transaction ID size as its critical mistake: the index corruption silently broke vacuum for a month, and without monitoring of transaction IDs nobody saw the database approach wraparound. Because the corruption had been replicated to the replicas, failing over did not help, and the backup servers and downloadable backups carried the same corruption. The team also found that, contrary to the error message, a full vacuum on a server in wraparound protection does not need single-user mode, and chose to run a slow, delayed service over no service while replicas were rebuilt.","ko":"BattleMetrics 는 Postgres 의 트랜잭션 ID 크기를 확인하는 헬스 체크를 두지 않은 것을 결정적인 실수로 보았다. 인덱스 손상은 사이트 성능에 영향이 없어 한 달 동안 드러나지 않았고, 그동안 vacuum 이 계속 실패하며 데이터베이스가 wraparound 에 다가갔다. 손상은 replica 에도 복제돼 있어 장애 조치가 소용없었고, 백업 서버와 내려받기용 백업도 같은 손상을 안고 있었다. 오류 문구와 달리 wraparound 보호에 들어간 서버에서도 single-user mode 없이 전체 vacuum 을 돌릴 수 있었다."},"related":[],"sources":[{"url":"https://learn.battlemetrics.com/article/64-march-27-2022-postgres-transacton-id-wraparound","kind":"blog","archived":"https://web.archive.org/web/20250805181036/https://learn.battlemetrics.com/article/64-march-27-2022-postgres-transacton-id-wraparound"}],"summary":{"en":"BattleMetrics runs 5 Postgres servers, one primary and four read replicas, with autovacuum policies that had worked for years, but without a health check on the size of transaction IDs. About a month before the outage, for a reason BattleMetrics does not know, the index on its player identifiers table, built on the identifier type and the identifier and used heavily to match players joining a server, became corrupted. Site performance did not change, so nobody noticed, but from then on every vacuum job errored out, and transaction IDs climbed until the primary went read-only at 03:23 UTC on 27 March. The corruption had also reached the backup servers and the downloadable backups.\n\nAfter a failover to a replica did not help, the team tried three recoveries in parallel: a full vacuum in single-user mode on the old primary, a restore from backup on a wiped server, and, following Google Cloud documentation, a vacuum without single-user mode on a third server with Postgres settings raised to give vacuum as many resources as possible. The third vacuum was cancelled after about 30 minutes with \"failed to re-find parent key in index \"player_identifiers_type_identifier_index\" for deletion target page 615856\", which explained why autovacuum had been failing. Dropping the index failed with the same wraparound error, so the team shut the database down, dropped the corrupted index in single-user mode, started it again and ran a vacuum that succeeded, after which the database accepted writes. The repair took about 3 hours, and rebuilding the index took about two hours.\n\nBattleMetrics then shut down its query workers, gave RCON updates priority and pointed services at the new primary. Even so, the single server's CPU, disk and network were fully saturated: P50 RCON processing delay was two and a half minutes, P90 and P99 sat at their 5-minute limit, and some servers saw delays of up to two hours. The first new replica took 3 hours and 44 minutes to bootstrap because of the load on the primary and came online at 12:40 UTC, when 660 thousand updates were waiting. With more replicas the backlog caught up at 16:30 UTC, queries were restarted with throttling, player search indexing caught up at 16:46 UTC and Steam lookups at 17:53 UTC, and at 00:42 all replicas were back and queries ran at full speed.","ko":"BattleMetrics 는 계정, 서버, 플레이어 정보를 PostgreSQL 에 두고, 웹사이트와 백엔드 서비스가 이 데이터베이스 없이는 돌아가지 않는다. Postgres 는 트랜잭션 약 21억 개까지만 견디고 그 뒤로는 쓰기 명령을 받지 않으며, 주기적인 vacuum 으로 이 위험을 줄인다. BattleMetrics 는 autovacuum 정책을 두고 몇 년 동안 문제없이 썼지만, 트랜잭션 ID 크기를 확인하는 헬스 체크는 두지 않았다. 플레이어 식별자 테이블의 인덱스가 알 수 없는 이유로 손상됐고, 로그로 보아 약 한 달 전인 2022-02-26 에 생긴 것으로 추정했다. 이 손상은 사이트 성능에 영향이 없어 아무도 몰랐지만, vacuum 작업은 이 손상 탓에 모두 오류로 끝났다. 손상은 replica, 백업 서버, 데이터베이스 장애 때 쓰려고 둔 내려받기용 백업에도 복제됐다.\n\n2022-03-27 3:23 UTC 에 주 데이터베이스가 wraparound 보호로 읽기 전용이 됐다. 팀은 replica 로 수동 장애 조치를 했지만 같은 상태가 복제돼 있어 소용없었다. 그다음 Postgres 서버 다섯 대 중 세 대로 세 가지 방법을 동시에 시도했다. 원래 primary 에서는 오류 문구대로 single-user mode 에서 전체 vacuum 을 돌렸고, 다른 한 대는 지우고 백업에서 복원을 시작했으며, 나머지 한 대에서는 Google Cloud 문서의 방법을 따랐다. 세 번째 방법이 통했다. wraparound 보호에 들어간 서버에서도 single-user mode 없이 전체 vacuum 을 돌릴 수 있었다. 팀은 vacuum 에 자원을 최대한 주도록 설정을 올리고 재시작한 뒤 vacuum 을 시작했다. 약 30분 뒤 vacuum 이 인덱스 오류로 취소되면서 손상된 인덱스가 드러났다. 팀은 데이터베이스를 내리고 single-user mode 에서 인덱스를 지운 뒤 다시 올려 vacuum 을 돌렸고, 이번에는 vacuum 이 성공해 데이터베이스가 쓰기를 다시 받았다. 수리에는 약 3시간이 걸렸다.\n\n지운 인덱스를 다시 만드는 데 약 두 시간이 걸렸다. 서버 한 대로는 RCON 과 쿼리를 다 감당할 수 없어 쿼리 워커를 멈추고 RCON 업데이트를 우선했다. 인덱스가 돌아오자 서비스가 새 primary 를 가리키게 했다. 쿼리를 멈췄는데도 서버 한 대의 CPU, 디스크, 네트워크가 포화돼 RCON 은 크게 지연된 채로 돌았다. 첫 replica 는 primary 부하 때문에 부트스트랩에 3시간 44분이 걸려 12:40 UTC 에 올라왔고, 그때 밀린 업데이트는 66만 건이었다. replica 를 더 띄울 때마다 primary 부하가 줄어 16:30 UTC 에 RCON 업데이트를 따라잡았다. 그 뒤 RCON 이 늦어지지 않게 쿼리를 제한해서 다시 돌렸다. 플레이어 검색 색인은 16:46 UTC, Steam 프로필 조회는 17:53 UTC 에 따라잡았고, 00:42 에 모든 replica 가 돌아와 쿼리를 다시 최대 속도로 돌렸다."},"trigger":{"en":"A corruption of the index on the player identifiers table, which BattleMetrics' logs place at about 26 February 2022, made every vacuum job fail, so transaction IDs kept climbing until Postgres stopped accepting writes on 27 March.","ko":"플레이어 식별자 테이블의 인덱스가 알 수 없는 이유로 손상돼 vacuum 작업이 모두 오류로 끝났다. 로그로 보아 손상은 약 한 달 전인 2022-02-26 에 생긴 것으로 추정했고, 그동안 트랜잭션 ID 가 계속 쌓여 2022-03-27 에 wraparound 보호가 작동했다."},"severity":"unknown","symptoms":["writes-rejected","service-unavailable"],"timeline":{"detected_after":null,"resolved_after":"21h 19m"},"date_kind":"incident","detection":{"en":"Users failed to load the website and reported it as their API keys expired, then RCON updates and queries began to fail, and the team found that the main database no longer accepted writes.","ko":"처음 들어온 것은 웹사이트를 불러오지 못한다는 사용자 신고였다. 팀은 30분쯤 전에 작동한 DDoS 방어 탓으로 보았다가, RCON 업데이트와 쿼리가 실패하는 것을 보고 더 살펴본 끝에 주 데이터베이스가 쓰기를 받지 않는 것을 찾았다."},"components":["database","autovacuum","database-replication","database-backup"],"root_cause":"data-corruption","remediation":[{"text":{"en":"Shut the database down and dropped the corrupted player identifiers index in single-user mode","ko":"데이터베이스를 내리고 single-user mode 로 들어가 손상된 인덱스를 지운 뒤 데이터베이스를 다시 올렸다."}},{"text":{"en":"Ran the vacuum again, which succeeded and let the database accept writes","ko":"vacuum 을 다시 돌렸고, 이번에는 성공해 데이터베이스가 다시 쓰기를 받았다."}},{"text":{"en":"Rebuilt the player identifier index, which took about two hours","ko":"지운 플레이어 식별자 인덱스를 약 두 시간에 걸쳐 다시 만들었다."}},{"text":{"en":"Shut down the query workers and gave RCON updates priority","ko":"데이터베이스가 돌아온 뒤 쿼리 워커를 모두 멈추고 RCON 업데이트를 우선했다."}},{"text":{"en":"Pointed services at the new Postgres primary","ko":"인덱스가 돌아오자 서비스가 새 Postgres primary 를 가리키게 했다."}},{"text":{"en":"Bootstrapped new replicas one after another to take load off the primary","ko":"replica 를 더 부트스트랩해 하나 올라올 때마다 primary 부하를 덜었고, 16:30 UTC 에 RCON 업데이트를 따라잡았다."}},{"text":{"en":"Restarted queries with throttling, prioritised by server population and rank, after RCON updates had caught up","ko":"RCON 업데이트가 늦어지지 않게 쿼리를 제한해서 다시 돌렸고, 쿼리의 우선순위는 서버의 현재 접속 인원과 순위로 매겼다."}}],"action_items":[{"text":{"en":"Monitor errors in the Postgres logs","ko":"Postgres 로그의 오류를 모니터링한다."}},{"text":{"en":"Monitor and alert on transaction IDs","ko":"트랜잭션 ID 를 모니터링하고 알림을 건다."}},{"text":{"en":"Set up a logical replica in addition to physical replication","ko":"물리 복제에 더해 논리 replica 를 둔다."}},{"text":{"en":"Build a faster network to speed up recovery from failure","ko":"장애에서 더 빨리 복구하도록 더 빠른 네트워크를 갖춘다."}}],"contributing":["monitoring-blind-spot","overlapping-failures","no-spare-capacity"],"recurrence_of":null,"symptoms_text":{"en":"At 03:23 UTC on 27 March 2022, BattleMetrics' primary PostgreSQL database, which holds all account, server and player information, went into read-only mode. Users first saw the website fail to load, and soon RCON updates and queries began to fail as well.\n\nThe Postgres logs repeated the following error thousands of times: \"ERROR: database is not accepting commands to avoid wraparound data loss in database \"battlemetrics\"\", with \"HINT: Stop the postmaster and vacuum that database in single-user mode.\" and \"You might also need to commit or roll back old prepared transactions, or drop stale replication slots.\" Postgres can take only about 2.1 billion transactions before it refuses write commands, and vacuuming normally keeps it away from that limit.\n\nThe failure surfaced gradually. Some systems kept working for a while without being able to write: the website uses API keys issued to users for up to 15 minutes, and while a key was valid the website still loaded and showed information. Reports grew as the keys expired.\n\nAbout 30 minutes before the first problems, BattleMetrics' DDoS protection had activated against a small attack, so the website failures and then the failing RCON updates and queries were first taken to be part of that attack. Once the read-only database was found, a manual failover to a replica had no effect, because the transaction IDs close to wraparound and the index corruption, not yet found, had been replicated too.","ko":"2022-03-27 3:23 UTC 에 계정, 서버, 플레이어 정보를 담는 주 PostgreSQL 데이터베이스가 쓰기를 받지 않았다. 처음 보인 증상은 사용자가 웹사이트를 불러오지 못하는 것이었다.\n\n사용자용 API 키는 최대 15분 동안 유효하다. 키가 유효한 동안은 사용자가 웹사이트를 불러오고 정보를 볼 수 있었다. 키가 만료되면서 웹사이트를 불러오지 못한다는 신고가 늘었다. 곧 RCON 업데이트와 쿼리도 실패하기 시작했다.\n\n데이터베이스 로그에는 다음 오류가 수천 번 반복됐다.\nERROR: database is not accepting commands to avoid wraparound data loss in database \"battlemetrics\"\nHINT: Stop the postmaster and vacuum that database in single-user mode.\nYou might also need to commit or roll back old prepared transactions, or drop stale replication slots.\n\n문제가 시작되기 30분쯤 전에 작은 공격으로 DDoS 방어가 작동했기 때문에, 팀은 처음에 웹사이트 문제와 RCON 업데이트 및 쿼리의 실패를 그 공격 탓으로 보았다. 더 살펴보고 나서야 주 데이터베이스가 쓰기를 받지 않는 것을 찾았다.\n\nreplica 도 영향을 받았는지 알 수 없는 상태에서 replica 하나로 수동 장애 조치를 했지만 소용없었다. wraparound 직전의 트랜잭션 ID 와 아직 찾지 못한 데이터 손상이 replica 에도 복제돼 있었다.\n\n최대한 자원을 준 전체 vacuum 은 약 30분 뒤 failed to re-find parent key in index \"player_identifiers_type_identifier_index\" for deletion target page 615856 오류로 취소됐다. 팀은 이 오류를 보고 플레이어 식별자 인덱스가 손상돼 그동안 autovacuum 이 실패해 왔다는 것을 알았다. 그 인덱스를 지우려 하자 다시 database is not accepting commands to avoid wraparound data loss in database 오류가 나왔다.\n\n데이터베이스를 고친 뒤에도 Postgres 서버 한 대로는 부하를 감당하지 못해 CPU, 디스크, 네트워크가 모두 포화됐다. RCON 처리 지연은 P50 이 2분 30초였고 P90 과 P99 는 상한인 5분에 머물러 있었다. 로그를 보면 일부 서버는 최대 두 시간까지 지연됐다. 업데이트가 많은 서버일수록 더 늦어졌다."},"updated_at":"2026-11-14T12:33:56.493861Z","url":"https://benchlet.com/incidentlib/app/cases/IL-0311","org_slug":"battlemetrics"}