At this stage, you should be fairly comfortable with concurrency in Go and should be able to implement basic goroutines and concurrent mechanisms with ease.
We have also dabbled in some distributed concurrency patterns that are managed not only through the application itself, but also through third-party data stores for networked applications that operate concurrently in congress.
Earlier in this book, we examined some preliminary and basic testing and logging. We looked at the simpler implementations of Go's internal test tool, performed some race condition testing using the race tool, and performed some rudimentary load and performance testing.
However, there's much more to be looked at here, particularly as it relates to the potential black hole of concurrent code—we've seen unexpected behavior among code that runs in goroutines and is non-blocking.
In this chapter, we'll further investigate load and performance testing, look at unit testing in Go, and experiment with more advanced tests and debugging. We'll also look at best practices for logging and reporting, as well as take a closer look at panicking and recovering.
Lastly, we'll want to see how all of these things can be applied not just to our standalone concurrent code, but also to distributed systems.
Along the way, we'll introduce a couple of frameworks for unit testing in a variety of different styles.
Though we haven't specifically mentioned it, the idiomatic nature of error handling in Go makes debugging naturally easier by mandate.
One good practice for any large-scale function inside Go code is to return an error as a return value—for many smaller methods and functions, this is potentially burdensome and unnecessary. Still, it's a matter for consideration whenever we're building something that involves a lot of moving pieces.
For example, consider a simple Add() function:
func Add(x int, y int) int {
return x + y
}If we wish to follow the general rule of "always return an error value", we may be tempted to convert this function to the following code:
package main
import
(
"fmt"
"errors"
"reflect"
)
func Add(x int, y int) (int, error) {
var err error
xType := reflect.TypeOf(x).Kind()
yType := reflect.TypeOf(y).Kind()
if xType != reflect.Int || yType != reflect.Int {
fmt.Println(xType)
err = errors.New("Incorrect type for integer a or b!")
}
return x + y, err
}
func main() {
sum,err := Add("foo",2)
if err != nil {
fmt.Println("Error",err)
}
fmt.Println(sum)
}You can see that we're (very poorly) reinventing the wheel. Go's internal compiler kills this long before we ever see it. So, we should focus on things that the compiler may not catch and that can cause unexpected behavior in our applications, particularly when it comes to channels and listeners.
The takeaway is to let Go handle the errors that the compiler would handle, unless you wish to handle the exceptions yourself, without causing the compiler specific grief. In the absence of true polymorphism, this is often cumbersome and requires the invocation of interfaces, as shown in the following code:
type Alpha struct {
}
type Numeric struct {
}You may recall that creating interfaces and structs allows us to route our function calls separately based on type. This is shown in the following code:
func (a Alpha) Add(x string, y string) (string, error) {
var err error
xType := reflect.TypeOf(x).Kind()
yType := reflect.TypeOf(y).Kind()
if xType != reflect.String || yType != reflect.String {
err = errors.New("Incorrect type for strings a or b!")
}
finalString := x + y
return finalString, err
}
func (n Numeric) Add(x int, y int) (int, error) {
var err error
xType := reflect.TypeOf(x).Kind()
yType := reflect.TypeOf(y).Kind()
if xType != reflect.Int || yType != reflect.Int {
err = errors.New("Incorrect type for integer a or b!")
}
return x + y, err
}
func main() {
n1 := Numeric{}
a1 := Alpha{}
z,err := n1.Add(5,2)
if err != nil {
log.Println("Error",err)
}
log.Println(z)
y,err := a1.Add("super","lative")
if err != nil {
log.Println("Error",err)
}
log.Println(y)
}This still reports what will eventually be caught by the compiler, but also handles some form of error on what the compiler cannot see: external input. We're routing our Add() function through an interface, which provides some additional standardization by directing the struct's parameters and methods more explicitly.
If, for example, we take user input for our values and need to evaluate the type of that input, we may wish to report an error in this way as the compiler will never know that our code can accept the wrong type.
One way of handling messaging and logging that keeps a focus on concurrency and isolation is to shackle our goroutine with its own logger that will keep everything separate from the other goroutines.
At this point, we should note that this may not scale—that is, it may at some point become expensive to create thousands or tens of thousands of goroutines that have their own loggers, but at a minimal size, this is totally doable and manageable.
To do this logging individually, we'll want to tie a Logger instance to each goroutine, as shown in the following code:
package main
import
(
"log"
"os"
"strconv"
)
const totalGoroutines = 5
type Worker struct {
wLog *log.Logger
Name string
}We'll create a generic Worker struct that will ironically do no work (at least not in this example) other than hold onto its own Logger object. The code is as follows:
func main() {
done := make(chan bool)
for i:=0; i< totalGoroutines; i++ {
myWorker := Worker{}
myWorker.Name = "Goroutine " + strconv.FormatInt(int64(i),10) + ""
myWorker.wLog = log.New(os.Stderr, myWorker.Name, 1)
go func(w *Worker) {
w.wLog.Print("Hmm")
done <- true
}(&myWorker)
}Each goroutine is saddled with its own log routine through Worker. While we're spitting our output straight to the console, this is largely unnecessary. However, if we want to siphon each to its own logfile, we could do so by using the following code:
log.Println("...")
<- done
}In the earlier chapters of this book, we briefly addressed IDEs and gave a few examples of IDEs that have a tight integration with Go.
As we're examining logging and debugging, there's one IDE we previously and specifically didn't mention before, primarily because it's intended for a very small selection of languages—namely, Go and Lua. However, if you end up working primarily or exclusively in Go, you'll find it absolutely essential, primarily as it relates to debugging, logging, and feedback capabilities.
LiteIDE is cross-platform and works well on OS X, Linux, and Windows. The number of debugging and testing benefits it presents in a GUI form are invaluable, particularly if you're already very comfortable with Go. That last part is important because developers often benefit most from "learning the hard way" before diving in with tools that simplify the programming process. It's almost always better to know how and why something works or doesn't work at the core before being presented with pretty icons, menus, and pop-up windows. Having said that, LiteIDE is a fantastic, free tool for the advanced Go programmer.
By formalizing a lot of the tools and error reporting from Go, we can easily plow through some of the more vexing debugging tasks by seeing them onscreen.
LiteIDE also brings context awareness, code completion, go fmt, and more into our workspace. You can imagine how an IDE tuned specifically for Go can help you keep your code clean and bug free. Refer to the following screenshot:
LiteIDE showing output and automatic code completion on Windows
Tip
LiteIDE for Linux, OS X, and Windows can be found at https://code.google.com/p/liteide/.
Throughout this book, we have usually handled soft errors, warnings, and general messages with the fmt.Println syntax by sending a message to the console.
While this is quick and easy for demonstration purposes, it's probably ideal to use the log package to handle these sorts of things. This is because we have more versatility, as log relates to where we want our messages to end up.
As for our purposes so far, the messages are ethereal. Switching out a simple Println statement to Logger is extremely simple.
We've been relaying messages before using the following line of code:
fmt.Println("Horrible error:",err)You'll notice the change to Logger proves pretty similar:
myLogger.Println("Horrible error:", err)This is especially useful for goroutines, as we can create either a global Logger interface that can be accessed anywhere or pass the logger's reference to individual goroutines and ensure our logging is handled concurrently.
One consideration for having a single logger for use across our entire application is the possibility that we may want to log individual processes separately for clarity in analysis. We'll talk a bit more about that later in this chapter.
To replicate passing messages to the command line, we can simply use the following line of code:
log.Print("Message")With defaults to stdout as its io.writer—recall that we can set any io.writer as the log's destination.
However, we will also want to be able to log to file quickly and easily. After all, any application running in the background or as a daemon will need to have something a little more permanent.
There are a lot of ways to send an error to a logfile—we can, after all, handle this with built-in file operation OS calls. In fact, this is what many people do.
However, the log package offers some standardization and potential symbiosis between the command-line feedback and more permanent storage of errors, warnings, and general information.
The simplest way to do this is to open a file using the os.OpenFile() method (and not the os.Open() method) and pass that reference to our log instantiation as io.Writer.
Let's take a look at such functionality in the following example:
package main
import (
"log"
"os"
)
func main() {
logFile, _ := os.OpenFile("/var/www/test.log", os.O_RDWR, 0755)
log.SetOutput(logFile)
log.Println("Sending an entry to log!")
logFile.Close()
}In our preceding goroutine package, we could assign each goroutine its own file and pass a file reference as an io Writer (we'll need to have write access to the destination folder). The code is as follows:
for i:=0; i< totalGoroutines; i++ {
myWorker := Worker{}
myWorker.Name = "Goroutine " + strconv.FormatInt(int64(i),10)
+ ""
myWorker.FileName = "/var/www/"+strconv.FormatInt(int64(i),10)
+ ".log"
tmpFile,_ := os.OpenFile(myWorker.FileName, os.O_CREATE,
0755)
myWorker.File = tmpFile
myWorker.wLog = log.New(myWorker.File, myWorker.Name, 1)
go func(w *Worker) {
w.wLog.Print("Hmm")
done <- true
}(&myWorker)
}When we talk about logging errors to memory, we're really referring to a data store, although there's certainly no reason other than volatility and limited resources to reject logging to memory as a viable option.
While we'll look at a more direct way to handle networked logging through another package in the next section, let's delineate our various application errors in a concurrent, distributed system without a lot of hassle. The idea is to use shared memory (such as Memcached or a shared memory data store) to pass our log messages.
While these will technically still be logfiles (most data stores keep individual records or documents as JSON-encoded hard files), it has a distinctively different feel than traditional logging.
Going back to our old friend from the previous chapter—CouchDB—passing our logging messages to a central server can be done almost effortlessly, and it allows us to track not just individual machines, but their individual concurrent goroutines. The code is as follows:
package main
import
(
"github.com/couchbaselabs/go-couchbase"
"io"
"time"
"fmt"
"os"
"net/http"
"crypto/md5"
"encoding/hex"
)
type LogItem struct {
ServerID string "json:server_id"
Goroutine int "json:goroutine"
Timestamp time.Time "json:time"
Message string "json:message"
Page string "json:page"
}This is what will eventually become our JSON document that will be sent to our Couchbase server. We'll use the Page, Timestamp, and ServerID as a combined, hashed key to allow multiple, concurrent requests to the same document against separate servers to be logged separately, as shown in the following code:
var currentGoroutine int
func (li LogItem) logRequest(bucket *couchbase.Bucket) {
hash := md5.New()
io.WriteString(hash,li.ServerID+li.Page+li.Timestamp.Format("Jan
1, 2014 12:00am"))
hashString := hex.EncodeToString(hash.Sum(nil))
bucket.Set(hashString,0,li)
currentGoroutine = 0
}When we reset currentGoroutine to 0, we use an intentional race condition to allow goroutines to report themselves by numeric ID while executing concurrently. This allows us to debug an application that appears to work correctly until it invokes some form of concurrent architecture. Since goroutines will be self-identified by an ID, it allows us to add more granular routing of our messages.
By designating a different log location by goroutine ID, timestamp, and serverID, any concurrency issues that arise can be quickly plucked from logfiles. This is done using the following code:
func main() {
hostName, _ := os.Hostname()
currentGoroutine = 0
logClient, err := couchbase.Connect("http://localhost:8091/")
if err != nil {
fmt.Println("Error connecting to logging client", err)
}
logPool, err := logClient.GetPool("default")
if err != nil {
fmt.Println("Error getting pool",err)
}
logBucket, err := logPool.GetBucket("logs")
if err != nil {
fmt.Println("Error getting bucket",err)
}
http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
request := LogItem{}
request.Goroutine = currentGoroutine
request.ServerID = hostName
request.Timestamp = time.Now()
request.Message = "Request to " + r.URL.Path
request.Page = r.URL.Path
go request.logRequest(logBucket)
})
http.ListenAndServe(":8080",nil)
}