PostgreSQLのレプリカでSELECTしたときにクエリがキャンセルされるまでの実験

RDSの設定変更をしたあと以下のエラーが出るようになってしまいました。

過去に何回か出てるのですが、とりあえず時間のかかるクエリが悪いから短くすればいいんだな、くらいの理解でした。
恥ずかしながら、ちゃんと理解できておらず、このくらいの認識になっていたので、いい機会だから調べてみました。

ERROR:  canceling statement due to conflict with recovery
DETAIL:  User was holding shared buffer pin for too long.

エラーの原因を推測する

裏側の仕組みは既にまとめてくださっている方がいました。

記事を追ってみると重要そうに太字で書いてありました。

スレーブでの参照とスレーブが参照しているタプルを物理削除するWAL(VACUUM等で出力される)の適用がコンフリクトします。

このコンフリクトが起きた後、max_standby_streaming_delay秒後にキャンセルされるようです。

......と、なんとなく想像できるのですが、具体的に何すればコンフリクトするの？というところが分かりませんでした。

このままだと結局分かった気になってるだけ、という感覚です。
ということで、もっと分かった気になるために実験をしてみようと思います(今回の趣旨)

事前準備

terraformで一撃実験環境(過去にクラスターの実験で使ってたものを流用しています)

サブネットやセキュリティグループは調整してください。

コンソールから作っても問題ありません。

• クラスター
• マスター用インスタンス
• レプリカ用インスタンス
• サブネットグループ
• クラスターパラメータグループ
• パラメータグループ

main.tf

provider "aws" { region = "ap-northeast-1" }

resource "aws_rds_cluster_instance" "db01" {
  engine = "aurora-postgresql"
  engine_version = "9.6.8"
  cluster_identifier = "daijinadb"
  identifier         = "db01"
  instance_class     = "db.r4.large"
  db_subnet_group_name    = "${aws_db_subnet_group.daijinadb_subnet.name}"
  db_parameter_group_name = "${aws_db_parameter_group.daijinadb_parameter.name}"

  publicly_accessible = false
}

resource "aws_rds_cluster_instance" "db02" {
  engine = "aurora-postgresql"
  engine_version = "9.6.8"
  cluster_identifier = "daijinadb"
  identifier         = "db01"
  instance_class     = "db.r4.large"
  db_subnet_group_name    = "${aws_db_subnet_group.daijinadb_subnet.name}"
  db_parameter_group_name = "${aws_db_parameter_group.daijinadb_parameter.name}"
  publicly_accessible = false
}

resource "aws_rds_cluster" "daijinadb" {
  cluster_identifier = "daijinadb"
  engine = "aurora-postgresql"
  engine_version = "9.6.8"
  database_name = "totemodaijinadb"
  master_username = "postgres"
  master_password = "hogehoge"
  skip_final_snapshot = "true"
  backup_retention_period = 1
  port = 5432
  db_cluster_parameter_group_name = "${aws_rds_cluster_parameter_group.daijinadb_parameter.name}"
  vpc_security_group_ids    = "securitygroup-iikanjinihenkoushitene"
  db_subnet_group_name = "${aws_db_subnet_group.daijinadb_subnet.name}"
}

resource "aws_rds_cluster_parameter_group" "daijina_parameter" {
  name        = "daijina_parameter"
  family      = "aurora-postgresql9.6"
  description = "aurora-postgresql9.6"

  parameter {
    name = "timezone"
    value = "JST-9"
  }
}

resource "aws_db_parameter_group" "daijina_parameter" {
  name   = "daijina_parameter"
  family = "aurora-postgresql9.6"
  description = "totemo daiji"

  parameter {
    name = "log_min_duration_statement"
    value = "1000"
  }

  parameter {
    name = "log_statement"
    value = "ddl"
  }
}

resource "aws_db_subnet_group" "daijinadb_subnet" {
  name       = "daijinadb_subnet"
  description = "totemo daijina subnet"
  subnet_ids = [
    "subnet-iikanjinihenkoushitene-a",
    "subnet-iikanjinihenkoushitene-c"
  ]
}

仮説

実験用のインスタンスができたので実験前にどうすればキャンセルされるのか仮説を立ててみます。
建てた仮説が以下です。

順番	マスター	レプリカ
1	UPDATEで不要タプルを作成
2		処理に時間のかかるSELECT
3	VACUUMで不要タプルの物理削除を実行
4	WALを生成
5		WALを適用
6		30秒後にSELECTがキャンセルされる

UPDATEすると論理削除扱いになって、VACUUMしたタイミングで物理削除されるので、まずUPDATEしています。

次に、この状態で重いSELECTを実行します。これがキャンセルされれば今回の実験は成功です。

今度は論理削除扱いになっている行をVACUUMで物理削除します。

4,5は表面上確認できないので想像ですが、
マスター側でVACUUMをかければ、
レプリカ側で論理削除扱いになっているものも消す必要があるので、
そのためのWALを生成し、それを適用しようとするはずです。

最後にSELECTの結果を待っている状態でmax_standby_streaming_delay秒待ちます。

実験

Auroraは読み書きができるエンドポイント、読み込みのみのエンドポイントがそれぞれ用意され、
それぞれマスター用インスタンス、レプリカ用インスタンスにアクセスされます。
以下のSQLの実行インスタンスはそのように読み替えていただければ幸いです。

• [マスター] 下準備(重いクエリを手軽に実行するための準備)

正直、空のインスタンスに大量のデータ入れなくちゃいけなくて実験無理じゃない？と思っていたのですが、
簡単に重いSELECTを実現できる方法が紹介されていたのでこれを利用しました。

create table test (item1 int);
insert into test values(1);
insert into test values(2);
insert into test values(3);
insert into test values(4);
insert into test values(5);
insert into test values(6);
insert into test values(7);
insert into test values(8);
insert into test values(9);
insert into test values(10);

• 1. [マスター] Updateして不要タプルを作成

update test set item1 = '1' where item1 = '2';
SELECT relname, n_live_tup, n_dead_tup FROM pg_stat_user_tables; ※vacuumにより物理削除されるタプルがあるか確認

• 1. [レプリカ] 処理に時間のかかるSELECT

select count(*) from test a , test b , test c , test d , test e, test f, test g, test h, test i, test j, test k;

• 1. [マスター] VACUUMで不要タプルの物理削除を実行

VACUUM test;

これらはPostgreSQLの仕事

• 1. [レプリカ] 30秒後にSELECTがキャンセルされる

ERROR:  canceling statement due to conflict with recovery
DETAIL:  User was holding shared buffer pin for too long.

出た！

まとめ

• 不要タプルがある状態になっている
• 処理に時間のかかるSELECTをかける
• VACUUMをかける

以上の条件で、キャンセルされる可能性があるということが分かりました。

PostgreSQLの仕組みを完全に知らない以上、このエラーが出る他のケースが網羅されているとは限りませんが、一つの原因はこれなんだなと、わかった気になれました。
おそらく網羅されたケースは公式文書のこれだと思いますが、文章読んでもいまいちつかみきれないのでいずれ実験してみようかなと思います。