Machen Sie Ihre Go-Programme mit Profiling blitzschnell

German (Deutsch) translation by Tatsiana Bochkareva (you can also view the original English article)

Go wird häufig zum Schreiben verteilter Systeme, erweiterter Datenspeicher und Microservices verwendet. Die Leistung ist in diesen Bereichen der Schlüssel.

In diesem Tutorial erfahren Sie, wie Sie Ihre Programme profilieren, um sie blitzschnell (CPU besser nutzen) oder federleicht (weniger Speicher verwenden) zu machen. Ich werde mich mit CPU- und Speicherprofilen befassen, indem ich den pprof (den Go-Profiler) verwende, die Profile visualisiere und sogar Flammengraphen.

Bei der Profilerstellung wird die Leistung Ihres Programms in verschiedenen Dimensionen gemessen. Go bietet eine hervorragende Unterstützung für die Profilerstellung und kann die folgenden Abmessungen sofort profilieren:

eine Abtastung der CPU-Zeit pro Funktion UND Befehl
eine Stichprobe aller Heap-Zuordnungen
Stapelspuren aller aktuellen Goroutinen
Stack-Traces, die zur Erstellung neuer Betriebssystem-Threads führen
Stapelspuren, die zum Blockieren von Synchronisationsprimitiven führten
Stapeln Sie Spuren von Inhabern umstrittener Mutexe

Sie können sogar benutzerdefinierte Profile erstellen, wenn Sie möchten. Bei der Go-Profilerstellung wird eine Profildatei erstellt und anschließend mit dem Tool pprof go analysiert.

Wie Sie Profildateien erstellen

Es gibt verschiedene Möglichkeiten, eine Profildatei zu erstellen.

Verwenden von "go test" zum Generieren von Profildateien

Am einfachsten ist es, den go test zu verwenden. Es verfügt über mehrere Flags, mit denen Sie Profildateien erstellen können. So generieren Sie sowohl eine CPU-Profildatei als auch eine Speicherprofildatei für den Test im aktuellen Verzeichnis: go test -cpuprofile cpu.prof -memprofile mem.prof -bench.

Laden Sie Live-Profildaten von einem langjährigen Dienst herunter

Wenn Sie einen lang laufenden Webdienst profilieren möchten, können Sie die integrierte HTTP-Schnittstelle zum Bereitstellen von Profildaten verwenden. Fügen Sie irgendwo die folgende Importanweisung hinzu:

import _ "net/http/pprof"

Jetzt können Sie Live-Profildaten von der URL /debug /pprof/ herunterladen. Weitere Informationen finden Sie in der Dokumentation zum Paket net/http/pprof.

Profilerstellung im Code

Sie können Ihrem Code auch eine direkte Profilerstellung hinzufügen, um die vollständige Kontrolle zu erhalten. Zuerst müssen Sie runtime/pprof importieren. Die CPU-Profilerstellung wird durch zwei Aufrufe gesteuert:

pprof.StartCPUProfile()
pprof.StopCPUProfile()

Die Speicherprofilerstellung erfolgt durch Aufrufen von runtime.GC() gefolgt von pprof.WriteHeapProfile().

Alle Profilierungsfunktionen akzeptieren ein Dateihandle, für dessen ordnungsgemäßes Öffnen und Schließen Sie verantwortlich sind.

Das Beispielprogramm

Um den Profiler in Aktion zu sehen, verwende ich ein Programm, das das Problem 8 von Project Euler löst. Das Problem ist: Suchen Sie bei einer 1.000-stelligen Nummer die 13 benachbarten Ziffern in dieser Nummer, die das größte Produkt haben.

Hier ist eine triviale Lösung, die alle Sequenzen mit 13 Ziffern durchläuft und für jede solche Sequenz alle 13 Ziffern multipliziert und das Ergebnis zurückgibt. Das größte Ergebnis wird gespeichert und schließlich zurückgegeben:

package trivial

import (
    "strings"
)

func calcProduct(series string) int64 {
	digits := make([]int64, len(series))
	for i, c := range series {
		digits[i] = int64(c) - 48
	}

	product := int64(1)
	for i := 0; i < len(digits); i++ {
		product *= digits[i]
	}

	return product
}

func FindLargestProduct(text string) int64 {
	text = strings.Replace(text, "\n", "", -1)
	largestProduct := int64(0)
	for i := 0; i < len(text); i++ {
		end := i + 13
		if end > len(text) {
			end = len(text)
		}
		series := text[i:end]
		result := calcProduct(series)
		if result > largestProduct {
			largestProduct = result
		}
	}

	return largestProduct
}

Später, nach der Profilerstellung, werden wir einige Möglichkeiten sehen, um die Leistung mit einer anderen Lösung zu verbessern.

CPU-Profilerstellung

Lassen Sie uns die CPU unseres Programms profilieren. Ich werde die Go-Test-Methode mit diesem Test verwenden:

import (
    "testing"
)

const text = `
73167176531330624919225119674426574742355349194934
96983520312774506326239578318016984801869478851843
85861560789112949495459501737958331952853208805511
12540698747158523863050715693290963295227443043557
66896648950445244523161731856403098711121722383113
62229893423380308135336276614282806444486645238749
30358907296290491560440772390713810515859307960866
70172427121883998797908792274921901699720888093776
65727333001053367881220235421809751254540594752243
52584907711670556013604839586446706324415722155397
53697817977846174064955149290862569321978468622482
83972241375657056057490261407972968652414535100474
82166370484403199890008895243450658541227588666881
16427171479924442928230863465674813919123162824586
17866458359124566529476545682848912883142607690042
24219022671055626321111109370544217506941658960408
07198403850962455444362981230987879927244284909188
84580156166097919133875499200524063689912560717606
05886116467109405077541002256983155200055935729725
71636269561882670428252483600823257530420752963450
`

func TestFindLargestProduct(t *testing.T) {
	for i := 0; i < 100000; i++ {
		res := FindLargestProduct(text)
		expected := int64(23514624000)
		if res != expected {
			t.Errorf("Wrong!")
		}
	}
}

Beachten Sie, dass ich den Test 100.000 Mal ausführe, da der Go-Profiler ein Stichprobenprofiler ist, bei dem der Code tatsächlich eine erhebliche Zeit (mehrere Millisekunden kumuliert) für jede Codezeile benötigt. Hier ist der Befehl zum Vorbereiten des Profils:

go test -cpuprofile cpu.prof -bench .
ok _/github.com/the-gigi/project-euler/8/go/trivial	13.243s

Es dauerte etwas mehr als 13 Sekunden (für 100.000 Iterationen). Um das Profil anzuzeigen, rufen Sie jetzt mit dem Tool pprof go die interaktive Eingabeaufforderung auf. Es gibt viele Befehle und Optionen. Der grundlegendste Befehl ist topN; Mit der Option -cum werden die Top-N-Funktionen angezeigt, deren Ausführung die kumulativste Zeit in Anspruch genommen hat (eine Funktion, deren Ausführung nur sehr wenig Zeit in Anspruch nimmt, die jedoch häufig aufgerufen wird, kann sich oben befinden). Damit beginne ich normalerweise.

> go tool pprof cpu.prof
Type: cpu
Time: Oct 23, 2017 at 8:05am (PDT)
Duration: 13.22s, Total samples = 13.10s (99.06%)
Entering interactive mode (type "help" for commands)
(pprof) top5 -cum
Showing nodes accounting for 1.23s, 9.39% of 13.10s total
Dropped 76 nodes (cum <= 0.07s)
Showing top 5 nodes out of 53
 flat  flat%   sum%   cum   cum%
0.07s  0.53%  0.53%   10.64s 81.22%  FindLargestProduct
0      0%     0.53%   10.64s 81.22%  TestFindLargestProduct
0      0%     0.53%   10.64s 81.22%  testing.tRunner
1.07s  8.17%  8.70%   10.54s 80.46%  trivial.calcProduct
0.09s  0.69%  9.39%   9.47s  72.29%  runtime.makeslice

Lassen Sie uns die Ausgabe verstehen. Jede Zeile repräsentiert eine Funktion. Ich habe den Pfad zu jeder Funktion aus Platzgründen entfernt, aber er wird in der realen Ausgabe als letzte Spalte angezeigt.

Flat bedeutet die Zeit (oder den Prozentsatz), die innerhalb der Funktion verbracht wird, und Cum steht für kumulativ - die Zeit, die innerhalb der Funktion und aller von ihr aufgerufenen Funktionen verbracht wird. In diesem Fall, testing.tRunner ruft tatsächlich TestFindLargestProduct() auf, das FindLargestProduct() aufruft. Da dort jedoch praktisch keine Zeit verbracht wird, zählt der Stichprobenprofiler seine Flat-Zeit als 0.

Speicherprofilerstellung

Die Speicherprofilerstellung ist ähnlich, außer dass Sie ein Speicherprofil erstellen:

go test -memprofile mem.prof -bench .

PASS

ok      _/github.com/the-gigi/project-euler/8/go/trivial

Sie können Ihre Speichernutzung mit demselben Tool analysieren.

Verwenden von pprof zur Optimierung der Geschwindigkeit Ihres Programms

Mal sehen, was wir tun können, um das Problem schneller zu lösen. Wenn wir uns das Profil ansehen, sehen wir, dass calcProduct() 8,17% der flachen Laufzeit beansprucht, während makeSlice(), das von calcProduct() aufgerufen wird, 72% benötigt (kumulativ, weil es andere Funktionen aufruft). Dies gibt einen ziemlich guten Hinweis darauf, was wir optimieren müssen. Was macht der Code? Für jede Folge von 13 benachbarten Zahlen wird ein Slice zugewiesen:

func calcProduct(series string) int64 {
    digits := make([]int64, len(series))
    ...

Das sind fast 1.000 Mal pro Lauf und wir laufen 100.000 Mal. Speicherzuordnungen sind langsam. In diesem Fall muss nicht jedes Mal ein neues Slice zugewiesen werden. Tatsächlich ist es überhaupt nicht erforderlich, ein Slice zuzuweisen. Wir können einfach das Eingabearray scannen.

Der folgende Codeausschnitt zeigt, wie das laufende Produkt berechnet wird, indem einfach durch die erste Ziffer der vorherigen Sequenz dividiert und Multiplikation mit cur digit.

if cur == 1 {
	currProduct /= old
	continue
}

if old == 1 {
	currProduct *= cur
} else {
	currProduct = currProduct / old * cur
}

if currProduct > largestProduct {
	largestProduct = currProduct
}

Hier ist eine kurze Liste einiger algorithmischer Optimierungen:

Berechnung eines laufenden Produkts. Angenommen, wir berechnen das Produkt bei Index N... N+13 und nennen es P (N). Jetzt müssen wir das Produkt bei Index N+1..N+13 berechnen. P (N+1) ist gleich P(N), außer dass die erste Zahl am Index N weg ist und wir die neue Zahl am Index N+14T berücksichtigen müssen. Dies kann erreicht werden, indem das vorherige Produkt durch seine erste Zahl dividiert und mit der neuen Zahl multipliziert wird.
Keine Folge von 13 Zahlen mit 0 berechnen (das Produkt ist immer Null).
Vermeiden Sie Division oder Multiplikation mit 1.

Das komplette Programm finden Sie hier. Es gibt eine heikle Logik, um die Nullen zu umgehen, aber ansonsten ist es ziemlich einfach. Die Hauptsache ist, dass wir zu Beginn nur ein Array mit 1000 Bytes zuweisen und es per Zeiger (also keine Kopie) an die Funktion findLargestProductInSeries() mit einem Indexbereich übergeben.

package scan


func findLargestProductInSeries(digits *[1000]byte, 
                                start, end int) int64 {
    if (end - start)  < 13 {
        return -1
    }

    largestProduct := int64((*digits)[start])
    for i := 1; i < 13 ; i++ {
        d := int64((*digits)[start + i])
        if d == 1 {
            continue
        }
        largestProduct *= d
    }

    currProduct := largestProduct
    for ii := start + 13; ii < end; ii++ {
        old := int64((*digits)[ii-13])
        cur := int64((*digits)[ii])
        if old == cur {
            continue
        }

        if cur == 1 {
            currProduct /= old
            continue
        }

        if old == 1 {
            currProduct *= cur
        } else {
            currProduct = currProduct / old * cur
        }

        if currProduct > largestProduct {
            largestProduct = currProduct
        }
    }

    return largestProduct
}


func FindLargestProduct(text string) int64 {
    var digits [1000]byte
    digIndex := 0
    for _, c := range text {
        if c == 10 {
            continue
        }
        digits[digIndex] = byte(c) - 48
        digIndex++
    }

    start := -1
    end := -1
    findStart := true
    var largestProduct int64
    for ii := 0; ii < len(digits) - 13; ii++ {
        if findStart {
            if digits[ii] == 0 {
                continue
            } else {
                start = ii
                findStart = false
            }
        }

        if digits[ii] == 0 {
            end = ii
            result := findLargestProductInSeries(&digits, 
                                                 start, 
                                                 end)
            if result > largestProduct {
                largestProduct = result
            }
            findStart = true
        }
    }

    return largestProduct
}

Der Test ist der gleiche. Mal sehen, wie wir es mit dem Profil gemacht haben:

> go test -cpuprofile cpu.prof -bench .
PASS
ok      _/github.com/the-gigi/project-euler/8/go/scan	0.816s

Auf Anhieb können wir sehen, dass die Laufzeit von mehr als 13 Sekunden auf weniger als eine Sekunde gesunken ist. Das ist sehr gut. Zeit, hineinzuschauen. Verwenden wir nur top10, das nach flacher Zeit sortiert ist.

(pprof) top10
Showing nodes accounting for 560ms, 100% of 560ms total
flat  flat%   sum%     cum   cum%
290ms 51.79%  51.79%   290ms 51.79%  findLargestProductInSeries
250ms 44.64%  96.43%   540ms 96.43%  FindLargestProduct 
20ms  3.57%   100%     20ms  3.57%   runtime.usleep 
0     0%      100%     540ms 96.43%  TestFindLargestProduct 
0     0%      100%     20ms  3.57%   runtime.mstart 
0     0%      100%     20ms  3.57%   runtime.mstart1 
0     0%      100%     20ms  3.57%   runtime.sysmon 
0     0%      100%     540ms 96.43%  testing.tRunner

Das ist toll. Fast die gesamte Laufzeit wird in unserem Code verbracht. Überhaupt keine Speicherzuordnungen. Mit dem Befehl list können wir tiefer eintauchen und die Anweisungsebene betrachten:

(pprof) list FindLargestProduct
Total: 560ms
ROUTINE ======================== scan.FindLargestProduct
250ms      540ms (flat, cum) 96.43% of Total
 .          .     44:
 .          .     45:
 .          .     46:func FindLargestProduct(t string) int64 {
 .          .     47:    var digits [1000]byte
 .          .     48:  digIndex := 0
70ms       70ms   49:  for _, c := range text {
 .          .     50:    if c == 10 {
 .          .     51:      continue
 .          .     52:    }
 .          .     53:    digits[digIndex] = byte(c) - 48
10ms       10ms   54:    digIndex++
 .          .     55:  }
 .          .     56:
 .          .     57:  start := -1
 .          .     58:  end := -1
 .          .     59:  findStart := true
 .          .     60:  var largestProduct int64
 .          .     61:  for ii := 0; ii < len(digits)-13; ii++ {
10ms       10ms   62:    if findStart {
 .          .     63:      if digits[ii] == 0 {
 .          .     64:        continue
 .          .     65:      } else {
 .          .     66:        start = ii
 .          .     67:        findStart = false
 .          .     68:      }
 .          .     69:    }
 .          .     70:
70ms       70ms   71:    if digits[ii] == 0 {
 .          .     72:      end = ii
20ms      310ms   73:      result := f(&digits,start,end)
70ms       70ms   74:      if result > largestProduct {
 .          .     75:        largestProduct = result
 .          .     76:      }
 .          .     77:      findStart = true
 .          .     78:    }
 .          .     79:  }

Das ist ziemlich erstaunlich. Sie erhalten eine Aussage für Aussage Timing aller wichtigen Punkte. Beachten Sie, dass der Aufruf in Zeile 73 der funktion f() tatsächlich ein Aufruf von findLargestProductInSeries() ist, den ich aus Platzgründen im Profil umbenannt habe. Dieser Anruf dauert 20 ms. Vielleicht können wir durch Einbetten des Funktionscodes den Funktionsaufruf (einschließlich Zuweisen des Stapels und Kopieren von Argumenten) speichern und diese 20 ms speichern. Es kann andere sinnvolle Optimierungen geben, die diese Ansicht genau bestimmen kann.

Visualisierung

Das Betrachten dieser Textprofile kann für große Programme schwierig sein. Go bietet Ihnen viele Visualisierungsoptionen. Sie müssen Graphviz für den nächsten Abschnitt installieren.

Das pprof-Tool kann Ausgaben in vielen Formaten generieren. Eine der einfachsten Möglichkeiten (SVG-Ausgabe) besteht darin, an der interaktiven Eingabeaufforderung von pprof einfach 'web' einzugeben. Ihr Browser zeigt dann eine schöne Grafik mit dem pink markierten Hot Path an.

Flammengraphen

Die eingebauten Grafiken sind nett und hilfreich, aber bei großen Programmen kann es schwierig sein, selbst diese Grafiken zu erkunden. Eines der beliebtesten Tools zur Visualisierung der Leistungsergebnisse ist das Flammendiagramm. Das pprof-Tool unterstützt es noch nicht sofort, aber Sie können bereits mit Ubers go-torch-Tool mit Flammengraphen spielen. Es wird derzeit daran gearbeitet, pprof um eine integrierte Unterstützung für Flammengraphen zu erweitern.

Schlussfolgerung

Go ist eine Systemprogrammiersprache, mit der verteilte Hochleistungssysteme und Datenspeicher erstellt werden. Go bietet eine hervorragende Unterstützung, die die Profilerstellung Ihrer Programme, die Analyse ihrer Leistung und die Visualisierung der Ergebnisse immer besser macht.

Das Go-Team und die Community legen großen Wert darauf, die Leistung zu verbessern. Den vollständigen Quellcode mit drei verschiedenen Algorithmen finden Sie auf GitHub.