- GCP Cloud SQL For PostgreSQL 인스턴스의 데이터베이스들에 대한 쿼리 실행 시에 비정상적인 시간 지연 발생
- 단순한 PK 검색 쿼리
SELECT * FROM TABLE WHERE _id = $1;에도 20초 이상 소요
- 사용자들이 Public IP로 직접 접속하지 않고 Cloud SQL Auth Proxy를 통해 접속하며 리전 또한 일치하므로 VPC 네트워크 라우팅 문제가 아님
- Cloud SQL Auth Proxy 혹은 애플리케이션의 DB connection pool을 활용하므로, DB 연결을 매번 새로 열면서 생기는 TLS handshake 및 인증서 검증으로 인한 지연은 아님
- Cloud SQL 인스턴스의 CPU 사용률, 총 메모리 사용량, 총 연결 수, 저장소 사용량 등의 모니터링 지표 또한 특이한 부분은 없으나, 쿼리 통계에서 쿼리의 데이터베이스 부하가 비정상적으로 높은 현상을 확인 (정상적인 상태의 쿼리 부하는 0.1 미만을 유지하였음)
- Cloud SQL 인스턴스의 로그 탐색기에서
[1-1] db=cloudsqladmin,user=cloudsqladmin ERROR: canceling statement due to user request ERROR 레벨 로그가 남아있음
- Cloud SQL은
cloudsqladmin을 GCP 관리 계정으로 pg_is_in_recovery, pg_available_extensions 테이블에 대한 백그라운드 모니터링 쿼리 (heartbeat)를 실행하는데, DB 메타데이터를 읽는 쿼리가 타임아웃되면 Cloud SQL이 자체적으로 cancel함. 즉 이거는 원인보다는 결과로 보임
- Cloud SQL 인스턴스의 로그 탐색기에서
pg_size_pretty, pg_catalog.pg_stat_activity, pg_catalog.pg_prepared_xacts, pg_catalog.pg_replication_slots, pg_catalog.pg_stat_replication 테이블에 대한 INFO 레벨 로그가 많이 남아있음
- 스키마 변경이나 인덱스 추가 및 삭제, 컬럼 변경이 빈번하게 발생할 경우에 시스템 카탈로그 (
pg_catalog) 테이블의 크기가 커짐. 실제로 SELECT datname, numbackends, xact_commit, xact_rollback, blks_hit, blks_read, tup_returned, tup_fetched FROM pg_stat_database;를 실행했을 때 트랜잭션 커밋이 누적된 횟수를 뜻하는 xact_commit가 다른 테이블 대비 10배 이상 많았음
- 쿼리가 실행되기 이전에 시스템 카탈로그를 참조하여
pg_class, pg_attribute, pg_constraint, pg_type 등의 메타데이터를 가져오는 접근 비용이 급격히 증가하였을 것으로 보임
- 또한 시스템 카탈로그를 최적화하기 위한 autovacuum 및 autoanalyze 작업이 동시에 실행되면서 접근 경합 (lock contention)이 발생한 것으로 보임
- Cloud SQL 인스턴스 재시작을 통해 pg_catalog 테이블에서 락을 유발하는 트랜잭션을 해제하고 autovacuum 작업을 리셋하여 문제를 해결
pg_locks, pg_stat_activity나 Cloud SQL 쿼리 통계를 통해 시스템 카탈로그 접근 부하가 큰 쿼리를 식별하고, ORDER BY 및 LIMIT 조건을 통한 페이징 처리를 통해 쿼리 최적화 작업을 진행함 (동적인 조건을 가진 쿼리였기에 부분 인덱스 처리가 불가능하여 부득이하게 페이지네이션만 적용)- 추후 해당 문제가 재발하였을 때에 vacuum 및 analyze 작업을 수동으로 돌릴 수 있도록 조치함