Skip to content

Commit

Permalink
Enhance and begin using error handling framework
Browse files Browse the repository at this point in the history 
Add automatic appending of callstack to error handling framework
when CORE_LOGGING_ERROR is set to debug via core.yaml or calling
"peer logging setlevel error debug". Implement error handling framework
for peer logging CLI.

Change-Id: Ia65bae43f9c0a10cafa0596d9b65e2231aceac24
Signed-off-by: Will Lahti <wtlahti@us.ibm.com>
  • Loading branch information
@wlahti
wlahti committed Dec 5, 2016
1 parent da16559 commit 2dc82e0
Show file tree
Hide file tree
Showing 11 changed files with 236 additions and 60 deletions.
41 changes: 23 additions & 18 deletions core/errors/errors.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,28 +21,21 @@ import (
"encoding/json"
"fmt"
"runtime"

"github.com/hyperledger/fabric/flogging"
logging "github.com/op/go-logging"
)

// MaxCallStackLength is the maximum length of the stored call stack
const MaxCallStackLength = 30

// ComponentCode shows the originating component/module
type ComponentCode uint
type ComponentCode string

// ReasonCode for low level error description
type ReasonCode uint
type ReasonCode string

// Return codes
const (
Utility ComponentCode = iota
)

// Result codes
const (
// Placeholders
UnknownError ReasonCode = iota
ErrorWithArg ReasonCode = 1
)
var errorLogger = logging.MustGetLogger("error")

// CallStackError is a general interface for
// Fabric errors
Expand All @@ -67,7 +60,7 @@ func init() {
}

func initErrors() {
e := json.Unmarshal([]byte(errorCodes), &emap)
e := json.Unmarshal([]byte(errorMapping), &emap)
if e != nil {
panic(e)
}
Expand Down Expand Up @@ -98,7 +91,7 @@ func newHLError(debug bool) *hlError {

func setupHLError(e *hlError, debug bool) {
e.componentcode = Utility
e.reasoncode = UnknownError
e.reasoncode = UtilityUnknownError
if !debug {
e.stackGetter = noopGetStack
return
Expand Down Expand Up @@ -132,20 +125,28 @@ func (h *hlError) GetReasonCode() ReasonCode {

// GetErrorCode returns a formatted error code string
func (h *hlError) GetErrorCode() string {
return fmt.Sprintf("%d-%d", h.componentcode, h.reasoncode)
return fmt.Sprintf("%s-%s", h.componentcode, h.reasoncode)
}

// Message returns the corresponding error message for this error in default
// language.
// TODO - figure out the best way to read in system language instead of using
// hard-coded default language
func (h *hlError) Message() string {
return fmt.Sprintf(emap[fmt.Sprintf("%d", h.componentcode)][fmt.Sprintf("%d", h.reasoncode)][language], h.args...)
// initialize logging level for errors from core.yaml. it can also be set
// for code running on the peer dynamically via CLI using
// "peer logging setlevel error <log-level>"
errorLogLevelString, _ := flogging.GetModuleLogLevel("error")
if errorLogLevelString == logging.DEBUG.String() {
messageWithCallStack := fmt.Sprintf(emap[fmt.Sprintf("%s", h.componentcode)][fmt.Sprintf("%s", h.reasoncode)][language], h.args...) + "\n" + h.GetStack()
return messageWithCallStack
}
return fmt.Sprintf(emap[fmt.Sprintf("%s", h.componentcode)][fmt.Sprintf("%s", h.reasoncode)][language], h.args...)
}

// MessageIn returns the corresponding error message for this error in 'language'
func (h *hlError) MessageIn(language string) string {
return fmt.Sprintf(emap[fmt.Sprintf("%d", h.componentcode)][fmt.Sprintf("%d", h.reasoncode)][language], h.args...)
return fmt.Sprintf(emap[fmt.Sprintf("%s", h.componentcode)][fmt.Sprintf("%s", h.reasoncode)][language], h.args...)
}

// Error creates a CallStackError using a specific Component Code and
Expand Down Expand Up @@ -174,6 +175,10 @@ func getStack(stack callstack) string {
if stack == nil {
return fmt.Sprintf("No call stack available")
}
// this removes the core/errors module calls from the callstack because they
// are not useful for debugging
const firstNonErrorModuleCall int = 2
stack = stack[firstNonErrorModuleCall:]
for _, pc := range stack {
f := runtime.FuncForPC(pc)
file, line := f.FileLine(pc)
Expand Down
74 changes: 67 additions & 7 deletions core/errors/errors_json.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,11 +16,71 @@

package errors

const errorCodes string = `
{"0" :
{"0" :
{"en": "An unknown error occurred."},
"1":
{"en": "An error occurred: %s"}
}
// Component codes - should be set to the same key in the errorCodes json below
const (
Utility ComponentCode = "Utility"
Logging ComponentCode = "Logging"
Peer ComponentCode = "Peer"
)

// Reason codes - should be set to the same key in the errorCodes json below
const (
// Utility errors - placeholders
UtilityUnknownError ReasonCode = "UtilityUnknownError"
UtilityErrorWithArg ReasonCode = "UtilityErrorWithArg"

// Logging errors
LoggingUnknownError ReasonCode = "LoggingUnknownError"
LoggingErrorWithArg ReasonCode = "LoggingErrorWithArg"
LoggingNoParameters ReasonCode = "LoggingNoParameters"
LoggingNoLogLevelParameter ReasonCode = "LoggingNoLogLevelParameter"
LoggingInvalidLogLevel ReasonCode = "LoggingInvalidLogLevel"

// Peer errors
PeerConnectionError ReasonCode = "PeerConnectionError"
)

// To use this file to define a new component code or reason code, please follow
// these steps:
// 1. Add the new component code below the last component code or add the
// new reason code below the last reason code for the applicable component
// in the json formatted string below
// 2. Define the message in English using "en" as the key
// 3. Add a constant above for each new component/reason code making sure it
// matches the key used in the json formatted string below
// 4. Import "github.com/hyperledger/fabric/core/errors" wherever the error
// will be created.
// 5. Reference the component and reason codes in the call to
// errors.ErrorWithCallstack as follows:
// err = errors.ErrorWithCallstack(errors.Logging, errors.LoggingNoParameters)
// 6. Any code that receives this error will automatically have the callstack
// appended if CORE_LOGGING_ERROR is set to DEBUG in peer/core.yaml, at the
// command line when the peer is started, or if the error module is set
// dynamically using the CLI call "peer logging setlevel error debug"
// 6. For an example in context, see "peer/clilogging/common.go", which creates
// a number of callstack errors, and "peer/clilogging/setlevel.go", which
// receives the errors
const errorMapping string = `
{"Utility" :
{"UtilityUnknownError" :
{"en": "An unknown error occurred."},
"UtilityErrorWithArg":
{"en": "An error occurred: %s"}
},
"Logging":
{"LoggingUnknownError" :
{"en": "A logging error occurred."},
"LoggingErrorWithArg":
{"en": "A logging error occurred: %s"},
"LoggingNoParameters":
{"en": "No parameters provided."},
"LoggingNoLogLevelParameter":
{"en": "No log level provided."},
"LoggingInvalidLogLevel":
{"en": "Invalid log level provided - %s"}
},
"Peer" :
{"PeerConnectionError" :
{"en": "Error trying to connect to local peer: %s"}
}
}`
116 changes: 95 additions & 21 deletions core/errors/errors_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,10 +19,12 @@ package errors
import (
"fmt"
"testing"

"github.com/hyperledger/fabric/flogging"
)

func TestError(t *testing.T) {
e := Error(Utility, UnknownError)
e := Error(Utility, UtilityUnknownError)
s := e.GetStack()
if s != "" {
t.Fatalf("No error stack should have been recorded.")
Expand All @@ -31,15 +33,15 @@ func TestError(t *testing.T) {

// TestErrorWithArg tests creating an error with a message argument
func TestErrorWithArg(t *testing.T) {
e := Error(Utility, ErrorWithArg, "arg1")
e := Error(Utility, UtilityErrorWithArg, "arg1")
s := e.GetStack()
if s != "" {
t.Fatalf("No error stack should have been recorded.")
}
}

func TestErrorWithCallstack(t *testing.T) {
e := ErrorWithCallstack(Utility, UnknownError)
e := ErrorWithCallstack(Utility, UtilityUnknownError)
s := e.GetStack()
if s == "" {
t.Fatalf("No error stack was recorded.")
Expand All @@ -49,54 +51,126 @@ func TestErrorWithCallstack(t *testing.T) {
// TestErrorWithCallstackAndArg tests creating an error with a callstack and
// message argument
func TestErrorWithCallstackAndArg(t *testing.T) {
e := ErrorWithCallstack(Utility, ErrorWithArg, "arg1")
e := ErrorWithCallstack(Utility, UtilityErrorWithArg, "arg1")
s := e.GetStack()
if s == "" {
t.Fatalf("No error stack was recorded.")
}
}

func oops() CallStackError {
return Error(Utility, UnknownError)
}

func ExampleError() {
err := oops()
// when the 'error' module is set to anything but debug, the callstack will
// not be appended to the error message
flogging.SetModuleLogLevel("error", "warning")

err := ErrorWithCallstack(Utility, UtilityUnknownError)

if err != nil {
fmt.Printf("%s\n", err.Error())
fmt.Printf("%s\n", err.GetErrorCode())
fmt.Printf("%d\n", err.GetComponentCode())
fmt.Printf("%d\n", err.GetReasonCode())
fmt.Printf("%s\n", err.GetComponentCode())
fmt.Printf("%s\n", err.GetReasonCode())
fmt.Printf("%s\n", err.Message())
fmt.Printf("%s\n", err.MessageIn("en"))
// Output:
// An unknown error occurred.
// 0-0
// 0
// 0
// Utility-UtilityUnknownError
// Utility
// UtilityUnknownError
// An unknown error occurred.
// An unknown error occurred.
}
}

// ExampleErrorWithArg tests the output for a sample error with a message
// argument
func ExampleErrorWithArg() {
err := Error(Utility, ErrorWithArg, "arg1")
func ExampleUtilityErrorWithArg() {
// when the 'error' module is set to anything but debug, the callstack will
// not be appended to the error message
flogging.SetModuleLogLevel("error", "warning")

err := ErrorWithCallstack(Utility, UtilityErrorWithArg, "arg1")

if err != nil {
fmt.Printf("%s\n", err.Error())
fmt.Printf("%s\n", err.GetErrorCode())
fmt.Printf("%d\n", err.GetComponentCode())
fmt.Printf("%d\n", err.GetReasonCode())
fmt.Printf("%s\n", err.GetComponentCode())
fmt.Printf("%s\n", err.GetReasonCode())
fmt.Printf("%s\n", err.Message())
fmt.Printf("%s\n", err.MessageIn("en"))
// Output:
// An error occurred: arg1
// 0-1
// 0
// 1
// Utility-UtilityErrorWithArg
// Utility
// UtilityErrorWithArg
// An error occurred: arg1
// An error occurred: arg1
}
}

// ExampleLoggingInvalidLogLevel tests the output for a logging error where
// and an invalid log level has been provided
func ExampleLoggingInvalidLogLevel() {
// when the 'error' module is set to anything but debug, the callstack will
// not be appended to the error message
flogging.SetModuleLogLevel("error", "warning")

err := ErrorWithCallstack(Logging, LoggingInvalidLogLevel, "invalid")

if err != nil {
fmt.Printf("%s\n", err.Error())
fmt.Printf("%s\n", err.GetErrorCode())
fmt.Printf("%s\n", err.GetComponentCode())
fmt.Printf("%s\n", err.GetReasonCode())
fmt.Printf("%s\n", err.Message())
fmt.Printf("%s\n", err.MessageIn("en"))
// Output:
// Invalid log level provided - invalid
// Logging-LoggingInvalidLogLevel
// Logging
// LoggingInvalidLogLevel
// Invalid log level provided - invalid
// Invalid log level provided - invalid
}
}

// ExampleLoggingInvalidLogLevel tests the output for a logging error where
// and an invalid log level has been provided and the stack trace should be
// displayed with the error message
func ExampleLoggingInvalidLogLevel_withCallstack() {
// when the 'error' module is set to debug, the callstack will be appended
// to the error message
flogging.SetModuleLogLevel("error", "debug")

err := ErrorWithCallstack(Logging, LoggingInvalidLogLevel, "invalid")

if err != nil {
fmt.Printf("%s", err.Error())
fmt.Printf("%s\n", err.GetErrorCode())
fmt.Printf("%s\n", err.GetComponentCode())
fmt.Printf("%s\n", err.GetReasonCode())
fmt.Printf("%s", err.Message())
fmt.Printf("%s\n", err.MessageIn("en"))
// Output:
// Invalid log level provided - invalid
// /opt/gopath/src/github.com/hyperledger/fabric/core/errors/errors_test.go:145 github.com/hyperledger/fabric/core/errors.ExampleLoggingInvalidLogLevel_withCallstack
// /opt/go/src/testing/example.go:115 testing.runExample
// /opt/go/src/testing/example.go:38 testing.RunExamples
// /opt/go/src/testing/testing.go:744 testing.(*M).Run
// github.com/hyperledger/fabric/core/errors/_test/_testmain.go:116 main.main
// /opt/go/src/runtime/proc.go:192 runtime.main
// /opt/go/src/runtime/asm_amd64.s:2087 runtime.goexit
// Logging-LoggingInvalidLogLevel
// Logging
// LoggingInvalidLogLevel
// Invalid log level provided - invalid
// /opt/gopath/src/github.com/hyperledger/fabric/core/errors/errors_test.go:145 github.com/hyperledger/fabric/core/errors.ExampleLoggingInvalidLogLevel_withCallstack
// /opt/go/src/testing/example.go:115 testing.runExample
// /opt/go/src/testing/example.go:38 testing.RunExamples
// /opt/go/src/testing/testing.go:744 testing.(*M).Run
// github.com/hyperledger/fabric/core/errors/_test/_testmain.go:116 main.main
// /opt/go/src/runtime/proc.go:192 runtime.main
// /opt/go/src/runtime/asm_amd64.s:2087 runtime.goexit
// Invalid log level provided - invalid
}
}
4 changes: 2 additions & 2 deletions flogging/logging.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -106,7 +106,7 @@ func GetModuleLogLevel(module string) (string, error) {
// flogging/logging.go
level := logging.GetLevel(module).String()

loggingLogger.Infof("Module '%s' logger enabled for log level: %s", module, level)
loggingLogger.Debugf("Module '%s' logger enabled for log level: %s", module, level)

return level, nil
}
Expand All @@ -121,7 +121,7 @@ func SetModuleLogLevel(module string, logLevel string) (string, error) {
loggingLogger.Warningf("Invalid logging level: %s - ignored", logLevel)
} else {
logging.SetLevel(logging.Level(level), module)
loggingLogger.Infof("Module '%s' logger enabled for log level: %s", module, level)
loggingLogger.Debugf("Module '%s' logger enabled for log level: %s", module, level)
}

logLevelString := level.String()
Expand Down
Loading

0 comments on commit 2dc82e0

Please sign in to comment.