Profil CPU dan heap menjawab “berapa banyak”, tetapi program concurrent sering sakit karena pertanyaan “kapan”: goroutine yang saling menunggu, penjadwal yang memindah-mindahkan kerja, GC yang menyela di detik kritis. Execution tracer merekam linimasa peristiwa runtime — pembuatan goroutine, blocking pada channel, preemption, siklus GC — ke satu berkas lengkap dengan urutan waktunya. Pada chapter ini kita merekam trace dari program empat goroutine, membuka berkasnya dengan go tool trace, dan mengekstrak profil latensi penjadwal tanpa membuka browser.

Merekam Linimasa Eksekusi #

API-nya sesederhana profiler: trace.Start(berkas) membuka perekaman, trace.Stop() menutupnya. Berkas contoh.go di bawah halaman menjalankan empat goroutine yang masing-masing menjumlahkan bilangan, mengumpulkan hasilnya lewat channel ber-buffer, lalu memanggil trace.Stop sebelum program berakhir:

go
package main

import (
	"fmt"
	"os"
	"runtime/trace"
	"sync"
)

// hitungTotal menjumlahkan bilangan dari 0 sampai n-1.
func hitungTotal(n int) int {
	total := 0
	for i := range n {
		total += i
	}
	return total
}

func main() {
	berkas, err := os.CreateTemp("", "trace-*.out")
	if err != nil {
		fmt.Println("gagal membuat berkas trace:", err)
		return
	}

	if err := trace.Start(berkas); err != nil {
		fmt.Println("gagal memulai trace:", err)
		return
	}

	// Empat goroutine dikerjakan penjadwal; hasilnya dikumpulkan lewat channel.
	hasil := make(chan int, 4)
	var wg sync.WaitGroup
	for i := 1; i <= 4; i++ {
		wg.Add(1)
		go func(bagian int) {
			defer wg.Done()
			hasil <- hitungTotal(bagian * 1000)
		}(i)
	}
	wg.Wait()
	close(hasil)

	jumlah := 0
	for v := range hasil {
		jumlah += v
	}

	trace.Stop()
	berkas.Close()

	fmt.Println("jumlah total:", jumlah)
	fmt.Println("trace berhasil dibuat: true")
}

Output yang Dihasilkan:

text
jumlah total: 14995000
trace berhasil dibuat: true

Program sengaja tidak mencetak ukuran berkas trace karena angkanya bergantung pada jumlah peristiwa yang terekam dan berubah antar eksekusi. Mari kita telaah baris demi baris program di atas:

  1. Baris 20–24: os.CreateTemp menyiapkan berkas keluaran dengan pola trace-*.out; path pastinya acak dan tidak dicetak.
  2. Baris 26–29 (trace.Start): dari titik ini runtime mencatat setiap peristiwa penjadwalan ke berkas; overhead perekaman sengaja dibuat kecil agar tidak mengubah perilaku program.
  3. Baris 31–40: empat goroutine dibuat di dalam jendela rekam; channel ber-buffer 4 membuat goroutine tidak pernah terblok saat mengirim hasil.
  4. Baris 41–47: wg.Wait() memblok main hingga semua selesai — peristiwa blocking ini sendiri terekam sebagai data berharga.
  5. Baris 49–53: trace.Stop() wajib dipanggil agar footer berkas ditulis; tanpa itu berkas rusak dan tidak bisa dibaca.

Membuka Trace dengan go tool trace #

Berbeda dengan pprof, go tool trace menampilkan datanya sebagai halaman visual di browser. Perintah berikut membangun server HTTP lokal lalu membuka jendela trace:

bash
go tool trace /tmp/trace-XXXX.out

Perintah itu membuka browser secara otomatis; berikut ringkasan opsi-opsinya sesuai bantuan resmi go tool trace yang dicetak saat dijalankan tanpa argumen:

text
Usage of 'go tool trace':
Given a trace file produced by 'go test':
        go test -trace=trace.out pkg

Open a web browser displaying trace:
        go tool trace [flags] [pkg.test] trace.out

Generate a pprof-like profile from the trace:
    go tool trace -pprof=TYPE [pkg.test] trace.out

[pkg.test] argument is required for traces produced by Go 1.6 and below.
Go 1.7 does not require the binary argument.

Supported profile types are:
    - net: network blocking profile
    - sync: synchronization blocking profile
    - syscall: syscall blocking profile
    - sched: scheduler latency profile

Flags:
        -http=addr: HTTP server listen address (e.g., ':6060')
        -pprof=type: print a pprof-like profile instead
        -d=mode: print debug info and exit (modes: wire, parsed, footprint)

When providing only a port to -http (e.g., ':6060'), the tool listens only on localhost.
To listen on all addresses, explicitly add the unspecified address (e.g., '0.0.0.0:6060').

Halaman utama tracer menyajikan ringkasan in-process: jumlah goroutine per status, durasi GC, serta tabel Network/Syscall/Sync blocking dan Scheduler latency. View trace memperlihatkan garis waktu per-P (processor logis) — kapan goroutine berjalan, menunggu, atau disalahkan GC — sehingga jeda aneh antar goroutine bisa dilihat langsung dengan mata.

Profil Penjadwal Tanpa Browser #

Untuk scripting dan server jauh, go tool trace -pprof=sched mengubah trace menjadi profil latensi penjadwal bergaya pprof:

bash
go tool trace -pprof=sched /tmp/trace-XXXX.out > sched.prof
go tool pprof -top sched.prof

Output yang Dihasilkan:

text
Main binary filename not available.
Type: delay
Showing nodes accounting for 320ns, 100% of 320ns total
      flat  flat%   sum%        cum   cum%
     320ns   100%   100%      320ns   100%  sync.(*WaitGroup).Add
         0     0%   100%      320ns   100%  main.main.func1
         0     0%   100%      320ns   100%  sync.(*WaitGroup).Done

Satu kelas bug concurrency masih tak terlihat di trace maupun profil: data race, yang diam-diam merusak data tanpa jejak waktu. Race detector menutup celah itu pada chapter berikutnya.

Referensi #

Berkas Sumber

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

contoh.go

Unduh berkas
go
package main

import (
	"fmt"
	"os"
	"runtime/trace"
	"sync"
)

// hitungTotal menjumlahkan bilangan dari 0 sampai n-1.
func hitungTotal(n int) int {
	total := 0
	for i := range n {
		total += i
	}
	return total
}

func main() {
	berkas, err := os.CreateTemp("", "trace-*.out")
	if err != nil {
		fmt.Println("gagal membuat berkas trace:", err)
		return
	}

	if err := trace.Start(berkas); err != nil {
		fmt.Println("gagal memulai trace:", err)
		return
	}

	// Empat goroutine dikerjakan penjadwal; hasilnya dikumpulkan lewat channel.
	hasil := make(chan int, 4)
	var wg sync.WaitGroup
	for i := 1; i <= 4; i++ {
		wg.Add(1)
		go func(bagian int) {
			defer wg.Done()
			hasil <- hitungTotal(bagian * 1000)
		}(i)
	}
	wg.Wait()
	close(hasil)

	jumlah := 0
	for v := range hasil {
		jumlah += v
	}

	trace.Stop()
	berkas.Close()

	fmt.Println("jumlah total:", jumlah)
	fmt.Println("trace berhasil dibuat: true")
}