Ketidakcocokan besar antara ukuran indeks yang dilaporkan dan jumlah buffer dalam rencana eksekusi

Masalah

Kami memiliki pertanyaan seperti

SELECT COUNT(1) 
  FROM article
  JOIN reservation ON a_id = r_article_id 
 WHERE r_last_modified < now() - '8 weeks'::interval 
   AND r_group_id = 1 
   AND r_status = 'OPEN';

Karena mengalami timeout (setelah 10 menit) lebih sering daripada tidak, saya memutuskan untuk menyelidiki masalah ini.

The EXPLAIN (ANALYZE, BUFFERS)Output terlihat seperti ini:

 Aggregate  (cost=264775.48..264775.49 rows=1 width=0) (actual time=238960.290..238960.291 rows=1 loops=1)
   Buffers: shared hit=200483 read=64361 dirtied=666 written=8, temp read=3631 written=3617
   I/O Timings: read=169806.955 write=0.154
   ->  Hash Join  (cost=52413.67..264647.65 rows=51130 width=0) (actual time=1845.483..238957.588 rows=21644 loops=1)
         Hash Cond: (reservation.r_article_id = article.a_id)
         Buffers: shared hit=200483 read=64361 dirtied=666 written=8, temp read=3631 written=3617
         I/O Timings: read=169806.955 write=0.154
         ->  Index Scan using reservation_r_article_id_idx1 on reservation  (cost=0.42..205458.72 rows=51130 width=4) (actual time=34.035..237000.197 rows=21644 loops=1)
               Filter: ((r_group_id = 1) AND (r_status = 'OPEN') AND (r_last_modified < (now() - '56 days'::interval)))
               Rows Removed by Filter: 151549
               Buffers: shared hit=200193 read=48853 dirtied=450 written=8
               I/O Timings: read=168614.105 write=0.154
         ->  Hash  (cost=29662.22..29662.22 rows=1386722 width=4) (actual time=1749.392..1749.392 rows=1386814 loops=1)
               Buckets: 32768  Batches: 8  Memory Usage: 6109kB
               Buffers: shared hit=287 read=15508 dirtied=216, temp written=3551
               I/O Timings: read=1192.850
               ->  Seq Scan on article  (cost=0.00..29662.22 rows=1386722 width=4) (actual time=23.822..1439.310 rows=1386814 loops=1)
                     Buffers: shared hit=287 read=15508 dirtied=216
                     I/O Timings: read=1192.850
 Total runtime: 238961.812 ms

Simpul bottleneck jelas merupakan pemindaian indeks. Jadi mari kita lihat definisi indeks:

CREATE INDEX reservation_r_article_id_idx1 
    ON reservation USING btree (r_article_id)
 WHERE (r_status <> ALL (ARRAY['FULFILLED', 'CLOSED', 'CANCELED']));

Ukuran dan nomor baris

Ukurannya (dilaporkan oleh \di+atau dengan mengunjungi file fisik) adalah 36 MB. Karena pemesanan biasanya hanya menghabiskan waktu yang relatif singkat di semua status yang tidak tercantum di atas, ada banyak pembaruan yang terjadi, sehingga indeksnya cukup besar (sekitar 24 MB terbuang di sini) - masih, ukurannya relatif kecil.

The reservationtabel sekitar 3,8 GB dalam ukuran, yang mengandung sekitar 40 juta baris. Jumlah pemesanan yang belum ditutup adalah sekitar 170.000 (jumlah persisnya dilaporkan dalam simpul pemindaian indeks di atas).

Sekarang yang mengejutkan: laporan pemindaian indeks mengambil sejumlah besar buffer (yaitu, 8 kb halaman):

Buffers: shared hit=200193 read=48853 dirtied=450 written=8

Angka-angka yang dibaca dari cache dan disk (atau cache OS) menambahkan hingga 1,9 GB!

Skenario terburuk

Di sisi lain, skenario terburuk, ketika setiap tuple duduk di halaman berbeda dari tabel, akan menjelaskan kunjungan (21644 + 151549) + 4608 halaman (total baris diambil dari tabel ditambah nomor halaman indeks dari fisik) ukuran). Ini masih hanya di bawah 180.000 - jauh di bawah yang diamati hampir 250.000.

Menarik (dan mungkin penting) adalah bahwa kecepatan baca disk adalah sekitar 2,2 MB / s, yang cukup normal, saya kira.

Terus?

Adakah yang tahu dari mana perbedaan ini bisa terjadi?

Catatan: Untuk lebih jelasnya, kami memiliki ide tentang apa yang harus diperbaiki / diubah di sini, tetapi saya benar-benar ingin memahami angka yang saya dapatkan - inilah pertanyaannya.

Pembaruan: memeriksa efek caching atau microvacuuming

Berdasarkan jawaban jjanes , saya telah memeriksa apa yang terjadi ketika saya langsung menjalankan permintaan yang sama persis. Jumlah buffer yang terpengaruh tidak benar-benar berubah. (Untuk melakukan ini, saya menyederhanakan kueri ke minimumnya yang masih menunjukkan masalah.) Inilah yang saya lihat dari jalankan pertama:

 Aggregate  (cost=240541.52..240541.53 rows=1 width=0) (actual time=97703.589..97703.590 rows=1 loops=1)
   Buffers: shared hit=413981 read=46977 dirtied=56
   I/O Timings: read=96807.444
   ->  Index Scan using reservation_r_article_id_idx1 on reservation  (cost=0.42..240380.54 rows=64392 width=0) (actual time=13.757..97698.461 rows=19236 loops=1)
         Filter: ((r_group_id = 1) AND (r_status = 'OPEN') AND (r_last_modified < (now() - '56 days'::interval)))
         Rows Removed by Filter: 232481
         Buffers: shared hit=413981 read=46977 dirtied=56
         I/O Timings: read=96807.444
 Total runtime: 97703.694 ms

dan setelah yang kedua:

 Aggregate  (cost=240543.26..240543.27 rows=1 width=0) (actual time=388.123..388.124 rows=1 loops=1)
   Buffers: shared hit=460990
   ->  Index Scan using reservation_r_article_id_idx1 on reservation  (cost=0.42..240382.28 rows=64392 width=0) (actual time=0.032..385.900 rows=19236 loops=1)
         Filter: ((r_group_id = 1) AND (r_status = 'OPEN') AND (r_last_modified < (now() - '56 days'::interval)))
         Rows Removed by Filter: 232584
         Buffers: shared hit=460990
 Total runtime: 388.187 ms

Saya pikir kuncinya di sini adalah banyak pembaruan, dan mengasapi indeks.

Indeks berisi pointer ke baris dalam tabel yang tidak lagi 'hidup'. Ini adalah versi lama dari baris yang diperbarui. Versi baris lama disimpan untuk sementara waktu, untuk memenuhi permintaan dengan snapshot lama, dan kemudian disimpan untuk sementara waktu lebih karena tidak ada yang ingin melakukan pekerjaan menghapusnya lebih sering daripada yang diperlukan.

Saat memindai indeks, ia harus mengunjungi baris-baris ini, dan kemudian memperhatikan bahwa mereka tidak lagi terlihat, jadi abaikan saja. The explain (analyze,buffers)pernyataan tidak melaporkan kegiatan ini secara eksplisit, kecuali melalui penghitungan buffer membaca / hit dalam proses memeriksa baris ini.

Ada beberapa kode "microvacuum" untuk btrees, sehingga ketika pemindaian kembali ke indeks lagi, ia mengingat bahwa penunjuk yang dikejar tidak lagi hidup, dan menandainya sudah mati dalam indeks. Dengan begitu permintaan serupa berikutnya yang dijalankan tidak perlu mengejarnya lagi. Jadi, jika Anda menjalankan kueri yang sama persis lagi, Anda mungkin akan melihat akses buffer turun mendekati apa yang Anda prediksi.

Anda juga dapat VACUUMmembuat tabel lebih sering, yang akan membersihkan tupel mati dari tabel itu sendiri, bukan hanya dari indeks parsial. Secara umum, tabel dengan indeks parsial turn-over tinggi cenderung mendapat keuntungan dari kekosongan yang lebih agresif daripada tingkat standar.