Debugging Go Tests
April 6, 2020
Delve is Awesome
Let’s start by saying in most cases if you are using a debugger you are probably not having the best day. This post is to try and convince you that it doesn’t always have to be the case. I regularly use Delve and Go tests to understand how something complex is actually working. If you’ve never heard of Delve, it is a debugger for the Go programming language.
To be able to use Delve with your go projects start by installing it. If you’re using VS Code and the Go extension chances are it’s already installed on you machine.
Install Delve (dlv)
$ go get -u github.com/derekparker/delve/cmd/dlv
Test Delve Installation
$ dlv version
Delve Debugger
Version: 1.4.0
Build: $Id: 67422e6f7148fa1efa0eac1423ab5594b223d93b $
On To The Fun Stuff
A fun and interesting example of a test, that is a little complex and difficult to understand, is the TestKMeans test in my Go Vector library. This library provides a nice vector API for Golang, with all kinds of fun and useful math operations on the vectors. For instance this library implements K-Means clustering.
K-Means is a type of unsupervised learning used when you have unlabeled data represented as vectors. The goal of this algorithm is to find groups in the data. The algorithm works iteratively to assign each data point to one of K groups based on the features in the vector. Data points are clustered based on feature similarity. The results of the K-means clustering algorithm is the centroids of the K clusters, which can be used to label any vector by simple calculating it’s mathematical distance to the centroid.
Launching Delve
First we need to clone the govector library. Once it’s cloned change the directory to the libraries root and run the following command to enter the debugger and run the test.
$ dlv test --build-flags='github.com/phenixrizen/govector' -- -test.run ^TestKMeans$
You should get a interactive Delve debugger console:
Type 'help' for list of commands.
(dlv)
In this tutorial we are going to use the following commands in Delve:
b- sets a breakpoint in the codec- runs the code until a breakpoint is reachedn- steps to the next line of codep- evaluates a expressionlocals- prints the local variables and their valuesargs- prints the arguments passed to functionclear- removes a breakpoint
Now lets start setting some breakpoints:
(dlv) b nodeRange kmeans.go:31
Breakpoint nodeRange set at 0x7af5cf for github.com/phenixrizen/govector.Train() ./kmeans.go:31
(dlv) b cents kmeans.go:41
Breakpoint cents set at 0x7af6a7 for github.com/phenixrizen/govector.Train() ./kmeans.go:41
Now we are going to run the code to the first breakpoint:
(dlv) c
> [nodeRange] github.com/phenixrizen/govector.Train() ./kmeans.go:31 (hits goroutine(6):1 total:1) (PC: 0x7af5cf)
26: }
27:
28: // Check to make sure everything is consistent, dimension-wise
29: stdLen := 0
30: for i, node := range nodes {
=> 31: curLen := len(node)
32: if i == 0 {
33: stdLen = curLen
34: }
35: if i > 0 && len(node) != stdLen {
36: return nil, ErrorVectorLengths
You can see that we are in a loop that is iterating over all the nodes that were passed to the Train function. In this case 7 vectors. We are ensuring all the vectors lengths match. Now lets look at the arguments passed to the function and the local variables to understand the logic.
(dlv) args
nodes = github.com/phenixrizen/govector.Nodes len: 7, cap: 7, [...]
clusterCount = 3
maxRounds = 10
~r3 = github.com/phenixrizen/govector.Nodes len: 0, cap: 0, nil
~r4 = error nil
(dlv) p nodes
github.com/phenixrizen/govector.Nodes len: 7, cap: 7, [
[0.1,2.3,1,5],
[1.1,2.6,4,5],
[3.1,2.3,3,5],
[0.6,2.2,5,5],
[0.1,5.3,4,5],
[0.1,2.3,4,5],
[0.1,2.3,1],
]
(dlv) locals
stdLen = 0
i = 0
node = github.com/phenixrizen/govector.Vector len: 4, cap: 4, [...]
curLen = 0
Now lets continue to the next iteration and look at the local variables:
(dlv) c
> [nodeRange] github.com/phenixrizen/govector.Train() ./kmeans.go:31 (hits goroutine(6):2 total:2) (PC: 0x7af5cf)
26: }
27:
28: // Check to make sure everything is consistent, dimension-wise
29: stdLen := 0
30: for i, node := range nodes {
=> 31: curLen := len(node)
32: if i == 0 {
33: stdLen = curLen
34: }
35: if i > 0 && len(node) != stdLen {
36: return nil, ErrorVectorLengths
(dlv) locals
stdLen = 4
i = 1
node = github.com/phenixrizen/govector.Vector len: 4, cap: 4, [...]
curLen = 4
To break out of the loop lets clear the breakpoint. We named the loop breakpoint nodeRange.
(dlv) clear nodeRange
Breakpoint nodeRange cleared at 0x7af5cf for github.com/phenixrizen/govector.Train() ./kmeans.go:31
Now lets continue:
(dlv) c
> [cents] github.com/phenixrizen/govector.Train() ./kmeans.go:41 (hits goroutine(6):1 total:1) (PC: 0x7af6a7)
36: return nil, ErrorVectorLengths
37: }
38:
39: }
40:
=> 41: centroids := make(Nodes, clusterCount)
42:
43: r := rand.New(rand.NewSource(randSeed))
44:
45: // Pick centroid starting points from Nodes
46: for i := 0; i < clusterCount; i++ {
Now lets jump to the next line and see the value of centroids is nil.
(dlv) n
> github.com/phenixrizen/govector.Train() ./kmeans.go:43 (PC: 0x7af6fe)
38:
39: }
40:
41: centroids := make(Nodes, clusterCount)
42:
=> 43: r := rand.New(rand.NewSource(randSeed))
44:
45: // Pick centroid starting points from Nodes
46: for i := 0; i < clusterCount; i++ {
47: srcIndex := r.Intn(len(nodes))
48: srcLen := len(nodes[srcIndex])
(dlv) p centroids
github.com/phenixrizen/govector.Nodes len: 3, cap: 3, [
nil,
nil,
nil,
]
In the K-Means library we next pick some random nodes or vectors as the starting values for the centroids. Let’s set a breakpoint past this loop and print the centroids selected:
(dlv) b movement kmeans.go:55
Breakpoint movement set at 0x7af9c7 for github.com/phenixrizen/govector.Train() ./kmeans.go:55
(dlv) c
> [movement] github.com/phenixrizen/govector.Train() ./kmeans.go:55 (hits goroutine(6):1 total:1) (PC: 0x7af9c7)
50: centroids[i] = n
51: copy(centroids[i], nodes[r.Intn(len(nodes))])
52: }
53:
54: // Train centroids
=> 55: movement := true
56: for i := 0; i < maxRounds && movement; i++ {
57: movement = false
58:
59: groups := make(map[int][]Vector)
60:
(dlv) locals
stdLen = 4
centroids = github.com/phenixrizen/govector.Nodes len: 3, cap: 3, [...]
r = ("*math/rand.Rand")(0xc000013350)
movement = false
(dlv) p centroids
github.com/phenixrizen/govector.Nodes len: 3, cap: 3, [
[0.1,2.3,1,5],
[0.1,5.3,4,5],
[0.1,5.3,4,5],
]
Now lets walk through the training iterations. We can set breakpoints, iterate and print local variable values as we have above:
b trainInteration kmeans.go:61
Breakpoint trainInteration set at 0x7afaa0 for github.com/phenixrizen/govector.Train() ./kmeans.go:61
(dlv) b returnCents kmeans.go:76
Breakpoint returnCentroids set at 0x7aff3f for github.com/phenixrizen/govector.Train() ./kmeans.go:76
Run c multiple times…
(dlv) c
> [trainInteration] github.com/phenixrizen/govector.Train() ./kmeans.go:61 (hits goroutine(6):1 total:1) (PC: 0x7afaa0)
56: for i := 0; i < maxRounds && movement; i++ {
57: movement = false
58:
59: groups := make(map[int][]Vector)
60:
=> 61: for _, node := range nodes {
62: near := Nearest(node, centroids)
63: groups[near] = append(groups[near], node)
64: }
65:
66: for key, group := range groups {
(dlv)
(dlv) locals
stdLen = 4
centroids = github.com/phenixrizen/govector.Nodes len: 3, cap: 3, [...]
r = ("*math/rand.Rand")(0xc000013350)
movement = false
i = 2
groups = map[int][]github.com/phenixrizen/govector.Vector [...]
(dlv) p centroids
github.com/phenixrizen/govector.Nodes len: 3, cap: 3, [
[1.6,2.3,2,5],
[0.6000000000000001,2.3666666666666667,4.333333333333333,5],
[0.1,5.3,4,5],
]
You will eventually break out of the loop and we can print the centroid values that will be returned after training:
(dlv) c
> [returnCents] github.com/phenixrizen/govector.Train() ./kmeans.go:76 (hits goroutine(6):1 total:1) (PC: 0x7aff3f)
71: movement = true
72: }
73: }
74: }
75:
=> 76: return centroids, nil
77: }
78:
79: // Nearest return the index of the closest centroid from nodes
80: func Nearest(in Vector, nodes Nodes) int {
81: count := len(nodes)
(dlv) p centroids
github.com/phenixrizen/govector.Nodes len: 3, cap: 3, [
[1.6,2.3,2,5],
[0.6000000000000001,2.3666666666666667,4.333333333333333,5],
[0.1,5.3,4,5],
]
Now lets end the test by continuing one final time:
(dlv) c
PASS
Process 7665 has exited with status 0
I Repeat Delve Is Awesome
I hope you have learned that debugging doesn’t always have to be done on a bad day. I regularly use Delve to help me understand what is happening or why a test is failing. I can’t tell you the number times that I have caught a bad piece of logic using Delve. I really hope this helps…