Go: تحليل أداء Go

❌ Database too slow? — But queries only take 2ms
❌ Downstream service timeout? — Called it and the response is normal
❌ Network latency? — All in the same datacenter
✅ Actual cause: string concatenation causing massive memory allocation + frequent GC

import (
    "net/http"
    _ "net/http/pprof"  // One line to enable pprof
)

func main() {
    // pprof endpoints auto-registered at /debug/pprof/
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()
    // Business code continues running...
}

# Collect 30-second CPU profile
go tool pprof -http=:8081 http://localhost:6060/debug/pprof/profile?seconds=30

# Result: flame graph shows strings.Builder only uses 2% CPU,
# while strings.Join + garbage collection uses 78% CPU!

package main

import (
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"  // Import to auto-register pprof endpoints
    "time"
)

func slowFunction() {
    // Simulate a slow function
    var result string
    for i := 0; i < 100000; i++ {
        result += fmt.Sprintf("%d ", i) // Bad string concatenation
    }
}

func main() {
    // Start pprof HTTP service (separate port, not exposed externally)
    go func() {
        log.Println("pprof listening on :6060")
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    // Business service
    http.HandleFunc("/work", func(w http.ResponseWriter, r *http.Request) {
        slowFunction()
        fmt.Fprintln(w, "done")
    })

    log.Println("Business service listening on :8080")
    log.Fatal(http.ListenAndServe(":8080", nil))
}

# pprof endpoints:
# http://localhost:6060/debug/pprof/          — index
# http://localhost:6060/debug/pprof/profile   — CPU profile (default 30s)
# http://localhost:6060/debug/pprof/heap      — Heap profile
# http://localhost:6060/debug/pprof/goroutine — goroutine info
# http://localhost:6060/debug/pprof/block     — block analysis
# http://localhost:6060/debug/pprof/mutex     — lock contention analysis

// string_bench_test.go
package main

import (
    "strings"
    "testing"
)

// Bad approach: + concatenation
func BenchmarkStringPlus(b *testing.B) {
    for i := 0; i < b.N; i++ {
        var s string
        for j := 0; j < 1000; j++ {
            s += "a"
        }
    }
}

// Good approach: strings.Builder
func BenchmarkStringBuilder(b *testing.B) {
    for i := 0; i < b.N; i++ {
        var sb strings.Builder
        for j := 0; j < 1000; j++ {
            sb.WriteString("a")
        }
        _ = sb.String()
    }
}

// Good approach: pre-allocate
func BenchmarkStringBuilderPrealloc(b *testing.B) {
    for i := 0; i < b.N; i++ {
        var sb strings.Builder
        sb.Grow(1000)
        for j := 0; j < 1000; j++ {
            sb.WriteString("a")
        }
        _ = sb.String()
    }
}

# Run benchmark (view memory allocations)
$ go test -bench=. -benchmem -count=3

# Generate CPU profile
$ go test -bench=. -cpuprofile=cpu.prof -memprofile=mem.prof

# Analyze profile
$ go tool pprof -http=:8081 cpu.prof

package main

import (
    "log"
    "net/http"
    _ "net/http/pprof"
    "strings"
)

func heavyCPU() string {
    var sb strings.Builder
    for i := 0; i < 10000; i++ {
        sb.WriteString("hello")
        sb.WriteString(" ")
        sb.WriteString("world")
        sb.WriteString("\n")
    }
    return sb.String()
}

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    http.HandleFunc("/cpu", func(w http.ResponseWriter, r *http.Request) {
        result := heavyCPU()
        w.Write([]byte(result[:100]))
    })

    log.Fatal(http.ListenAndServe(":8080", nil))
}

# Collect CPU profile (access /cpu endpoint multiple times within 30 seconds)
$ go tool pprof -http=:8081 http://localhost:6060/debug/pprof/profile?seconds=30

# CLI mode
$ go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
(pprof) top       # Show Top 10 hot functions
(pprof) list main # View per-line time in the main package
(pprof) web       # Open visualization in browser

(pprof) top
Showing nodes accounting for 4.56s, 82.31% of 5.54s total
Dropped 28 nodes (cum <= 0.03s)
      flat  flat%   sum%        cum   cum%
     2.34s 42.24% 42.24%      2.34s 42.24%  runtime.memmove
     1.12s 20.22% 62.46%      1.12s 20.22%  runtime.mallocgc
     0.56s 10.11% 72.57%      0.56s 10.11%  strings.(*Builder).copy
     ...

package main

import (
    "log"
    "net/http"
    _ "net/http/pprof"
)

var leak []string  // Global variable, never garbage collected

func memoryLeak() {
    // Appends 10000 entries on each call, never clears
    for i := 0; i < 10000; i++ {
        leak = append(leak, "leaked string data")
    }
}

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    http.HandleFunc("/leak", func(w http.ResponseWriter, r *http.Request) {
        memoryLeak()
        w.Write([]byte("leaked"))
    })

    log.Fatal(http.ListenAndServe(":8080", nil))
}

# Collect heap profile (view current memory allocation)
$ go tool pprof -http=:8081 http://localhost:6060/debug/pprof/heap

# View functions with the most allocations
$ go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap
(pprof) top
(pprof) list main.memoryLeak

# Four viewing modes:
-inuse_space  # Currently in-use memory (default)
-inuse_objects # Currently in-use object count
-alloc_space  # Total allocated memory
-alloc_objects # Total allocated object count

# Use alloc_space to find leaks (see who allocates the most)
$ go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap

# View goroutine count and status
$ go tool pprof http://localhost:6060/debug/pprof/goroutine

# View goroutine stack trace (text)
$ curl http://localhost:6060/debug/pprof/goroutine?debug=2

package main

import (
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"
    "time"
)

func leakyGoroutine() {
    ch := make(chan int)
    go func() {
        // This goroutine will never exit
        val := <-ch  // Blocks forever
        fmt.Println(val)
    }()
    // ch will never receive data
}

func main() {
    go func() {
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    http.HandleFunc("/leak", func(w http.ResponseWriter, r *http.Request) {
        leakyGoroutine()
        w.Write([]byte("leaked"))
    })

    log.Fatal(http.ListenAndServe(":8080", nil))
}

$ curl http://localhost:6060/debug/pprof/goroutine?debug=2
# The output shows each goroutine's stack trace:
# goroutine 5 [chan receive]:
# main.leakyGoroutine.func1()
#     /app/main.go:14
# If you see many [chan receive] with no corresponding sender → leak

// bench_test.go
package main

import (
    "encoding/json"
    "testing"
)

type Data struct {
    ID    int    `json:"id"`
    Name  string `json:"name"`
    Email string `json:"email"`
}

// Benchmark: JSON serialization performance
func BenchmarkJSONMarshal(b *testing.B) {
    data := Data{ID: 1, Name: "Alice", Email: "alice@example.com"}

    for i := 0; i < b.N; i++ {
        _, err := json.Marshal(data)
        if err != nil {
            b.Fatal(err)
        }
    }
}

// Benchmark: JSON serialization + pre-allocated buffer
func BenchmarkJSONMarshalBuffer(b *testing.B) {
    data := Data{ID: 1, Name: "Alice", Email: "alice@example.com"}
    buf := make([]byte, 0, 256)

    for i := 0; i < b.N; i++ {
        buf = buf[:0]
        result, err := json.Marshal(data)
        if err != nil {
            b.Fatal(err)
        }
        buf = append(buf, result...)
    }
}

$ go test -bench=. -benchmem -count=5 ./...
BenchmarkJSONMarshal-8          10000000   156.2 ns/op   48 B/op   1 allocs/op
BenchmarkJSONMarshalBuffer-8    10000000   158.1 ns/op   48 B/op   1 allocs/op

package main

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

func main() {
    // Create trace file
    f, _ := os.Create("trace.out")
    defer f.Close()

    // Start trace
    trace.Start(f)
    defer trace.Stop()

    // Run code under test
    var wg sync.WaitGroup
    for i := 0; i < 10; i++ {
        wg.Add(1)
        go func(id int) {
            defer wg.Done()
            result := fibonacci(30)
            fmt.Printf("Worker %d: %d\n", id, result)
        }(i)
    }
    wg.Wait()
}

func fibonacci(n int) int {
    if n <= 1 {
        return n
    }
    return fibonacci(n-1) + fibonacci(n-2)
}

# After generating the trace file, view it in a browser
$ go tool trace trace.out
# Opens the browser, showing:
# - Goroutine analysis: how long each goroutine ran
# - Scheduling latency: when goroutines were scheduled
# - Network blocking: what goroutines are waiting for
# - System calls: when GC ran

// debug_demo.go
package main

import (
    "encoding/json"
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"
    "strings"
)

// ---------- Slow API ----------

type UserResponse struct {
    ID    int    `json:"id"`
    Name  string `json:"name"`
    Email string `json:"email"`
    Bio   string `json:"bio"`
}

// Bad version: string concatenation + heavy allocation
func generateUserJSON(userID int) []byte {
    var bio strings.Builder
    // Simulate generating a large amount of text
    for i := 0; i < 1000; i++ {
        bio.WriteString(fmt.Sprintf("Line %d: User data for ID %d with some additional info\n", i, userID))
    }

    resp := UserResponse{
        ID:    userID,
        Name:  fmt.Sprintf("User_%d", userID),
        Email: fmt.Sprintf("user%d@example.com", userID),
        Bio:   bio.String(),
    }

    data, _ := json.Marshal(resp)
    return data
}

// Optimized version: pre-allocation + reduced formatting
func generateUserJSONOptimized(userID int) []byte {
    // Pre-allocate buffer
    var bio strings.Builder
    bio.Grow(50000)  // Estimated size

    for i := 0; i < 1000; i++ {
        bio.WriteString("Line ")
        bio.WriteString(fmt.Sprintf("%d", i))  // Can be further optimized with strconv.Itoa
        bio.WriteString(": User data for ID ")
        bio.WriteString(fmt.Sprintf("%d", userID))
        bio.WriteString(" with some additional info\n")
    }

    resp := UserResponse{
        ID:    userID,
        Name:  "User_" + fmt.Sprintf("%d", userID),
        Email: fmt.Sprintf("user%d@example.com", userID),
        Bio:   bio.String(),
    }

    data, _ := json.Marshal(resp)
    return data
}

// ---------- Analysis workflow ----------

/*
Debugging workflow:

(1) Step 1: Start pprof HTTP server
go run main.go (automatically starts pprof on :6060)

(2) Step 2: Load test
# In another terminal, send continuous requests
while true; do curl http://localhost:8080/user/1 > /dev/null; done

(3) Step 3: Collect CPU profile
go tool pprof -http=:8081 http://localhost:6060/debug/pprof/profile?seconds=30

(4) Step 4: View flame graph in browser
- Look for the widest color blocks → hot functions
- If you see runtime.memmove / runtime.mallocgc → excessive memory allocation
- Click main.generateUserJSON → view per-line code timing

(5) Step 5: View Heap profile
go tool pprof -alloc_space http://localhost:6060/debug/pprof/heap
(pprof) top
*/

func main() {
    // pprof
    go func() {
        log.Println("pprof on :6060")
        log.Println(http.ListenAndServe("localhost:6060", nil))
    }()

    // Business endpoint
    http.HandleFunc("/user/{id}", func(w http.ResponseWriter, r *http.Request) {
        id := r.PathValue("id")
        var userID int
        fmt.Sscanf(id, "%d", &userID)

        data := generateUserJSON(userID)
        w.Header().Set("Content-Type", "application/json")
        w.Write(data)
    })

    log.Println("Service listening on :8080")
    log.Fatal(http.ListenAndServe(":8080", nil))
}