I am building my TraceLog package and it is really important that the package logs any internal exceptions and prevents panics from shutting down the application. The TraceLog package must never be responsible for shutting down an application. I also have internal go routines that must never terminate until the application is shut down gracefully.
Understanding how to use Defer and Recover in your application can be a bit tricky at first, especially if you are used to using try/catch blocks. There is a pattern you can implement to provide that same type of try/catch protection in Go. Before I can show you this you need to learn how Defer, Panic and Recover work.
First you need to understand the intricacies of the keyword defer. Start with this piece of code:
package main
import (
"fmt"
)
func main() {
test()
}
func mimicError(key string) error {
return fmt.Errorf("Mimic Error : %s", key)
}
func test() {
fmt.Println("Start Test")
err := mimicError("1")
defer func() {
fmt.Println("Start Defer")
if err != nil {
fmt.Println("Defer Error:", err)
}
}()
fmt.Println("End Test")
}
The MimicError function is a test function that will be used to simulate an error. It is following the Go convention of using the error type to return an indication if something went wrong.
In Go the error type is defined as an interface:
type error interface {
Error() string
}
If you don't understand what a Go interface is at the moment then this might help for now. Any type that implements the
Error() function implements this interface and can be used as a variable of this type. The MimicError function is using
errors.New(string) to create an error type variable. The errors type can be found in the errors package.
Test function produces the following output:
Start Test
End Test
Start Defer
Defer Error : Mimic Error : 1
When you study the output you see that the Test function started and ended. Then right before the Test function terminated for good, the inline defer function was called. Two interesting things are happening here. First, the defer keyword is deferring the execution of the inline function until the Test function ends. Second, because Go supports closure, the err variable is accessible to the inline function and its message "Mimic Error : 1" is written to stdout.
You can define a defer function at any time inside your function. If that defer function requires state, as in this case with the err variable, then it must exist before the defer function is defined.
Now change the Test function a bit:
func test() {
fmt.Println("Start Test")
err := mimicError("1")
defer func() {
fmt.Println("Start Defer")
if err != nil {
fmt.Println("Defer Error:", err)
}
}()
err = mimicError("2")
fmt.Println("End Test")
}
This time the code is calling the MimicError function a second time after creating the inline defer function. Here is the output:
Start Test
End Test
Start Defer
Defer Error : Mimic Error : 2
The output is identical from the first test except for one change. This time the inline defer function wrote "Mimic Error : 2". It appears that the inline defer function has a reference to the err variable. So if the state of the err variable changes at any time before the inline defer function is called, you will see that value. To verify that the inline defer function is getting a reference to the err variable, change the code to write the address of the err variable in both the Test function and the inline defer function.
func test() {
fmt.Println("Start Test")
err := mimicError("1")
fmt. Println("Err Addr:", &err)
defer func() {
fmt.Println("Start Defer")
if err != nil {
fmt.Println("Err Addr Defer:", &err)
fmt.Println("Defer Error:", err)
}
}()
err = mimicError("2")
fmt.Println("End Test")
}
As you can see from the output below, the inline defer function has the same reference to the err variable. The address is the same inside of the Test function and inside of the inline defer function.
Start Test
Err Addr: 0x2101b3200
End Test
Start Defer
Err Addr Defer: 0x2101b3200
Defer Error : Mimic Error : 2
As long as the defer function is stated before the Test function terminates, the defer function will be executed. This is great, but what I want is the ability to always place the defer statement at the beginning of any function. This way the defer function is guaranteed to be called every time the function is executed and I don't have to over think where to place the defer statement. Occam's Razor applies here:
"When you have two competing theories that make exactly the same predictions, the simpler one is the better". What I want is an easy pattern that can be duplicated without requiring any thought.
The only problem is that the err variable needs to be defined before the defer statement can be implemented. Fortunately Go allows return variables to have names.
Now change the entire program as follows:
package main
import (
"fmt"
)
func main() {
if err := test(); err != nil {
fmt.Printf("Main Error: %v\n", err)
}
}
func mimicError(key string) error {
return fmt.Errorf("Mimic Error : %s", key)
}
func test() (err error) {
defer func() {
fmt.Println("Start Defer")
if err != nil {
fmt.Println("Defer Error:", err)
}
}()
fmt.Println("Start Test")
err = mimicError("1")
fmt.Println("End Test")
return err
}
The Test function now defines a return variable called err of type error. This is great because the err variable exists immediately and you can put the defer statement at the very beginning of the function. Also, the Test function now follows the Go convention and returns an error type back to the calling routine.
When you run the program you get the following output:
Start Test
End Test
Start Defer
Defer Error : Mimic Error : 1
Main Error: Mimic Error : 1
Now it is time to talk about the built-in function
panic. When any Go function calls panic the normal flow of the application stops. The function that calls panic ends immediately and causes a chain reaction of panics up the call stack. All the functions in the same call stack will end, one after the next, like dominos falling down. Eventually the panic reaches the top of the call stack and the application crashes. One good thing is that any existing defer functions will be executed during this panic sequence and they have the ability to stop the crash.
Look at this new Test function that calls the built in panic function and recovers from the call:
func test() error {
defer func() {
fmt.Println("Start Panic Defer")
if r := recover(); r != nil {
fmt.Println("Defer Panic:", r)
}
}()
fmt.Println("Start Test")
panic("Mimic Panic")
}
Look closely at the new inline defer function:
defer func() {
fmt.Println("Start Panic Defer")
if r := recover(); r != nil {
fmt.Println("Defer Panic:", r)
}
}()
The inline defer function is now calling another built-in function
recover. The recover function stops the chain reaction from going any farther up the call stack. It is like swiping a domino away so no more can fall down. The recover function can only be used inside of a defer function. This is because during the panic chain reaction only defer functions will be executed.
If the recover function is called and there is no panic occurring, the recover function will return nil. If there is a panic occurring, then the panic is stopped and the value given to the panic call will be returned.
This time the code is not calling the MimicError function but the built in panic function to simulate a panic. Look at the output from running the code:
Start Test
Start Panic Defer
Defer Panic : Mimic Panic
The inline defer function captures the panic, prints it to the screen and stops it dead in its tracks. Also notice that "End Test" is never displayed. The function terminated as soon as panic was called.
This is great but if there is an error I still want to display that as well. Something cool about Go and the defer keyword is that you can have more than one defer function stated at a time.
Change the Test function as follows:
func test() (err error) {
defer func() {
fmt.Println("Start Panic Defer")
if r := recover(); r != nil {
fmt.Println("Defer Panic :", r)
}
}()
defer func() {
fmt.Println("Start Defer")
if err != nil {
fmt.Println("Defer Error:", err)
}
}()
fmt.Println("Start Test")
err = mimicError("1")
panic("Mimic Panic")
}
Now both inline defer functions have been incorporated into beginning of the Test function. First the inline defer function that that recovers from panics and then the inline defer function that prints errors. One thing to note is that Go will execute these inline defer functions in the opposite order that are defined (First In - Last Out).
Run the code and look at the output:
Start Test
Start Error Defer
Defer Error : Mimic Error : 1
Start Panic Defer
Defer Panic : Mimic Panic
Main Error: Mimic Error : 1
The Test function starts as expected and the call to panic halts the execution of the Test function. This causes the inline defer function that prints errors to get called first. Since the Test function called the MimicError function before the panic, the error is printed. Then the inline defer function that recovers from panics is called and the panic is recovered.
There is one problem with this code. The main function had no idea that a panic was averted. All the main function knows is that an error occurred thanks to the MimicError function call. This is not good. I want the main function to know about the error that caused the panic. That is really the error that must be reported.
In the inline defer function that handles the panic we need to assign the error that caused the panic to the err variable.
func test() (err error) {
defer func() {
fmt.Println("Start Panic Defer")
if r := recover(); r != nil {
fmt.Printf("Defer Panic : %v\n", r)
err = fmt.Errorf("%v", r)
}
}()
defer func() {
fmt.Println("Start Defer")
if err != nil {
fmt.Println("Defer Error:", err)
}
}()
fmt.Println("Start Test")
err = mimicError("1")
panic("Mimic Panic")
}
Now when you run the code you get the following output:
Start Test
Start Error Defer
Defer Error : Mimic Error : 1
Start Panic Defer
Defer Panic : Mimic Panic
Main Error: Mimic Panic
This time when main function reports the error that caused the panic.
Everything looks good but this code is not really scalable. Having two inline defer functions is cool but not practical. What I need is a single function that can handle both errors and panics.
Here is a revised version of the full program with a new function called _CatchPanic:
package main
import (
"fmt"
)
func main() {
if err := test(); err != nil {
fmt.Println("Main Error:", err)
}
}
func catchPanic(err error, functionName string) {
if r := recover(); r != nil {
fmt.Printf("%s : PANIC Defered : %v\n", functionName, r)
if err != nil {
err = fmt.Errorf("%v", r)
}
} else if err != nil {
fmt.Printf("%s : ERROR : %v\n", functionName, err)
}
}
func mimicError(key string) error {
return fmt.Errorf("Mimic Error : %s", key)
}
func test() (err error) {
defer catchPanic(err, "Test")
fmt.Println("Start Test")
err = mimicError("1")
fmt.Println("End Test")
return err
}
The new function _CatchPanic incorporates both the panic recover and error handling. This time instead of defining an inline defer function the code is using an external function for the defer statement.
In this first test with the new _CatchPanic defer function, we need to make sure we didn't break our error handling.
Run the code and look at the output:
Start Test
End Test
Main Error: Mimic Error : 1
Everything looks good. Now we need to test a panic.
func test() (err error) {
defer catchPanic(err, "Test")
fmt.Println("Start Test")
err = mimicError("1")
panic("Mimic Panic")
}
Run the code and look at the output:
Start Test
Test5 : PANIC Defered : Mimic Panic
Main Error: Mimic Error : 1
Houston we have a problem. Main was provided the error from the MimicError function call and not from the panic. What went wrong?
func catchPanic(err error, functionName string) {
if r := recover(); r != nil {
fmt.Printf("%s : PANIC Defered : %v\n", functionName, r)
if err != nil {
err = fmt.Errorf("%v", r)
}
} else if err != nil {
fmt.Printf("%s : ERROR : %v\n", functionName, err)
}
}
Because defer is now calling an external function the code lost all the goodness that came with inline functions and Closure.
Change the code to print the address of the err variable from inside the Test function and_CatchPanic defer function.
func _CatchPanic(err error, functionName string) {
if r := recover(); r != nil {
fmt.Printf("%s : PANIC Defered : %v\n", functionName, r)
fmt.Println("Err Addr Defer:", &err)
if err != nil {
err = fmt.Errorf("%v", r)
}
} else if err != nil {
fmt.Printf("%s : ERROR : %v\n", functionName, err)
}
}
func test() (err error) {
fmt.Println("Err Addr:", &err)
defer _CatchPanic(err, "Test7")
fmt.Printf("Start Test\n")
err = mimicError("1")
panic("Mimic Panic")
}
When you run the code you can see why main did not get the error from the panic.
Err Addr: 0x2101b31f0
Start Test
Test5 : PANIC Defered : Mimic Panic
Err Addr Defer: 0x2101b3270
Main Error: Mimic Error : 1
When the Test function passes the err variable to the catchPanic defer function it is passing the variable by value. In Go all arguments are passed by value. So the catchPanic defer function has its own copy of the err variable. Any changes to catchPanic's copy remains with catchPanic.
To fix the pass by value problem the code needs to pass the err variable by reference.
package main
import (
"fmt"
)
func main() {
if err := testFinal(); err != nil {
fmt.Println("Main Error:", err)
}
}
func catchPanic(err *error, functionName string) {
if r := recover(); r != nil {
fmt.Printf("%s : PANIC Defered : %v\n", functionName, r)
if err != nil {
*err = fmt.Errorf("%v", r)
}
} else if err != nil && *err != nil {
fmt.Printf("%s : ERROR : %v\n", functionName, *err)
}
}
func mimicError(key string) error {
return fmt.Errorf("Mimic Error : %s", key)
}
func testFinal() (err error) {
defer catchPanic(&err, "TestFinal")
fmt.Println("Start Test")
err = mimicError("1")
panic("Mimic Panic")
}
Now run the code and look at the output:
Start Test
Test6 : PANIC Defered : Mimic Panic
Main Error: Mimic Panic
The main function now reports the error that occurred because of the panic.
If you want to capture a stack trace as well just make this change to catchPanic. Remember to import "runtime".
func catchPanic(err *error, functionName string) {
if r := recover(); r != nil {
fmt.Printf("%s : PANIC Defered : %v\n", functionName, r)
// Capture the stack trace
buf := make([]byte, 10000)
runtime.Stack(buf, false)
fmt.Printf("%s : Stack Trace : %s", functionName, string(buf))
if err != nil {
*err = fmt.Errorf("%v", r)
}
} else if err != nil && *err != nil {
fmt.Printf("%s : ERROR : %v\n", functionName, *err)
}
}
With this pattern you can implement Go routines that can handle errors and trap panic situations. In many cases these conditions just need to be logged or reported up the call stack to be handled gracefully. Having a single place to implement this type of code and a simple way to integrate it into each function will reduce errors and keep your code clean.
However I have learned it is best to only use this pattern to catch panics only. Leave the logging of errors to the application logic. If not then you may be logging the errors twice.
func catchPanic(err *error, functionName string) {
if r := recover(); r != nil {
fmt.Printf("%s : PANIC Defered : %v\n", functionName, r)
// Capture the stack trace
buf := make([]byte, 10000)
runtime.Stack(buf, false)
fmt.Printf("%s : Stack Trace : %s", functionName, string(buf))
if err != nil {
*err = fmt.Errorf("%v", r)
}
}
}
As always I hope this can help you with your Go programming.