From d43d30ef263bc5652f4fde3350812b36943ce1d6 Mon Sep 17 00:00:00 2001 From: Kevin Fries Date: Fri, 9 Aug 2024 14:25:34 -0600 Subject: [PATCH] Initial Version --- README.md | 132 +++++++++++++++++++++++++++++++++++++++- at_exit.go | 28 +++++++++ go.mod | 17 ++++++ go.sum | 24 ++++++++ logger.go | 161 +++++++++++++++++++++++++++++++++++++++++++++++++ logger_test.go | 77 +++++++++++++++++++++++ 6 files changed, 437 insertions(+), 2 deletions(-) create mode 100644 at_exit.go create mode 100644 go.mod create mode 100644 go.sum create mode 100644 logger.go create mode 100644 logger_test.go diff --git a/README.md b/README.md index ed81c5c..b001fa1 100644 --- a/README.md +++ b/README.md @@ -1,3 +1,131 @@ -# logger +# cse-go-logging +Common golang logging module for use in CSE Go applications -GO library that provides defaults and conventions for the zap logger \ No newline at end of file +## Overview + +This library will help you define a consistent logging experience within your Go applications. In a simple statement... + +* This library will define a **Log Message** +* That is at a **Log Level** +* Which is formatted in a defined **Log Format** +* And forwarded to a **Log Destination** + +This module is wrapper around Uber's Zap package. It serves more as a quick, consistent configuration than to add any additional functionality. For more details on how to use Zap, you can read the [Uber Documentation](https://pkg.go.dev/go.uber.org/zap) + +### Additional Convenience Methods + +I, for one, get annoyed with the following code: + +~~~ +MyObject, err := SomeInitializer(param1, param2) +if err != nil { + panic(err) +} +~~~ + +Those last three lines are extremely common, and clutter up the code and really do not add to readability. So, I created a set of convenience methods where you can replace the error handling with OnError(err) and have it log your error, and panic or fatal automatically. The above code now becomes: + +~~~ +MyObject, err := SomeInitializer(param1, param2) +PanicOnError(err) +~~~ + +Its just athletics, but code is cleaner + + +### Process Cleanup + +Another issue this library is trying to make simpler is proper shutdown on Fatal and Panic. + +In many ways GO follows functional not object-oriented patterns. If an object is created, and defer() was defined, it can have unwanted side effects. So, I often avoid it unless the object is created, used, then immediately discarded. So how to we safely handle longer running objects. + +This module has a solution, and you can use piggyback this in your own programs if you like. + +There is a struct called AtExit that is defined, and it has two methods on it: + +* Register +* Cleanup + +Register takes one parameter, a function name. The call will register that function to be called any time you run a PanicOnError or FatalOnError. The Cleanup function will call all functions "Registered" before issuing the fatal/panic call. + +Usage Example: +~~~ +var ( + db +) + +func init() { + db = // Insert your favorite database connect string here + + AtExit.Register(ShutDownDbConnection) +} + +func ShutDownDbConnection() { + logger.ErrorOnError(db.close()) +} +~~~ + +### Log Message + +A log message, simply put will contain + +* a time and date stamp +* a string indicating the Log Level +* a Log message + +Optional items that may appear include + +* A locator for where the message was requested in the code +* Name Value pairs the code may want you to note +* A stack trace giving even more detailed trace for error handling + +### Log Level + +As with many level based logging libraries, this library will define the following log levels: + +* **Debug:** Recommendation: Tracing variable Values {user: Joe} +* **Info:** Recommendation: Dev status message {DB Connection successful} +* **Warn:** Recommendation: Non-Critical Errors {Got string, expected int, using 0} +* **Error:** Recommendation: Serious error but not enough to stop program execution {Network Not Found, 404 errors} +* **Fatal:** Recommendation: Serious Errors, program exist with error code 1 +* **Panic:** Recommendation: Full panic mode, {divide by 0} + +## Log Format + +In this library, there will be two different output formats + +* **Text:** Single line per message with space delimiters +* **JSON:** JSON format for easy automated processing + +Example of Text Log Format: +~~~ +2024-01-25T12:33:25.613-0700 INFO cse-go-logging/logging_test.go:25 This is my log message +~~~ + +Example of JSON Log Format: +~~~ +{ + "level": "error", + "ts": "2024-01-25T13:10:01.025-0700", + "caller": "cse-go-logging/logging_test.go:25", + "msg": "This is my log message", + "stacktrace": "cse-go-logging.(*LoggingTestSuite).Test_Placeholder\n\t/Users/a846682/GolandProjects/cse-go-logging/logging_test.go:25\nreflect.Value.call\n\t/Users/a846682/.asdf/installs/golang/1.21.6/go/src/reflect/value.go:596\nreflect.Value.Call\n\t/Users/a846682/.asdf/installs/golang/1.21.6/go/src/reflect/value.go:380\ngithub.com/stretchr/testify/suite.Run.func1\n\t/Users/a846682/.asdf/installs/golang/1.21.6/packages/pkg/mod/github.com/stretchr/testify@v1.8.1/suite/suite.go:175\ntesting.tRunner\n\t/Users/a846682/.asdf/installs/golang/1.21.6/go/src/testing/testing.go:1595" +} +~~~ + +### Log Destination + +Depending on the **Log Environment** you have configured your code to use, the log output will be sent to one of three different destinations: + +* **StdErr:** Development, Debug, and Production logs will send messages to standard error. These should appear on your output console within your machine +* **LogFile:** Debug and Testing logs will create a file in your running directory named */log/debug* +* If you are running with a Testing log, the library will not use your live file system, but instead will use a memory map backed filesystem called LogFS and will exist as long as the test suite is running. + +## Log Environments + +This library defines four predefined environments for your logging needs: + +* **Development:** for normal development operations. Logs will be text based, and log Info and higher messages. Output will be to StdErr +* **Debug:** To increase the verbosity of logging, a Debug environment will also include Debug log messages, and will capture all logs to a *logs/debug* file within your working directory. In addition, stack traces will be turned on. So, errors can be more easily tracked. +* **Testing:** This environment will operate exactly like Debug, except that it will not send logs to stderr, and will attach a memory backed file system that /logs/debug will be written to. This allows tests to easily pick up the output of log messages and test for proper logging +* **Production:** Unlike the other environments, Production logs are JSON formatted. diff --git a/at_exit.go b/at_exit.go new file mode 100644 index 0000000..9ad2b75 --- /dev/null +++ b/at_exit.go @@ -0,0 +1,28 @@ +package logger + +import ( + "github.com/sirupsen/logrus" + "path/filepath" + "runtime" +) + +var ( + AtExit AtExitStruct +) + +type AtExitStruct struct { + handlers []func() +} + +func (aes *AtExitStruct) Register(newFunc func()) { + _, file, _, _ := runtime.Caller(1) + logrus.Tracef("At Exit Function Registered: %s", filepath.Base(file)) + aes.handlers = append(aes.handlers, newFunc) +} + +func (aes *AtExitStruct) Cleanup() { + logrus.Info("Cleaning up resources") + for _, handler := range aes.handlers { + handler() + } +} diff --git a/go.mod b/go.mod new file mode 100644 index 0000000..e629d57 --- /dev/null +++ b/go.mod @@ -0,0 +1,17 @@ +module logger + +go 1.22.6 + +require ( + github.com/sirupsen/logrus v1.9.3 + github.com/stretchr/testify v1.9.0 + go.uber.org/zap v1.27.0 +) + +require ( + github.com/davecgh/go-spew v1.1.1 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect + go.uber.org/multierr v1.10.0 // indirect + golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..53ff7dc --- /dev/null +++ b/go.sum @@ -0,0 +1,24 @@ +github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= +github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= +github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= +github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= +github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= +github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg= +github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= +go.uber.org/goleak v1.3.0 h1:2K3zAYmnTNqV73imy9J1T3WC+gmCePx2hEGkimedGto= +go.uber.org/goleak v1.3.0/go.mod h1:CoHD4mav9JJNrW/WLlf7HGZPjdw8EucARQHekz1X6bE= +go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= +go.uber.org/multierr v1.10.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y= +go.uber.org/zap v1.27.0 h1:aJMhYGrd5QSmlpLMr2MftRKl7t8J8PTZPA732ud/XR8= +go.uber.org/zap v1.27.0/go.mod h1:GB2qFLM7cTU87MWRP2mPIjqfIDnGu+VIO4V/SdhGo2E= +golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 h1:0A+M6Uqn+Eje4kHMK80dtF3JCXC4ykBgQG4Fe06QRhQ= +golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= +gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/logger.go b/logger.go new file mode 100644 index 0000000..53002a4 --- /dev/null +++ b/logger.go @@ -0,0 +1,161 @@ +package logger + +import ( + "io" + "log" + "os" + "path/filepath" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +type LogEnvironment int + +const ( + Development LogEnvironment = iota + Debug + Testing + Production +) + +var ( + Logger *zap.Logger + LogConfigs = [4]zap.Config{ + { + Level: zap.NewAtomicLevelAt(zap.InfoLevel), + Development: true, + Encoding: "console", + EncoderConfig: zap.NewDevelopmentEncoderConfig(), + OutputPaths: []string{"stderr"}, + ErrorOutputPaths: []string{"stderr"}, + }, + { + Level: zap.NewAtomicLevelAt(zap.DebugLevel), + Development: true, + Encoding: "console", + EncoderConfig: zap.NewDevelopmentEncoderConfig(), + OutputPaths: []string{"./logs/debug", "stderr"}, + ErrorOutputPaths: []string{"stderr"}, + }, + { + Level: zap.NewAtomicLevelAt(zap.DebugLevel), + Development: true, + Encoding: "console", + EncoderConfig: zap.NewDevelopmentEncoderConfig(), + OutputPaths: []string{"./logs/debug_test"}, + ErrorOutputPaths: []string{"stderr"}, + }, + { + Level: zap.NewAtomicLevelAt(zap.InfoLevel), + Development: false, + Encoding: "json", + EncoderConfig: zapcore.EncoderConfig{ + TimeKey: "ts", + LevelKey: "level", + NameKey: "logger", + CallerKey: "caller", + FunctionKey: zapcore.OmitKey, + MessageKey: "msg", + StacktraceKey: "stacktrace", + LineEnding: zapcore.DefaultLineEnding, + EncodeLevel: zapcore.LowercaseLevelEncoder, + EncodeTime: zapcore.ISO8601TimeEncoder, + EncodeDuration: zapcore.SecondsDurationEncoder, + EncodeCaller: zapcore.ShortCallerEncoder, + }, + OutputPaths: []string{"stderr"}, + ErrorOutputPaths: []string{"stderr"}, + }, + } +) + +func SetLogger(env LogEnvironment) { + var logdir = "./logs" + + switch env { + case Development: + // file system not used + case Debug: + if _, err := os.Stat(logdir); os.IsNotExist(err) { + if err = os.Mkdir(logdir, os.ModePerm); err != nil { + panic(err) + } + } + + if _, err := os.Stat("./logs/debug"); os.IsNotExist(err) { + file, err := os.Create(filepath.Join(logdir, "debug")) + if err != nil { + log.Fatal(err) + } + _ = file.Close() + } + case Testing: + if _, err := os.Stat(logdir); os.IsNotExist(err) { + if err = os.Mkdir(logdir, os.ModePerm); err != nil { + panic(err) + } + } + + if _, err := os.Stat("./logs/debug_test"); os.IsNotExist(err) { + file, err := os.Create(filepath.Join(logdir, "debug_test")) + if err != nil { + log.Fatal(err) + } + _ = file.Close() + } + + AtExit.Register(DeleteTestLog) + case Production: + // file system not used + } + + Logger = zap.Must(LogConfigs[env].Build()) +} + +func DeleteTestLog() { + _ = os.Remove("./logs/debug_test") + + dir, _ := os.Open("./logs") + if _, err := dir.Readdirnames(1); err == io.EOF { + _ = os.Remove("./logs") + } +} + +func DebugOnError(err error) { + if err != nil { + Logger.Debug(err.Error()) + } +} + +func InfoOnError(err error) { + if err != nil { + Logger.Info(err.Error()) + } +} + +func WarnOnError(err error) { + if err != nil { + Logger.Warn(err.Error()) + } +} + +func ErrorOnError(err error) { + if err != nil { + Logger.Error(err.Error()) + } +} + +func FatalOnError(err error) { + if err != nil { + AtExit.Cleanup() + Logger.Fatal(err.Error()) + } +} + +func PanicOnError(err error) { + if err != nil { + AtExit.Cleanup() + Logger.Panic(err.Error()) + } +} diff --git a/logger_test.go b/logger_test.go new file mode 100644 index 0000000..b651d07 --- /dev/null +++ b/logger_test.go @@ -0,0 +1,77 @@ +package logger + +import ( + "fmt" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/suite" + "go.uber.org/zap" + "os" + "testing" +) + +func TestAppConfigSuite(t *testing.T) { + suite.Run(t, new(LoggingTestSuite)) +} + +type LoggingTestSuite struct{ suite.Suite } + +func (suite *LoggingTestSuite) SetupSuite() { + SetLogger(Testing) +} + +func (suite *LoggingTestSuite) TearDownSuite() { + AtExit.Cleanup() +} + +func (suite *LoggingTestSuite) Test_DebugOnError() { + var err error + + DebugOnError(fmt.Errorf("0001: Simple DEBUG test log message")) + assert.FileExists(suite.T(), "./logs/debug_test", "Logger did not create output file") + + b, err := os.ReadFile("./logs/debug_test") + assert.NoError(suite.T(), err, "Error Reading Log File") + assert.Contains(suite.T(), string(b), "0001: Simple DEBUG test log message", "Log does not contain expected message") +} + +func (suite *LoggingTestSuite) Test_InfoOnError() { + var err error + + InfoOnError(fmt.Errorf("0002: Simple INFO test log message")) + assert.FileExists(suite.T(), "./logs/debug_test", "Logger did not create output file") + + b, err := os.ReadFile("./logs/debug_test") + assert.NoError(suite.T(), err, "Error Reading Log File") + assert.Contains(suite.T(), string(b), "0002: Simple INFO test log message", "Log does not contain expected message") +} + +func (suite *LoggingTestSuite) Test_WarnOnError() { + var err error + + WarnOnError(fmt.Errorf("0003: Simple WARN test log message")) + assert.FileExists(suite.T(), "./logs/debug_test", "Logger did not create output file") + + b, err := os.ReadFile("./logs/debug_test") + assert.NoError(suite.T(), err, "Error Reading Log File") + assert.Contains(suite.T(), string(b), "0003: Simple WARN test log message", "Log does not contain expected message") +} + +func (suite *LoggingTestSuite) Test_ErrorOnError() { + var err error + + ErrorOnError(fmt.Errorf("0001: Simple ERROR test log message")) + assert.FileExists(suite.T(), "./logs/debug_test", "Logger did not create output file") + + b, err := os.ReadFile("./logs/debug_test") + assert.NoError(suite.T(), err, "Error Reading Log File") + assert.Contains(suite.T(), string(b), "0001: Simple ERROR test log message", "Log does not contain expected message") +} + +func (suite *LoggingTestSuite) Test_DebugWithVariables() { + Logger.Debug("0010 DEBUG test with data", zap.String("Field1", "Sample Text"), zap.Int("Field2", 1500)) + assert.FileExists(suite.T(), "./logs/debug_test", "Logger did not create output file") + + b, err := os.ReadFile("./logs/debug_test") + assert.NoError(suite.T(), err, "Error Reading Log File") + assert.Contains(suite.T(), string(b), "0010 DEBUG test with data\t{\"Field1\": \"Sample Text\", \"Field2\": 1500}", "Log does not contain expected message") +}