Profiling

Cost centre, profil heap, dan penafsiran laporannya.

Daftar isi

Program yang benar belum tentu program yang efisien, dan intuisi tentang letak kemahalannya sering keliru. Profiling (profiling) adalah pengukuran yang memetakan biaya waktu dan memori ke bagian-bagian program, sehingga perbaikan performa diarahkan ke tempat yang benar-benar mahal. GHC menyediakan dua lapis pengukuran, yaitu tabel cost centre yang menghitung waktu dan alokasi per fungsi, serta profil heap yang merekam isi memori seiring berjalannya program. Topik ini membahas persiapan program, membaca kedua laporan itu, dan tanda peringatan yang menyertainya.

Program uji dan kompilasi berprofil#

Program berikut menghitung penjumlahan list besar dengan dua cara, yaitu foldl yang menumpuk perhitungan tertunda dan foldl' yang memaksa akumulator setiap langkah. Hasilnya sama, tetapi biayanya tidak, dan perbedaan itulah yang akan dibaca pada laporan profil.

haskell uji-kinerja.hs
import Data.List (foldl')

jumlahLambat :: [Int] -> Int
jumlahLambat = foldl (+) 0

jumlahCepat :: [Int] -> Int
jumlahCepat = foldl' (+) 0

main :: IO ()
main = do
  print (jumlahLambat [1 .. 300000])
  print (jumlahCepat [1 .. 300000])
text Keluaran
45000150000
45000150000

Keluaran di atas berasal dari eksekusi biasa, yang cukup untuk memastikan programnya benar. Pengukuran memerlukan biner yang dikompilasi dengan tiga flag, yaitu -prof yang mengaktifkan dukungan profiling, -rtsopts yang mengizinkan opsi runtime pada saat program dijalankan, serta -fprof-auto yang menandai setiap fungsi yang dideklarasikan sebagai cost centre, yaitu satuan pengukuran yang menampung biaya fungsi tersebut beserta bagian yang dipanggilnya.

bash
# tidak-dijalankan
# kompilasi program dengan dukungan profiling
ghc -prof -rtsopts -fprof-auto uji-kinerja.hs -o uji-kinerja

Kompilasi berprofil tidak dapat direproduksi pada lingkungan contoh jalur ini karena memerlukan varian berprofiling dari seluruh paket yang terpasang, sehingga bentuk perintah dan keluarannya diambil dari dokumentasi resmi GHC. Perintah di atas tidak mencetak apa pun apabila berhasil, dan laporan pengukuran baru muncul ketika biner dijalankan dengan opsi RTS.

Cost centre dengan +RTS -p#

Biner berprofil dijalankan seperti program biasa, dengan tambahan opsi +RTS ... -RTS yang dipisahkan dari argumen program. Opsi -p memerintahkan runtime mengumpulkan biaya per cost centre dan menuliskan laporannya ke berkas uji-kinerja.prof.

bash
# tidak-dijalankan
# jalankan biner berprofil dan minta laporan cost centre
./uji-kinerja +RTS -p
cat uji-kinerja.prof

Bentuk laporannya seperti contoh berikut, yang diambil dari program contoh pada dokumentasi GHC.

text Keluaran yang diharapkan
        Wed Oct 12 16:14 2011 Time and Allocation Profiling Report  (Final)

           Main +RTS -p -RTS

        total time  =        0.68 secs   (34 ticks @ 20 ms)
        total alloc = 204,677,844 bytes  (excludes profiling overheads)

COST CENTRE MODULE  %time %alloc

fib         Main    100.0  100.0


                                                      individual     inherited
COST CENTRE MODULE                  no.     entries  %time %alloc   %time %alloc

MAIN        MAIN                    102           0    0.0    0.0   100.0  100.0
 CAF        GHC.IO.Handle.FD        128           0    0.0    0.0     0.0    0.0
 CAF        GHC.IO.Encoding.Iconv   120           0    0.0    0.0     0.0    0.0
 CAF        GHC.Conc.Signal         110           0    0.0    0.0     0.0    0.0
 CAF        Main                    108           0    0.0    0.0   100.0  100.0
  main      Main                    204           1    0.0    0.0   100.0  100.0
   fib      Main                    205     2692537  100.0  100.0   100.0  100.0

Bagian atas laporan merangkum total waktu dan total alokasi, sedangkan tabelnya dibaca kolom demi kolom, yaitu entries untuk berapa kali cost centre dipanggil, %time untuk porsi waktu, dan %alloc untuk porsi alokasi memori, masing-masing dalam versi individual dan inherited. Nilai individual menyatakan biaya cost centre itu sendiri, sedangkan inherited menambahkan biaya seluruh bagian yang dipanggilnya, sehingga penjumlahan kedua versi tetap terbaca sebagai pohon. Angka waktunya berasal dari pengambilan sampel, sehingga nilainya berubah antar eksekusi dan hanya proporsi besarnya yang layak dibandingkan.

Menafsirkan laporan#

Pada program uji di atas, pola yang diharapkan muncul pada kolom %alloc, yaitu jumlahLambat menguasai alokasi karena setiap langkah penjumlahannya menumpuk thunk sebesar sel listnya, sedangkan jumlahCepat berbagi porsi kecil. Pola semacam ini adalah temuan yang paling sering diambil dari profil, yaitu perbedaan besar pada %alloc dengan %time yang relatif kecil, tanda pekerjaan yang menumpuk memori tanpa banyak komputasi. Kebalikannya juga bermakna, karena %time yang tinggi dengan %alloc rendah menandakan perhitungan murni yang mahal, misalnya aritmetika berulang.

Cost centre yang dihasilkan -fprof-auto mengikuti struktur fungsi yang dideklarasikan, sehingga tabelnya langsung menampilkan nama-nama fungsi program. Apabila pemisahan yang lebih halus diperlukan, anotasi {-# SCC "nama" #-} menandai ekspresi mana pun sebagai cost centre dengan nama yang ditentukan sendiri, dan laporan kemudian menampilkan bagian-bagian kecil di dalam fungsi yang sama.

Profil heap dengan +RTS -hc#

Lapis kedua mengukur isi memori, bukan waktu. Opsi -hc merekam sampel heap yang dikelompokkan menurut cost centre pembuatnya, dan berkas hasilnya dikonversi menjadi gambar oleh hp2ps.

bash
# tidak-dijalankan
# rekam profil heap lalu ubah menjadi grafik PostScript
./uji-kinerja +RTS -hc
hp2ps uji-kinerja.hp

Alur lengkapnya merangkum seluruh pembahasan ini, dari sumber program sampai kedua laporan yang dibaca.

uji-kinerja.hs(sumber)uji-kinerjaghc -prof -rtsopts -fprof-autouji-kinerja.proftabel cost centreuji-kinerja.hpdata profil heap+RTS -p+RTS -hcuji-kinerja.psgrafik heaphp2ps
Alur profiling, dari kompilasi berprofil sampai laporan cost centre dan grafik heap

Grafik heap menggunakan sumbu datar sebagai waktu berjalan dan sumbu tegak sebagai memori terpakai, dengan warna yang membagi penyumbangnya menurut cost centre. Pada program uji, grafiknya akan menunjukkan memori yang naik mendekati puncak saat jumlahLambat menumpuk thunk-nya, kemudian turun ketika akhirnya dihitung, bentuk yang menjadi tanda pengenal akumulasi tertunda. Profil heap menjadi pelengkap tabel cost centre karena temuan akumulasi pada tabel dapat dikonfirmasi secara visual di sini.

Kesalahan umum#

Kesalahan pertama adalah menjalankan biner tanpa flag -rtsopts pada kompilasinya. Opsi +RTS -p ditolak oleh runtime dengan pesan yang meminta program dibangun ulang dengan -rtsopts, sehingga flag itu perlu hadir sejak awal, bukan diselipkan saat pengukuran. Kesalahan kedua berupa membandingkan waktu absolut antara program biasa dan program berprofil, karena build berprofil menghasilkan kode yang berbeda dengan biaya tambahan pengukuran, sehingga angka profiling digunakan untuk membandingkan porsi antarbagian, bukan untuk mengklaim kecepatan mutlak.

Kesalahan ketiga berupa memprofilkan program yang dijalankan melalui runghc, karena pengukuran cost centre hanya berlaku pada biner hasil kompilasi -prof, sedangkan runghc menafsirkan kode tanpa laporan pengukuran. Setiap kesalahan tersebut berujung pada laporan yang hilang atau angka yang menyesatkan, dan kedua akibat itu dicegah dengan pola yang sama, yaitu flag -prof, -rtsopts, dan -fprof-auto dipasang bersama sejak kompilasi.

Ringkasan#

  • Profiling memerlukan kompilasi -prof -rtsopts -fprof-auto, yaitu dukungan pengukuran, izin opsi runtime, dan penandaan fungsi sebagai cost centre.
  • +RTS -p menulis tabel cost centre berisi entries, %time, dan %alloc dalam versi individual dan inherited, dengan angka waktu yang berubah antar eksekusi.
  • Porsi %alloc yang tinggi dengan %time kecil menandai penumpukan struktur tertunda, dan anotasi SCC memungkinkan pengukuran yang lebih halus.
  • +RTS -hc beserta hp2ps menghasilkan grafik heap yang mengonfirmasi temuan tabel secara visual.

Referensi#