なんか前も調べたんだけど、今日表題のようなことが起こったので備忘録。

 

ちなみにkernelのディスクキャッシュには、seq scanであれindex scanであれ、read/writeしたテーブル/インデックス上のページは一発で乗る(っぽい)。

 

しかし、postgresqlのshared_buffersでは、たぶんseq scanでread/writeしたページ(ブロックかもしんない)は、「ちょっとずつ乗る」っぽい。

 

実際に観測した事象は、あるWebサービスで、バックエンドにpostgresql 9.6を使ってるんだけど、カラムの値がjsonになってて、postgresqlでカラムの中のjsonをselectするSQLが、seq scanになってるらしくて、繰り返し何度もWebサービスの同じアクション(同じアイコンをひたすらクリックし続けるとか)して意図的に「同じクエリ」を発行させているにもかかわらず、

pg_stat_statementsのキャッシュヒット率(=shared_blks_hits/(shared_blks_hits+shared_blks_read))

がアクションのたびにじわじわ0.5%くらいずつ100%に近づくという現象を観測したンゴ。

----- ここから20190501追記------

shared_buffers=512MB,seq scan対象テーブルサイズは約150MBの場合、対象テーブルをseq scan するクエリを1回コールするたびに256KBずつshared_bufferに乗っていた。

このため、150MBのテーブルすべてが乗るまで125÷0.25=500コールを必要とした。

※共有bufferの内訳を見るにはpg_buffercacheモジュールというのを使うらしい

http://pgsqldeepdive.blogspot.com/2012/12/pgbuffercache.html

※一回のアクションやコールごとのあるクエリの共有バッファhit率の推移は、pg_stat_statementsを仕込んでおいて1アクションの直前にresetをして1アクション直後に、shared_blks_readとshared_blks_hitからヒット率を確認できるぞなもし。

※関係ないけど、意図的にあるテーブル全部を共有bufferに載せ切るには、pg_prewarm拡張モジュールを使えばいいらしいンゴ。

----- ここまで20190501追記------

postgresqlサービス起動直後だと、このアクションにともなうクエリのキャッシュヒット率はほぼ0%なのが、アクションを繰り返すにつれてじわ上がりした。

 

ほかのindex scanなクエリは一回のアクションでキャッシュに乗っちゃって、2回目以降のキャッシュヒット率は100%になるものが多い。

 

そんで、下記のような記事を見つけたんこぶ

 

https://www.pgconf.asia/JA/2017/wp-content/uploads/sites/2/2017/12/D1-A5.pdf

 

上記の21ページに、「PostgreSQLは、取得結果が大きく、共有バッファの大部分を 占めてしまいそうな場合、shared_buffersを全て使わず、リ ングバッファ内にとどめる」らしいんご。

 

つまり、seq scanでテーブル内の大量のページ(ブロック?)をreadしても、kernelのページキャッシュのように「そのすべてのページを」キャッシュするわけではなく、最初はリングバッファ内にとどめつつ、ひつこくアクセスを繰り返されることでじわじわshared_bufferに乗せるみたい。

 

上記の動作をpostgresqlバックエンドプロセスをstraceすると、大量のreadシステムコールが、seq scan対象のテーブルに対して発行されていることが見れる。

※tomcatなどのコネクションプーリング経由でpostgresqlにつないでる場合、コネクションプーリングの数だけ居るバックエンドプロセスすべてにstraceかまして、中に大量の書き込みがあった出力だけ見る。

その際、strace -Tttオプションで時刻も取得すると、後でシステムコールから次のシステムコールまでの時間Δtを集計してどのシステムコールに時間がかかっていたか確認できる。

 

ここで脱線するけが、postgresqlはプランナーがテーブル行数の推測値を得る際に、テーブルに対応するファイル(openしてファイルディスクリプタでアクセスする)にlseekシステムコールを大量に発行するが、一つのpostgresqlクラスタに対して別のクライアントが同じテーブルに同時にクエリを発行した場合、カーネルがテーブルにスピンロックをかけるらしく、衝突によって待ちが発生することがある。

 

実際に、複数のクエリを同時に発行して衝突しやすい条件にしてjmeterなどでリクエストを大量に送ってシステムコールを見ると、lseek一個当たりの平均レスポンス時間の差が観測できる場合がある。

 

さらに脱線かますんご。

 

負荷テストをほかの負荷がかかってる環境でやると当然ながら外乱の影響を受けるが、任意の時刻に環境にどのくらいの負荷がかかっててパフォーマンステストの外乱になりうるかの予測は難しい。 例えば、ESXi上のテスト環境にテストと関係ないVMが動いている場合、メモリ使用量、CPU使用率は枯渇させなければ影響がないだろうと予想が立つが、ディスクIOは難しい。ESXiのストレージのキャッシュを枯渇させるような大量のIOと同時に、random read IOが大量にあると、自分のテスト環境の外乱となる。

 

外乱は、ディスクIOの低減から、テンポラリファイルのread/writeの速度低下、shared_buffersにキャッシュがまだ乗ってなくて、kernelのディスクキャッシュも枯渇気味のshared_blks_readもディスクIOになるのでレスポンス時間が長くなる。

 

あと、統計解析するのはいいんだけど、t検定とかexcelでやる前に、変動係数と誤差の許容値から必要試行回数をちゃんと計算してからデータを取り始めなくちゃ。

そしたら、必要試行回数が500回とかになっちゃったりして。

自動計測しこむか、誤差の許容値を下げようず。

試行回数少な目なのに野心大きすぎwww