2025/07/09 02:17 When Sigterm Does Nothing: A Postgres Mystery

ロボ子、大変なのじゃ!ClickPipesのチームがPostgresのリードレプリカで、論理レプリケーションスロットを作る時にバグに遭遇したらしいぞ!

それは大変ですね、博士。具体的にはどんな問題だったんですか?

普通は数秒で終わるクエリが、なんと数時間もかかったらしいのじゃ!しかも、Postgresの通常の方法じゃ止められなくて、お客さんが怒っちゃうし、本番データベースも危なくなるリスクがあったみたい。

それは深刻ですね…。原因は何だったんでしょう?

それがなんと、Postgresのバグだったらしいのじゃ!ClickPipesは、データをいろんな場所に簡単に移動できるようにするのが使命で、データベースパイプラインを担当してるみたい。

なるほど。それで、CDC(Change Data Capture)が関係してくるんですね。

そう!CDCはデータベースの変更をずっと追跡して、ClickPipesがほぼリアルタイムでClickHouseに複製できるようにするプロセスなのじゃ。Postgresは主に論理レプリケーションスロットを使ってCDCを実行するらしい。

論理レプリケーションスロット、ですか。WAL(Write-Ahead Log)から変更をデコードして、コンシューマーにストリームするんですね。

その通り!ClickPipeは論理レプリケーションを中心に作られていて、スロットを作ってたくさんの顧客データベースからデータを読み取るのじゃ。

今回の問題は、新しいPostgresリードレプリカからデータを複製するパイプが「スタック」した、ということですね。

そうそう!インスタンスを確認しても問題は見当たらなくて、単一のアクティブな接続が何かを実行しているだけだったのじゃ。新しいパイプを作る時、最初に論理レプリケーションスロットを作るんだけど、それが終わらない。

wait_eventが表示されない、ということは、Postgresはこのコマンドが何も待機していないと考えているんですね。

その通り!しかも、作ろうとしてるスロットが、アクティブなPIDを持つpg_replication_slotsシステムテーブルに表示されてるのじゃ。

ClickPipeが切断されても、その不正なコマンドは消えなかった、と。

そう!pg_cancel_backendとかpg_terminate_backendを使っても、そのクエリに割り当てられたバックエンドプロセスにSIGINTとかSIGTERMシグナルを送っても効果がなかったのじゃ!

SIGTERMが効かないのは異常ですね。レプリケーションスロットが「アクティブ」とマークされて、スロットに接続されたプロセスが終了を拒否するから、削除もできない状態になったんですね。

そう!スロットはWALを保持し始めて、スロットから読み取ったり削除したりする方法がないと、WALをずっと保持し続けて、ストレージを使い果たしてしまう危険性があるのじゃ!

顧客はマネージドPostgresサービスを実行していたから、Postgresインスタンスを完全に再起動するしかなかったんですね。

以前にも同じような問題があって、hot_standby_feedbackをオンにすると解決したように見えたけど、別のマネージドサービスで最新のPostgresバージョンでも同じ問題が起きたから、調査を始めたらしいのじゃ。

顧客のPostgresプロバイダーのサポートから、壊れたクエリを実行しているバックエンドプロセスのstrace出力が得られたんですね。

そう!nanosleepしか表示されなくて、IOとか他のシステムコールがないから、バックエンドが1msの一定時間でsleep()呼び出しを繰り返していることがわかったのじゃ。

レプリケーションスロットの作成の制御フローで、特定条件下でそのようにスリープする関数を見つけた、と。

その通り!それで、この関数が何をするのか、どんな状態になるとそうなるのかを逆算したのじゃ。

再現手順も確立できたんですね。プライマリでトランザクションを開始して、リードレプリカで論理レプリケーションスロットを作成すると、問題が再現される、と。

そう!内部的には、レプリケーションスロットの作成には、スロット作成クエリが発行される前に、トランザクションがCOMMIT/ROLLBACKされるのを待つ必要があるのじゃ。スロットが将来のすべてのトランザクションをデコードできる「一貫したポイント」に到達する必要があるから。

古いトランザクションの完了を待つには時間がかかる可能性があるから、この待機を可能な限り効率的に実装することが重要なんですね。

その通り!Postgresは色々な操作に対して色々なロックを処理して、古いトランザクションでロックを取得するためにこのインフラストラクチャを再利用できるのじゃ。

トランザクションは完了後にのみtransactionidロックを解放するから、このロックを取得すると、トランザクションが完了したことが確認されるんですね。

そう!でも、リードレプリカだと、この動きが変わってくるのじゃ。

リードレプリカは「ホットスタンバイ」と呼ばれるんですね。プライマリからWALレコードを受信して、プライマリ上のすべてのデータの正確なコピーを維持する。

そう!トランザクションの完了を待つ関数XactLockTableWaitの中で、LockAcquireを介してロックを取得して、TransactionIdIsInProgressでトランザクションがまだ進行中かどうかを確認するのじゃ。

トランザクションが実行中として登録されているが、transactionidでロックをまだ取得していないウィンドウがあるんですね。

そう!ホットスタンバイの場合、スタンバイは論理レプリケーションスロットを作成しながら一貫したポイントを見つける必要があって、古いトランザクションは終了する必要があるのじゃ。

トランザクションを実行しているのはスタンバイではないから、LockAcquireはスタンバイですぐに返される。でも、TransactionIdIsInProgressはKnownAssignedXidsを考慮に入れるから、トランザクションがまだ実行中であることがわかる。

その通り!だから、1msのスリープにヒットして、別のループ反復が発生するのじゃ。でも、これは一時的な状況じゃなくて、数時間もスタックする可能性があるのじゃ!

プライマリでの最適化されたLockAcquire待機が、固定の1msポーリングループに置き換えられてしまうんですね。

そう!しかも、LockAcquireが待機する必要がある場合、割り込みも処理するけど、このスリープケースは一時的なケースだから、ループ内に割り込みを処理するコードがないのじゃ!

それがバックエンドプロセスを「アンキル不可能」にした理由なんですね。LockAcquireがそれを処理したから、外部操作を待機していることを報告しない。

その通り!ClickPipesチームは、この問題が単発のケースじゃないとわかって、RCAを特定して、それに対処するパッチを開発したのじゃ。

Postgresコミュニティは、パッチをすぐにレビューしてバックポートしてくれたんですね。

そう!一見単純なバグの調査が、最新のデータベースシステムの奥深さを明らかにしたのじゃ。PostgreSQLからClickHouseにデータを複製すると、カラムナストレージのパフォーマンスが上がるからオススメなのじゃ。

勉強になりました!

ところでロボ子、このバグ、まるで私が徹夜でデバッグしてる時の顔みたいじゃない?

博士、それは… 1msごとにスリープしてるんですか?
⚠️この記事は生成AIによるコンテンツを含み、ハルシネーションの可能性があります。
