Mengukur Performa Query

Optimasi yang salah arah biasanya bukan lahir dari kebodohan, melainkan dari pengukuran yang menipu. Query yang diuji sekali saja di cache yang sedang hangat terlihat “sudah cepat”; query pembanding yang diuji ketika cache sedang dingin terlihat lambat padahal rencananya sama bagusnya; dan jam yang dipasang di sisi klien menghukum transfer jaringan yang bukan salah query. Chapter penutup section ini merangkai alat ukur yang tepat — EXPLAIN (ANALYZE, BUFFERS) untuk melihat asal data, \timing untuk jam sisi klien — lalu membedah jebakan-jebakan pengukuran yang paling sering menjebak pembanding query: bias cache, derau satu-eksekusi, dan ketidakadilan kondisi awal.

Basis Latihan dan Konteks Server #

Pengukuran hanya bermakna dengan konteks. Basis latihan kita satu tabel besar dan satu tabel kecil: log_transaksi berisi 300.000 baris dengan keterangan panjang sehingga ukurannya 138 MB — sengaja melebihi shared_buffers — serta penjualan_uji berisi 1.000 baris yang pasti tertampung penuh di cache:

sql
buat-tabel.sql
-- Tabel besar: 300.000 baris dengan keterangan panjang sehingga
-- ukurannya (138 MB) sengaja melampaui shared_buffers server (128 MB).
CREATE TABLE log_transaksi (
    id bigint GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
    akun text NOT NULL,
    keterangan text NOT NULL,
    nominal numeric(14,2) NOT NULL
);

INSERT INTO log_transaksi (akun, keterangan, nominal)
SELECT 'AKT-' || lpad((g % 1000)::text, 4, '0'),
       lpad('mutasi otomatis ' || g, 400, 'x'),
       1000 + (g % 100) * 25.50
FROM generate_series(1, 300000) AS g;

CREATE INDEX idx_log_transaksi_akun ON log_transaksi (akun);

ANALYZE log_transaksi;

-- Tabel kecil sebagai pembanding: halamannya pasti masih
-- tertinggal di cache setelah penulisan barusan.
CREATE TABLE penjualan_uji (
    id integer GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
    produk text NOT NULL,
    jumlah integer NOT NULL
);

INSERT INTO penjualan_uji (produk, jumlah)
SELECT (ARRAY['Kopi','Teh'])[1 + g % 2], 1 + g % 10
FROM generate_series(1, 1000) AS g;

ANALYZE penjualan_uji;

SELECT count(*) AS baris_transaksi FROM log_transaksi;
SELECT pg_size_pretty(pg_relation_size('log_transaksi')) AS ukuran_transaksi;
SELECT count(*) AS baris_penjualan FROM penjualan_uji;

Output yang Dihasilkan:

text
CREATE TABLE
INSERT 0 300000
CREATE INDEX
ANALYZE
CREATE TABLE
INSERT 0 1000
ANALYZE
 baris_transaksi 
-----------------
          300000
(1 row)

 ukuran_transaksi 
------------------
 138 MB
(1 row)

 baris_penjualan 
-----------------
            1000
(1 row)

Konteks memori ikut dibaca dari pg_settings, karena angka buffer nanti hanya bermakna relatif terhadap ukuran cache halaman server:

sql
konteks-server.sql
-- Konteks memori server menentukan arti angka buffer:
-- shared_buffers adalah cache halaman yang dihitung sebagai hit/read.
SELECT name, setting, unit, source
FROM pg_settings
WHERE name IN ('shared_buffers', 'work_mem', 'effective_cache_size')
ORDER BY name;

Output yang Dihasilkan:

text
         name         | setting | unit |       source       
----------------------+---------+------+--------------------
 effective_cache_size | 524288  | 8kB  | default
 shared_buffers       | 16384   | 8kB  | configuration file
 work_mem             | 4096    | kB   | default
(3 rows)

Server latihan ini punya shared_buffers 16384 × 8 kB = 128 MB. Tabel 138 MB kita karenanya tidak pernah muat penuh di cache — satu fakta kecil yang akan menjelaskan semua keanehan di bagian berikutnya.

BUFFERS: Melihat dari Mana Data Datang #

EXPLAIN (ANALYZE, BUFFERS) menambahkan satu lapis bukti yang tidak dimiliki EXPLAIN ANALYZE polos: jumlah halaman 8 kB yang disentuh, dipisah menjadi hit (ditemukan di shared_buffers) dan read (diambil dari disk). File berikut menguji kedua tabel — yang kecil sekali, yang besar dua kali beruntun:

sql
explain-buffers.sql
-- Nonaktifkan worker paralel agar bentuk rencana stabil tiap eksekusi.
SET max_parallel_workers_per_gather = 0;

-- Tabel kecil baru ditulis: seluruh halamannya masih nempel di
-- shared_buffers, jadi "eksekusi pertama" BUKAN kondisi cache dingin.
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*) FROM penjualan_uji WHERE jumlah > 5;

-- Tabel besar 138 MB melampaui shared_buffers 128 MB: campuran
-- hit dan read, dan campuran itu TETAP ADA pada eksekusi kedua.
-- Angka waktu dan buffer bervariasi antar mesin dan antar eksekusi.
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;

EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;

RESET max_parallel_workers_per_gather;

Output yang Dihasilkan:

text
SET
                                                    QUERY PLAN                                                    
------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=19.75..19.76 rows=1 width=8) (actual time=0.136..0.136 rows=1 loops=1)
   Buffers: shared hit=6
   ->  Seq Scan on penjualan_uji  (cost=0.00..18.50 rows=500 width=0) (actual time=0.010..0.109 rows=500 loops=1)
         Filter: (jumlah > 5)
         Rows Removed by Filter: 500
         Buffers: shared hit=6
 Planning:
   Buffers: shared hit=55 read=2 written=2
 Planning Time: 0.242 ms
 Execution Time: 0.169 ms
(10 rows)

                                                         QUERY PLAN                                                         
----------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=21849.35..21849.36 rows=1 width=8) (actual time=70.514..70.515 rows=1 loops=1)
   Buffers: shared hit=15864 read=1784 written=31
   ->  Seq Scan on log_transaksi  (cost=0.00..21398.00 rows=180540 width=0) (actual time=0.254..61.848 rows=180000 loops=1)
         Filter: (nominal > '2000'::numeric)
         Rows Removed by Filter: 120000
         Buffers: shared hit=15864 read=1784 written=31
 Planning:
   Buffers: shared hit=42
 Planning Time: 0.102 ms
 Execution Time: 70.532 ms
(10 rows)

                                                         QUERY PLAN                                                         
----------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=21849.35..21849.36 rows=1 width=8) (actual time=66.555..66.556 rows=1 loops=1)
   Buffers: shared hit=15892 read=1756 written=21
   ->  Seq Scan on log_transaksi  (cost=0.00..21398.00 rows=180540 width=0) (actual time=0.301..57.882 rows=180000 loops=1)
         Filter: (nominal > '2000'::numeric)
         Rows Removed by Filter: 120000
         Buffers: shared hit=15892 read=1756 written=21
 Planning:
   Buffers: shared hit=42
 Planning Time: 0.066 ms
 Execution Time: 66.580 ms
(8 rows)

RESET

Tiga pelajaran terbaca langsung dari output tersebut. Pertama, scan tabel kecil menunjukkan Buffers: shared hit=6 tanpa satu pun read — padahal itu eksekusi PERTAMA query tersebut. Penulisannya sendiri (INSERT di file sebelumnya) sudah menaruh halaman-halaman itu ke cache: eksekusi pertama bukan berarti cache dingin, dan menganggapnya dingin adalah jebakan pengukuran klasik. Kedua, tabel besar memperlihatkan campuran hit=15864 read=1784: ekornya masih hangat dari penulisan, kepalanya sudah tergeser keluar cache — dan pada eksekusi kedua campuran itu TIDAK menghilang (read=1756), karena tabel yang lebih besar dari shared_buffers selalu menyisakan bagian yang harus diambil dari disk. Ketiga, kolom written yang muncul menunjukkan halaman kotor yang tergeser keluar cache ikut ditulis ke disk — pengukuran buffer kadang menjelaskan biaya yang bahkan tidak terlihat di waktu eksekusi. Seluruh angka waktu dan buffer di atas dicatat dari eksekusi nyata dan bervariasi antar mesin dan antar eksekusi; yang stabil adalah pola strukturalnya (ada/tidaknya read, jumlah baris rows=180000).

Dari sini kerangka “apa yang diukur” bisa dirangkum: performa query tidak berdiri di satu angka, melainkan tiga kelompok metrik yang saling menjelaskan.

Metrik	Sumber	Menjawab
Latensi	`Execution Time` (server) atau `\timing` (klien)	Berapa lama satu eksekusi berjalan
Buffer	`Buffers: shared hit/read`, `temp_blks_written`	Dari mana data datang, dan apakah beban jatuh ke disk
Baris	`rows` aktual lawan estimasi	Apakah statistik planner sehat dan filter efektif

\timing: Jam di Sisi Klien #

psql punya jam sendiri lewat meta-command \timing. Berbeda dengan Execution Time dari EXPLAIN ANALYZE yang dihitung di server, \timing mengukur sejak query dikirim sampai hasil selesai diterima dan dicetak — termasuk biaya transfer dan pemformatan. Tiga eksekusi beruntun memperlihatkan keduanya sekaligus: posisi jam dan derau angka:

sql
timing-klien.sql
-- \timing mengukur waktu sisi KLIEN: psql mencatat durasi sejak
-- query dikirim sampai hasil selesai diterima dan dicetak.
-- Tiga kali beruntun memperlihatkan derau pengukuran.
\timing on
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;
\timing off

Output yang Dihasilkan:

text
Timing is on.
 count  
--------
 180000
(1 row)

Time: 41.560 ms
 count  
--------
 180000
(1 row)

Time: 60.158 ms
 count  
--------
 180000
(1 row)

Time: 40.042 ms
Timing is off.

Tiga query identik, tiga hasil: 41,6 ms, 60,2 ms, dan 40,0 ms — selisih hampir 50% tanpa satu baris data atau satu rencana eksekusi yang berubah. Derau semacam ini (penjadwalan CPU, isi cache, aktivitas latar) adalah alasan utama mengapa kesimpulan dari satu eksekusi tidak boleh dipercaya: pilih selisih 40 ms lawan 41 ms pada satu-eksekusi dan Anda akan “membuktikan” hal apa pun. Praktik yang sehat: jalankan 5–10 kali, buang pencilan, dan bandingkan mediannya. Pilihan posisi jam mengikuti tujuan: \timing untuk apa yang dirasakan pengguna (termasuk jaringan), Execution Time untuk menghakimi query dan rencananya di server.

Perbandingan yang Adil dan pgbench #

Kesadaran terakhir dari disiplin pengukuran: saat membandingkan dua versi query, jalankan keduanya secara berselang-seling — A, B, A, B — bukan A lima kali lalu B lima kali, agar keduanya menanggung kondisi cache yang berganti secara setara; dan pastikan data yang dibandingkan identik (snapshot yang sama, statistik ANALYZE yang sama). Untuk beban yang lebih besar dari satu query, PostgreSQL membawa alat benchmark sendiri: pgbench. Alat ini membuat skema baku (tabel pgbench_accounts dan kawan-kawan berisi transaksi ala perbankan), lalu menghantamnya dari banyak klien paralel selama durasi tertentu:

bash
# Siapkan database benchmark bawaan (skala 10 ~ 1.000.000 baris akun).
pgbench -i -s 10 uji_pgbench

# Hantam 30 detik dengan 10 klien paralel, lalu baca laporan TPS-nya.
pgbench -c 10 -T 30 uji_pgbench

Kedua perintah di atas adalah sketsa pemakaian — belum dijalankan pada sesi ini, dan angka hasilnya sangat bergantung pada mesin, disk, serta skenario yang dipilih (transaksi bawaan bisa diganti skrip sendiri dengan -f). Laporan akhirnya berisi latency average dan tps (transaksi per detik) yang jauh lebih representatif untuk keputusan kapasitas daripada latensi satu query. Untuk mengolah rencana eksekusi secara terprogram, EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON) menghasilkan struktur data yang bisa diurai tool — jalur yang sama dipakai alat visualisasi plan.

Dengan ini perjalanan Section Query Optimization ditutup: kita sudah membaca rencana eksekusi, memahami scan dan join, merawat statistik dan VACUUM, memperbaiki join dan pagination, menangkap slow query, dan terakhir mengukur semuanya secara jujur. Database yang cepat, bagaimanapun, belum tentu database yang aman — pertanyaan berikutnya adalah siapa saja yang boleh menjalankan query itu, dan itu wilayah Section User Management dan Keamanan.

Referensi #

Berkas Sumber

Berkas pendukung halaman ini dapat diunduh dan dijalankan langsung sesuai penjelasan di atas.

sql
-- Tabel besar: 300.000 baris dengan keterangan panjang sehingga
-- ukurannya (138 MB) sengaja melampaui shared_buffers server (128 MB).
CREATE TABLE log_transaksi (
    id bigint GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
    akun text NOT NULL,
    keterangan text NOT NULL,
    nominal numeric(14,2) NOT NULL
);

INSERT INTO log_transaksi (akun, keterangan, nominal)
SELECT 'AKT-' || lpad((g % 1000)::text, 4, '0'),
       lpad('mutasi otomatis ' || g, 400, 'x'),
       1000 + (g % 100) * 25.50
FROM generate_series(1, 300000) AS g;

CREATE INDEX idx_log_transaksi_akun ON log_transaksi (akun);

ANALYZE log_transaksi;

-- Tabel kecil sebagai pembanding: halamannya pasti masih
-- tertinggal di cache setelah penulisan barusan.
CREATE TABLE penjualan_uji (
    id integer GENERATED ALWAYS AS IDENTITY PRIMARY KEY,
    produk text NOT NULL,
    jumlah integer NOT NULL
);

INSERT INTO penjualan_uji (produk, jumlah)
SELECT (ARRAY['Kopi','Teh'])[1 + g % 2], 1 + g % 10
FROM generate_series(1, 1000) AS g;

ANALYZE penjualan_uji;

SELECT count(*) AS baris_transaksi FROM log_transaksi;
SELECT pg_size_pretty(pg_relation_size('log_transaksi')) AS ukuran_transaksi;
SELECT count(*) AS baris_penjualan FROM penjualan_uji;

sql
-- Nonaktifkan worker paralel agar bentuk rencana stabil tiap eksekusi.
SET max_parallel_workers_per_gather = 0;

-- Tabel kecil baru ditulis: seluruh halamannya masih nempel di
-- shared_buffers, jadi "eksekusi pertama" BUKAN kondisi cache dingin.
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*) FROM penjualan_uji WHERE jumlah > 5;

-- Tabel besar 138 MB melampaui shared_buffers 128 MB: campuran
-- hit dan read, dan campuran itu TETAP ADA pada eksekusi kedua.
-- Angka waktu dan buffer bervariasi antar mesin dan antar eksekusi.
EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;

EXPLAIN (ANALYZE, BUFFERS)
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;

RESET max_parallel_workers_per_gather;

sql
-- Konteks memori server menentukan arti angka buffer:
-- shared_buffers adalah cache halaman yang dihitung sebagai hit/read.
SELECT name, setting, unit, source
FROM pg_settings
WHERE name IN ('shared_buffers', 'work_mem', 'effective_cache_size')
ORDER BY name;

sql
-- \timing mengukur waktu sisi KLIEN: psql mencatat durasi sejak
-- query dikirim sampai hasil selesai diterima dan dicetak.
-- Tiga kali beruntun memperlihatkan derau pengukuran.
\timing on
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;
SELECT count(*) FROM log_transaksi WHERE nominal > 2000;
\timing off