Query Profiling

Laporan pemakaian voucher TokoKita tiba-tiba butuh 2,3 detik untuk mengagregasi lima juta pesanan, padahal query sejenis biasanya selesai di bawah 150 milidetik. Chapter Mengukur Performa Pipeline memberi kita disiplin pengukuran di level pipeline; kini beban bergeser ke dalam, yaitu satu query di engine analitik yang lambat tanpa alasan yang terlihat. Chapter Query Optimization telah memperkenalkan cara membaca rencana eksekusi EXPLAIN ANALYZE. Bab ini menyusun alat tersebut menjadi alur kerja investigasi yang bisa diulang: ukur dulu, temukan operator yang menjadi hotspot, perbaiki satu hal, lalu ukur ulang dengan prosedur yang sama.

Piramida Profiling: Dari Gejala ke Operator #

Profiling yang disiplin bergerak dari level paling atas ke bawah, dan setiap level mengecilkan ruang investigasi sebelum kita menyentuh satu baris kode pun:

Prinsip piramida ini satu kalimat: jangan melompat level. Menambah index atau menulis ulang SQL sebelum tahu operator mana yang lambat hanyalah tebakan dengan biaya perawatan — persis pola yang kita tolak di level pipeline.

Studi Kasus: Query Voucher yang Melambat #

Dataset kasusnya sederhana namun mewakili: tabel fact pesanan berisi lima juta baris, dan tabel dim voucher yang seharusnya tiga baris ternyata berisi tiga puluh — tiga jenis voucher terduplikasi sepuluh kali akibat proses load yang berjalan ganda. Query yang dilaporkan lambat adalah agregasi sederhana: jumlah pesanan dan total nilai per jenis voucher.

# --- 1. Dataset: 5 juta pesanan + tabel voucher yang terduplikasi ---
con.execute("""
CREATE TABLE pesanan AS
SELECT i AS id,
       'pelanggan-' || (i % 50000)::VARCHAR AS pelanggan,
       1 + (i % 3)::INTEGER AS voucher_id,
       15000.0 + (i % 500) * 250.0 AS nilai
FROM range(5000000) t(i)
""")
con.execute("""
CREATE TABLE voucher AS
SELECT 1 + (i % 3)::INTEGER AS voucher_id,
       CASE (i % 3) WHEN 0 THEN 'cashback_5k'
                    WHEN 1 THEN 'diskon_10'
                    ELSE 'gratis_ongkir' END AS jenis
FROM range(30) t(i)   -- 3 jenis x 10 salinan: efek double-load
""")
print("tabel pesanan :", con.execute("SELECT count(*) FROM pesanan").fetchone()[0], "baris")
jenis_unik = con.execute("SELECT count(DISTINCT jenis) FROM voucher").fetchone()[0]
print(f"tabel voucher : {con.execute('SELECT count(*) FROM voucher').fetchone()[0]} "
      f"baris (jenis unik: {jenis_unik})")

Q_LAMBAT = """
SELECT v.jenis, count(*) AS jumlah, round(sum(p.nilai), 0) AS total
FROM pesanan p JOIN voucher v ON p.voucher_id = v.voucher_id
GROUP BY v.jenis ORDER BY v.jenis
"""

Pengukurannya memakai pola yang sudah kita kenal — pemanasan satu run, lalu median beberapa run — sehingga hasilnya kebal terhadap noise satu kali eksekusi:

def ukur(query, n_run=3):
    """Median n_run; run pertama sekalian mengembalikan hasil untuk ditampilkan."""
    hasil = con.execute(query).fetchall()  # pemanasan + ambil hasil
    durasi = []
    for _ in range(n_run):
        t0 = time.perf_counter()
        con.execute(query).fetchall()
        durasi.append(time.perf_counter() - t0)
    return statistics.median(durasi), hasil

Output yang Dihasilkan:

tabel pesanan : 5000000 baris
tabel voucher : 30 baris (jenis unik: 3)

=== Query lambat: median 3 run = 2.272 s ===
  ('cashback_5k', 16666670, Decimal('1289583382500'))
  ('diskon_10', 16666670, Decimal('1289583800000'))
  ('gratis_ongkir', 16666660, Decimal('1289582817500'))

=== Kutipan EXPLAIN ANALYZE (dipadatkan) ===
  Total Time: 2.39s
  HASH_GROUP_BY
  3 rows
  2.31s
  HASH_JOIN
  Join Type: INNER
  Conditions:
  voucher_id = voucher_id
  50,000,000 rows
  1.20s
  TABLE_SCAN                 TABLE_SCAN
  Table:                     Table:
  memory.main.pesanan        memory.main.voucher
  Type: Sequential Scan      Type: Sequential Scan
  5,000,000 rows                30 rows
  0.02s                     (0.00s)

Mari kita telaah bagian-bagian penting kode di atas:

1. Baris 17-24 (tabel pesanan): lima juta baris fact dibangun lewat range(5000000); voucher_id hanya bernilai 1-3 sehingga setiap pesanan menemukan pasangan join.
2. Baris 25-32 (tabel voucher terduplikasi): range(30) menghasilkan 30 baris padahal hanya 3 jenis unik — setiap voucher_id muncul sepuluh kali, meniru tabel dim yang ter-load ganda.
3. Baris 38-42 (query yang dilaporkan lambat): agregasi count dan sum per jenis — query yang tampak polos, tetapi seperti kita lihat sebentar lagi, jalur tengahnya memuat 50 juta baris.
4. Baris 54 (pemanasan): run pertama dijalankan sekali untuk mengisi cache dan mengambil hasil, lalu durasinya tidak diikutkan pengukuran.
5. Baris 55-60 (median): tiga run berikutnya diukur dengan time.perf_counter() dan diambil mediannya — disiplin yang sama dengan profil stage di chapter sebelumnya.

Membaca Hotspot dari Rencana Eksekusi #

Satu catatan tampilan lebih dulu: kutipan rencana di atas dihasilkan oleh fungsi pembantu yang membuang karakter garis kotak dari keluaran asli EXPLAIN ANALYZE — operator, jumlah baris, dan waktunya disalin apa adanya. Rencana dibaca dari operator paling bawah ke atas. TABLE_SCAN hanya 0,02 detik — membaca data bukan masalahnya. Yang menonjol adalah HASH_JOIN yang mengeluarkan 50.000.000 baris dari input 5 juta pesanan dan 30 voucher: karena setiap pesanan menemukan 10 salinan voucher yang cocok, join melipatgandakan baris fact sepuluh kali (fan-out). Baris-baris tersebut lalu diagregasi HASH_GROUP_BY selama 2,31 detik — hampir seluruh waktu query. Hotspot sejatinya bukan operator yang paling atas maupun paling bawah, melainkan jumlah baris yang mengalir di tengah.

Jejak fan-out juga terlihat di hasil: kolom jumlah bernilai 16.666.670 — tepat sepuluh kali nilai seharusnya. Kesalahan angka laporan semacam ini sering jadi petunjuk pertama sebelum profiling dijalankan.

Perbaikan, Ukur Ulang, dan Kapan Berhenti #

Akar masalahnya data, bukan rencana eksekusi, sehingga perbaikannya satu kalimat SQL: deduplikasi tabel dim, lalu jalankan query yang sama terhadap tabel bersih tersebut:

con.execute("CREATE OR REPLACE TABLE voucher_bersih AS "
            "SELECT DISTINCT voucher_id, jenis FROM voucher")
Q_BAIK = Q_LAMBAT.replace("voucher v", "voucher_bersih v")
d_baik, hasil_baik = ukur(Q_BAIK, n_run=5)

Output yang Dihasilkan:

=== Query setelah perbaikan: median 5 run = 0.108 s ===
  ('cashback_5k', 1666667, Decimal('128958338250'))
  ('diskon_10', 1666667, Decimal('128958380000'))
  ('gratis_ongkir', 1666666, Decimal('128958281750'))

=== Kutipan EXPLAIN ANALYZE setelah perbaikan ===
  Total Time: 0.137s
  HASH_GROUP_BY
  3 rows
  0.12s
  HASH_JOIN
  Join Type: INNER
  Conditions:
  voucher_id = voucher_id
  5,000,000 rows
  0.10s
  TABLE_SCAN                 TABLE_SCAN
  Table:                     Table:
  memory.main.pesanan     memory.main.voucher_bersih
  Type: Sequential Scan      Type: Sequential Scan
  5,000,000 rows                 3 rows
  0.01s                     (0.00s)

=== Sebelum vs sesudah ===
versi          waktu (s)   join keluar    diagregasi
voucher 30x        2.272    50,000,000    50,000,000
voucher 3x         0.108     5,000,000     5,000,000
speedup 21x | setiap angka jumlah lama tepat 10x angka baru: True

Perbaikan ini 21 kali lebih cepat tanpa satu pun operator ditambah atau diganti: jumlah baris yang mengalir cukup dipangkas menjadi sepersepuluhnya, dan seluruh operator ikut cepat. Kapan kita berhenti mengoptimalkan query ini? Tiga kriteria praktis: query sudah berada jauh di bawah anggaran waktunya; kandidat perbaikan berikutnya lebih kecil daripada pita noise pengukuran; dan profil sudah berubah bentuk — hotspot terbesar kini hanya 0,12 detik pada agregasi, sehingga usaha lebih lanjut tidak lagi sebanding dengan hasilnya.

Satu catatan kejujuran angka: nilai mutlak seperti 2,272 dan 0,108 detik berbeda antar mesin dan antar sesi. Yang stabil adalah polanya — 50 juta vs 5 juta baris di join, dan speedup satu sampai dua orde besaran. Referensi lengkap EXPLAIN ANALYZE tersedia di dokumentasi DuckDB .

Hotspot kasus kita berakhir di join, dan TABLE_SCAN yang 0,02 detik memang tak perlu disentuh. Namun ketika data tumbuh jauh melebihi memori dan query hanya menyentuh sebagian kecil baris, scan penuh menjadi biaya terbesar berikutnya — dan di situlah index serta partitioning memangkas data sebelum dibaca. Chapter Indexing dan Partitioning melanjutkan.