Golang: 可観測性とプロファイリングにより、ほぼ検出不可能なスロットリングがどのように明らかにされたか

Go との個人プロジェクトで、Bovespa から金融資産に関する情報を取得します。
このシステムはゴルーチンによる同時実行性と並列性を最大限に活用し、8 秒ごとに資産情報を (ビジネス計算とともに) 更新します。
当初、エラーや警告は表示されませんでしたが、一部のゴルーチンの実行に他のゴルーチンよりも時間がかかっていることに気付きました。

より具体的に言うと、p99 時間は 0.03 ms でしたが、ある時点では 0.9 ms まで増加しました。これにより、問題をさらに調査することになりました。

GOMAXPROCS 変数に基づいて作成されたセマフォ goroutine プールを使用していることがわかりました。
しかし、このアプローチには問題があることに気づきました。

GOMAXPROCS 変数を使用すると、コンテナーで使用可能なコアの数が正しく取得されません。コンテナーの使用可能なコアが VM の合計よりも少ない場合、VM の合計が考慮されます。たとえば、私の VM には利用可能なコアが 8 個ありますが、コンテナーには 4 個しかありませんでした。これにより、同時に実行する 8 つの goroutine が作成され、スロットリングが発生しました。

一晩かけて多くの調査を行った結果、コンテナ内にあるかどうかに関係なく、GOMAXPROCS 変数をより効率的に自動的に調整する Uber によって開発されたライブラリを発見しました。このソリューションは非常に安定していて効率的であることが証明されました: automaxprocs

ウーバーゴー / automaxproc

Linux コンテナーの CPU クォータと一致するように GOMAXPROCS を自動的に設定します。

automaxprocs

Linux コンテナーの CPU クォータに一致するように GOMAXPROCS を自動的に設定します。

インストール

go get -u go.uber.org/automaxprocs

クイックスタート

import _ "go.uber.org/automaxprocs"

func main() {
  // Your application logic here.
}

パフォーマンス

Uber の内部ロード バランサーから測定されたデータ。 200% の CPU クォータ (つまり 2 コア) でロード バランサーを実行しました:

GOMAXPROCS	RPS	P50 (ms)	P99.9 (ms)
1	28,893.18	1.46	19.70
2 (equal to quota)	44,715.07	0.84	26.38
3	44,212.93	0.66	30.07
4	41,071.15	0.57	42.94
8	33,111.69	0.43	64.32
Default (24)	22,191.40	0.45	76.19

When GOMAXPROCS is increased above the CPU quota, we see P50 decrease slightly, but see significant increases to P99. We also see that the total RPS handled also decreases.

When GOMAXPROCS is higher than the CPU quota allocated, we also saw significant throttling:

$ cat /sys/fs/cgroup/cpu,cpuacct/system.slice/[...]/cpu.stat
nr_periods 42227334
nr_throttled 131923
throttled_time 88613212216618

Once GOMAXPROCS was reduced to match the CPU quota, we saw no CPU throttling.

…

View on GitHub

.

Após implementar o uso dessa biblioteca, o problema foi resolvido, e agora o tempo p99 se manteve em 0.02 ms constantemente. Essa experiência destacou a importância da observabilidade e do profiling em sistemas concorrentes.

A seguir um exemplo bem simples, mas que consegue demonstrar a diferença de desempenho.

Utilizando o pacote nativo de testes e benckmak do Go, criei dois arquivos:

benchmarking_with_enhancement_test.go:

package main

import (
    _ "go.uber.org/automaxprocs"
    "runtime"
    "sync"
    "testing"
)

// BenchmarkWithEnhancement Função com melhoria, para adicionar o indice do loop em um array de inteiro
func BenchmarkWithEnhancement(b *testing.B) {
    // Obtém o número de CPUs disponíveis
    numCPUs := runtime.NumCPU()
    // Define o máximo de CPUs para serem usadas pelo programa
    maxGoroutines := runtime.GOMAXPROCS(numCPUs)
    // Criação do semáforo
    semaphore := make(chan struct{}, maxGoroutines)

    var (
        // Espera para grupo de goroutines finalizar
        wg sync.WaitGroup
        // Propriade
        mu sync.Mutex
        // Lista para armazenar inteiros
        list []int
    )

    // Loop com mihão de indices
    for i := 0; i < 1000000; i++ {
        semaphore <- struct{}{}
        // Adiciona ao waitGroup que existe mais uma goroutine para ser executada
        wg.Add(1)

        // Atribui a função a uma nova goroutine
        go func(i int) {
            // Quando a função finalizar, informa o semáforo e finaliza um registro do waitGroup
            defer func() {
                <-semaphore
                wg.Done()
            }()
            // Faz o bloqueio do array para outra goroutine não sobreescrever
            mu.Lock()
            // Adiciona o indice, em mais uma posição no array
            list = append(list, i)
            // Desbloqueia o array
            mu.Unlock()
        }(i)
    }
}

benchmarking_without_enhancement_test.go:

package main

import (
    "runtime"
    "sync"
    "testing"
)

// BenchmarkWithoutEnhancement Função sem a melhoria, para adicionar o indice do loop em um array de inteiro
func BenchmarkWithoutEnhancement(b *testing.B) {
    // Obtém o número de CPUs disponíveis
    numCPUs := runtime.NumCPU()
    // Define o máximo de CPUs para serem usadas pelo programa
    maxGoroutines := runtime.GOMAXPROCS(numCPUs)
    // Criação do semáforo
    semaphore := make(chan struct{}, maxGoroutines)

    var (
        // Espera para grupo de goroutines finalizar
        wg sync.WaitGroup
        // Propriade
        mu sync.Mutex
        // Lista para armazenar inteiros
        list []int
    )

    // Loop com mihão de indices
    for i := 0; i < 1000000; i++ {
        semaphore <- struct{}{}
        // Adiciona ao waitGroup que existe mais uma goroutine para ser executada
        wg.Add(1)

        // Atribui a função a uma nova goroutine
        go func(i int) {
            // Quando a função finalizar, informa o semáforo e finaliza um registro do waitGroup
            defer func() {
                <-semaphore
                wg.Done()
            }()
            // Faz o bloqueio do array para outra goroutine não sobreescrever
            mu.Lock()
            // Adiciona o indice, em mais uma posição no array
            list = append(list, i)
            // Desbloqueia o array
            mu.Unlock()
        }(i)
    }
}

A diferença entra elas, é que uma esta com a importação de biblioteca da Uber.

Ao executar o benchmark passando que seriam usados 2 CPUs, o resultado foi:

ns/op: fornece uma média em nanosegundos de quanto tempo leva para executar uma operação específica.

Percebam, que o total disponível da minha CPU são 8 núcleos, e foi o que a propriedade runtime.NumCPU() retornou. Porém, como na execução do benchmark, defini que o uso seriam de apenas duas CPUs, a o arquivo que não utilizou a automaxprocs, definiu que o limite de execução por vez, seriam de 8 goroutines, enquanto o mais eficiente seriam 2, pois dessa maneira se usa menos alocação deixa mais eficiente a execução.

Então, fica nítido a importância de observabilidade e proffiling das nossas aplicações.