From 0d423415f9e28a035051a78fb87c0c24baa13a29 Mon Sep 17 00:00:00 2001 From: Kyal Lanum <48729516+kyallanum@users.noreply.github.com> Date: Mon, 1 Jan 2024 16:29:41 -0700 Subject: [PATCH] Feature/add logging (#12) * Adds logging * Fixes execution not stopping after help command. Fixes #11 --- cmd/cmd_test.go | 24 ++++++++--- cmd/root.go | 64 +++++++++++++++++++---------- examples/apt-term-config.json | 2 +- go.mod | 2 + go.sum | 8 ++++ main.go | 13 +----- models/config/configuration_test.go | 13 +++++- models/config/rule_utils.go | 5 ++- models/config/searchterm_utils.go | 5 ++- models/logger/file_formatter.go | 17 ++++++++ models/logger/fomatter_hook.go | 26 ++++++++++++ models/logger/logger.go | 62 ++++++++++++++++++++++++++++ models/logger/stderr_formatter.go | 17 ++++++++ models/logger/stdout_formatter.go | 15 +++++++ 14 files changed, 228 insertions(+), 45 deletions(-) create mode 100644 models/logger/file_formatter.go create mode 100644 models/logger/fomatter_hook.go create mode 100644 models/logger/logger.go create mode 100644 models/logger/stderr_formatter.go create mode 100644 models/logger/stdout_formatter.go diff --git a/cmd/cmd_test.go b/cmd/cmd_test.go index b8c99a3..ced4462 100644 --- a/cmd/cmd_test.go +++ b/cmd/cmd_test.go @@ -1,20 +1,25 @@ package cmd import ( + "io" "os" "testing" config "github.com/kyallanum/athena/models/config" logs "github.com/kyallanum/athena/models/logs" + "github.com/sirupsen/logrus" ) func TestResolveFile(t *testing.T) { + logger := logrus.New() + logger.SetOutput(io.Discard) + os.Stdout, _ = os.Open(os.DevNull) defer os.Stdout.Close() logFile, _ := logs.LoadLogFile("../examples/apt-term.log") configuration, _ := config.CreateConfiguration("../examples/apt-term-config.json") - _, err := resolveLogFile(logFile, configuration) + _, err := resolveLogFile(logFile, configuration, logger) if err != nil { t.Errorf("An error occurred while resolving log file: %s", err) @@ -28,7 +33,7 @@ func TestResolveLogFileBadLog(t *testing.T) { logFile, _ := logs.LoadLogFile("../examples/apt-term-bad.log") configuration, _ := config.CreateConfiguration("../examples/apt-term-config.json") - _, err := resolveLogFile(logFile, configuration) + _, err := resolveLogFile(logFile, configuration, nil) if err.Error() != "log file contains no contents" { t.Errorf("Error was not properly returned when checking log file contents") @@ -36,13 +41,16 @@ func TestResolveLogFileBadLog(t *testing.T) { } func TestResolveLogFileBadConfig(t *testing.T) { + logger := logrus.New() + logger.SetOutput(io.Discard) + os.Stdout, _ = os.Open(os.DevNull) defer os.Stdout.Close() logFile, _ := logs.LoadLogFile("../examples/apt-term.log") configuration, _ := config.CreateConfiguration("../examples/apt-term-config-bad.json") - _, err := resolveLogFile(logFile, configuration) + _, err := resolveLogFile(logFile, configuration, logger) if err.Error() != "configuration file has no contents" { t.Errorf("Error was not properly returned when checking configuration contents") @@ -50,12 +58,15 @@ func TestResolveLogFileBadConfig(t *testing.T) { } func TestResolveLogFileNoConfigName(t *testing.T) { + logger := logrus.New() + logger.SetOutput(io.Discard) + logFile, _ := logs.LoadLogFile("../examples/apt-term.log") configuration := &config.Configuration{ Rules: make([]config.Rule, 1), } - _, err := resolveLogFile(logFile, configuration) + _, err := resolveLogFile(logFile, configuration, logger) if err.Error() != "configuration file contains no log name" { t.Errorf("Error was not properly returned when checking configuration name") @@ -63,12 +74,15 @@ func TestResolveLogFileNoConfigName(t *testing.T) { } func TestResolveLogFileNoConfigRules(t *testing.T) { + logger := logrus.New() + logger.SetOutput(io.Discard) + logFile, _ := logs.LoadLogFile("../examples/apt-term.log") configuration := &config.Configuration{ Name: "test", } - _, err := resolveLogFile(logFile, configuration) + _, err := resolveLogFile(logFile, configuration, logger) if err.Error() != "configuration does not have any rules" { t.Errorf("Error was not properly returned when checking configuration rules") } diff --git a/cmd/root.go b/cmd/root.go index 0f44303..1dc284d 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -6,11 +6,13 @@ import ( config "github.com/kyallanum/athena/models/config" library "github.com/kyallanum/athena/models/library" + logger_pkg "github.com/kyallanum/athena/models/logger" logs "github.com/kyallanum/athena/models/logs" + "github.com/sirupsen/logrus" "github.com/spf13/cobra" ) -var configFile, logFile string +var configFile, logFile, logOutput string var rootCmd = &cobra.Command{ Use: "athena [flags]", @@ -19,10 +21,10 @@ var rootCmd = &cobra.Command{ SilenceErrors: true, RunE: func(cmd *cobra.Command, args []string) error { if len(configFile) == 0 { - return fmt.Errorf(`required flag(s) "config" not set`) + return fmt.Errorf("exiting: required flag(s) \"config\" not set") } if len(logFile) == 0 { - return fmt.Errorf(`required flag(s) "log-file" not set`) + return fmt.Errorf("exiting: required flag(s) \"log-file\" not set") } return nil }, @@ -35,24 +37,42 @@ func Execute() error { } } + logger := logger_pkg.New() + defer func() { + if err := recover(); err != nil { + logger.Fatalf("An error occured: \n\t%s", err) + } + }() + err := rootCmd.Execute() + if err != nil { + fmt.Printf("%v\n", err) + os.Exit(1) + } else if rootCmd.Flags().Changed("help") { + os.Exit(1) + } + + if logOutput != "" { + logger_pkg.AddFileLogger(logger, logOutput) + } errCheck(err) - fmt.Println("Athena v1.0.0 Starting") - fmt.Println("Getting Configuration File: ", configFile, "...") + logger.Info("Athena v1.0.0 Starting") + + logger.Info("Getting Configuration File: ", configFile, "...") configuration, err := config.CreateConfiguration(configFile) errCheck(err) - fmt.Println("Configuration Loaded") + logger.Info("Configuration Loaded") - fmt.Println("Loading Log File: ", logFile, "... ") + logger.Info("Loading Log File: ", logFile, "... ") logFileContents, err := logs.LoadLogFile(logFile) errCheck(err) - fmt.Println("Log File Loaded") + logger.Info("Log File Loaded") - library, err := resolveLogFile(logFileContents, configuration) + library, err := resolveLogFile(logFileContents, configuration, logger) errCheck(err) - err = printSummary(library) + err = printSummary(library, logger) errCheck(err) return nil @@ -60,10 +80,12 @@ func Execute() error { func init() { rootCmd.Flags().StringVarP(&configFile, "config", "c", os.Getenv("ATHENA_CONFIG_FILE"), "") - rootCmd.Flags().StringVarP(&logFile, "log-file", "l", os.Getenv("ATHENA_LOG_FILE"), "") + rootCmd.Flags().StringVarP(&logFile, "file", "l", os.Getenv("ATHENA_LOG_FILE"), "") + rootCmd.Flags().StringVarP(&logOutput, "log-output", "o", os.Getenv("ATHENA_LOG_OUTPUT"), "") } -func resolveLogFile(contents *logs.LogFile, configuration *config.Configuration) (*library.Library, error) { +func resolveLogFile(contents *logs.LogFile, configuration *config.Configuration, logger *logrus.Logger) (*library.Library, error) { + wrapError := func(err error) error { return fmt.Errorf("unable to resolve log file: \n\t%w", err) } @@ -80,9 +102,9 @@ func resolveLogFile(contents *logs.LogFile, configuration *config.Configuration) ret_library := library.New(configuration.Name) - fmt.Println("Resolving Log File") + logger.Info("Resolving Log File") for i := 0; i < len(configuration.Rules); i++ { - currentRuleData, err := config.ResolveRule(contents, &configuration.Rules[i]) + currentRuleData, err := config.ResolveRule(contents, &configuration.Rules[i], logger) if err != nil { return nil, wrapError(err) } @@ -90,12 +112,12 @@ func resolveLogFile(contents *logs.LogFile, configuration *config.Configuration) ret_library.AddRuleData(configuration.Rules[i].Name, currentRuleData) } - fmt.Println("Log File Resolved") + logger.Info("Log File Resolved") return ret_library, nil } -func printSummary(library *library.Library) error { +func printSummary(library *library.Library, logger *logrus.Logger) error { wrapError := func(err error) error { return fmt.Errorf("unable to print summary: \n\t%w", err) } @@ -105,20 +127,20 @@ func printSummary(library *library.Library) error { return wrapError(err) } - fmt.Printf("\n--------------- %s Log File Summary ---------------\n", libraryName) + logger.Infof("\n--------------- %s Log File Summary ---------------\n", libraryName) libraryKeys := library.LibraryKeys() for _, rule := range libraryKeys { - fmt.Printf("Rule: %s\n", rule) + logger.Infof("Rule: %s\n", rule) ruleData, _ := library.RuleData(rule) summaryDataLen := ruleData.SummaryDataLen() if summaryDataLen == 0 { - fmt.Println("No summary lines provided.") + logger.Info("No summary lines provided.") } else { for i := 0; i < summaryDataLen; i++ { - fmt.Println("\t", ruleData.SummaryData(i)) + logger.Info("\t", ruleData.SummaryData(i)) } } - fmt.Println() + logger.Info() } return nil diff --git a/examples/apt-term-config.json b/examples/apt-term-config.json index 6c5a351..c77cf13 100644 --- a/examples/apt-term-config.json +++ b/examples/apt-term-config.json @@ -2,7 +2,7 @@ "name": "Apt Terminal", "rules": [{ "name": "GetPackage", - "printLog": false, + "printLog": true, "searchTerms": [ "Preparing to unpack ...[\\w/]*/[\\d\\-]*(?[\\w\\W]+?)_[\\w\\W]+? ...", "Unpacking (?{{library_name}}[:\\w]*?) \\((?[\\w\\W]+?)\\) over \\([\\w\\W]+?\\) ...", diff --git a/go.mod b/go.mod index ae60ff9..6456886 100644 --- a/go.mod +++ b/go.mod @@ -4,6 +4,7 @@ go 1.21 require ( github.com/davidmytton/url-verifier v1.0.0 + github.com/sirupsen/logrus v1.9.3 github.com/spf13/cobra v1.8.0 ) @@ -11,4 +12,5 @@ require ( github.com/asaskevich/govalidator v0.0.0-20230301143203-a9d515a09cc2 // indirect github.com/inconshreveable/mousetrap v1.1.0 // indirect github.com/spf13/pflag v1.0.5 // indirect + golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8 // indirect ) diff --git a/go.sum b/go.sum index 4099a51..5efb84c 100644 --- a/go.sum +++ b/go.sum @@ -1,6 +1,7 @@ github.com/asaskevich/govalidator v0.0.0-20230301143203-a9d515a09cc2 h1:DklsrG3dyBCFEj5IhUbnKptjxatkF07cF2ak3yi77so= github.com/asaskevich/govalidator v0.0.0-20230301143203-a9d515a09cc2/go.mod h1:WaHUgvxTVq04UNunO+XhnAqY/wQc+bxr74GqbsZ/Jqw= github.com/cpuguy83/go-md2man/v2 v2.0.3/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= +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/davidmytton/url-verifier v1.0.0 h1:TIdwZ+rWVnfnJPMD/DclwEJ0XewV4jkr0qEcX/58n+4= @@ -10,12 +11,19 @@ github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLf 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/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= +github.com/sirupsen/logrus v1.9.3 h1:dueUQJ1C2q9oE3F7wvmSGAaVtTmUizReu6fjN8uqzbQ= +github.com/sirupsen/logrus v1.9.3/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ= github.com/spf13/cobra v1.8.0 h1:7aJaZx1B85qltLMc546zn58BxxfZdR/W22ej9CFoEf0= github.com/spf13/cobra v1.8.0/go.mod h1:WXLWApfZ71AjXPya3WOlMsY9yMs7YeiHhFVlvLyhcho= github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA= github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= +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.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= +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/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/main.go b/main.go index e8e44e1..5d43837 100644 --- a/main.go +++ b/main.go @@ -1,20 +1,9 @@ package main import ( - "fmt" - "os" - "github.com/kyallanum/athena/cmd" ) func main() { - defer func() { - if err := recover(); err != nil { - fmt.Fprintln(os.Stderr, "\nAn error occured: ", err) - } - }() - - if err := cmd.Execute(); err != nil { - panic(err) - } + cmd.Execute() } diff --git a/models/config/configuration_test.go b/models/config/configuration_test.go index 8156ae0..510ad6c 100644 --- a/models/config/configuration_test.go +++ b/models/config/configuration_test.go @@ -3,6 +3,7 @@ package models import ( "bufio" "encoding/json" + "io" "net/http" "net/http/httptest" "os" @@ -11,6 +12,7 @@ import ( "testing" logs "github.com/kyallanum/athena/models/logs" + "github.com/sirupsen/logrus" ) func TestTranslateRegex(t *testing.T) { @@ -139,6 +141,9 @@ func TestCreateConfigurationFromWeb(t *testing.T) { } func TestResolveRule(t *testing.T) { + logger := logrus.New() + logger.SetOutput(io.Discard) + os.Stdout, _ = os.Open(os.DevNull) defer os.Stdout.Close() @@ -148,7 +153,7 @@ func TestResolveRule(t *testing.T) { currentRule := currentConfig.Rules[0] - ruleData, err := ResolveRule(logFile, ¤tRule) + ruleData, err := ResolveRule(logFile, ¤tRule, logger) if err != nil { t.Errorf("An error was returned when one should not have been: \n\t%s", err.Error()) } @@ -166,6 +171,10 @@ func TestResolveRuleBadRule(t *testing.T) { t.Errorf("%s", err.(error).Error()) } }() + + logger := logrus.New() + logger.SetOutput(io.Discard) + os.Stdout, _ = os.Open(os.DevNull) defer os.Stdout.Close() @@ -173,5 +182,5 @@ func TestResolveRuleBadRule(t *testing.T) { currentRule := &Rule{} - ResolveRule(logFile, currentRule) + ResolveRule(logFile, currentRule, logger) } diff --git a/models/config/rule_utils.go b/models/config/rule_utils.go index 0be9ba5..e4bc14f 100644 --- a/models/config/rule_utils.go +++ b/models/config/rule_utils.go @@ -5,9 +5,10 @@ import ( library "github.com/kyallanum/athena/models/library" logs "github.com/kyallanum/athena/models/logs" + "github.com/sirupsen/logrus" ) -func ResolveRule(contents *logs.LogFile, rule *Rule) (*library.RuleData, error) { +func ResolveRule(contents *logs.LogFile, rule *Rule, logger *logrus.Logger) (*library.RuleData, error) { wrapError := func(err error) error { return fmt.Errorf("unable to resolve rule %s: \n\t%w", rule.Name, err) } @@ -18,7 +19,7 @@ func ResolveRule(contents *logs.LogFile, rule *Rule) (*library.RuleData, error) currentRuleData := library.NewRuleData() for !allEntriesFound { - currentSearchTermData, err := resolveSearchTerms(contents, rule, &linesResolved) + currentSearchTermData, err := resolveSearchTerms(contents, rule, &linesResolved, logger) if err != nil { return nil, wrapError(err) } diff --git a/models/config/searchterm_utils.go b/models/config/searchterm_utils.go index aa98ee2..0ecf2f4 100644 --- a/models/config/searchterm_utils.go +++ b/models/config/searchterm_utils.go @@ -6,9 +6,10 @@ import ( library "github.com/kyallanum/athena/models/library" logs "github.com/kyallanum/athena/models/logs" + "github.com/sirupsen/logrus" ) -func resolveSearchTerms(logFile *logs.LogFile, rule *Rule, linesResolved *[]int) (*library.SearchTermData, error) { +func resolveSearchTerms(logFile *logs.LogFile, rule *Rule, linesResolved *[]int, logger *logrus.Logger) (*library.SearchTermData, error) { wrapError := func(err error) error { return fmt.Errorf("unable to resolve search terms for rule %s: \n\t%w", rule.Name, err) } @@ -47,7 +48,7 @@ func resolveSearchTerms(logFile *logs.LogFile, rule *Rule, linesResolved *[]int) } if rule.PrintLog { - fmt.Printf("%d: %s\n", fileIndex+1, currentLine) + logger.Infof("%d: %s", fileIndex+1, currentLine) } *linesResolved = append(*linesResolved, fileIndex) diff --git a/models/logger/file_formatter.go b/models/logger/file_formatter.go new file mode 100644 index 0000000..7dbc6cb --- /dev/null +++ b/models/logger/file_formatter.go @@ -0,0 +1,17 @@ +package logger + +import ( + "fmt" + + "github.com/sirupsen/logrus" +) + +type FileFormatter struct { + logrus.TextFormatter + TimestampFormat string +} + +func (formatter *FileFormatter) Format(entry *logrus.Entry) ([]byte, error) { + timestamp := entry.Time.Format(formatter.TimestampFormat) + return []byte(fmt.Sprintf("%s %s: %s\n", timestamp, entry.Level.String(), entry.Message)), nil +} diff --git a/models/logger/fomatter_hook.go b/models/logger/fomatter_hook.go new file mode 100644 index 0000000..af64e1e --- /dev/null +++ b/models/logger/fomatter_hook.go @@ -0,0 +1,26 @@ +package logger + +import ( + "io" + + "github.com/sirupsen/logrus" +) + +type FormatterHook struct { + Writer io.Writer + LogLevels []logrus.Level + Formatter logrus.Formatter +} + +func (hook *FormatterHook) Fire(entry *logrus.Entry) error { + line, err := hook.Formatter.Format(entry) + if err != nil { + return err + } + _, err = hook.Writer.Write(line) + return err +} + +func (hook *FormatterHook) Levels() []logrus.Level { + return hook.LogLevels +} diff --git a/models/logger/logger.go b/models/logger/logger.go new file mode 100644 index 0000000..9a438e3 --- /dev/null +++ b/models/logger/logger.go @@ -0,0 +1,62 @@ +package logger + +import ( + "io" + "os" + + "github.com/sirupsen/logrus" +) + +func AddFileLogger(logger *logrus.Logger, fileName string) { + file, err := os.OpenFile(fileName, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644) + if err != nil { + logger.Fatalf("An error occurred: \n\t%s", err.Error()) + } + + FileHook := &FormatterHook{ + Writer: file, + LogLevels: []logrus.Level{ + logrus.InfoLevel, + logrus.DebugLevel, + logrus.WarnLevel, + logrus.ErrorLevel, + logrus.FatalLevel, + logrus.PanicLevel, + }, + Formatter: &FileFormatter{ + TimestampFormat: "01/02/2006 15:03:04", + }, + } + + logger.AddHook(FileHook) +} + +func New() *logrus.Logger { + newLogger := logrus.New() + newLogger.SetOutput(io.Discard) + newLogger.SetLevel(logrus.InfoLevel) + + StdoutHook := &FormatterHook{ + Writer: os.Stdout, + LogLevels: []logrus.Level{ + logrus.InfoLevel, + }, + Formatter: &StdoutFormatter{}, + } + newLogger.AddHook(StdoutHook) + + StderrHook := &FormatterHook{ + Writer: os.Stderr, + LogLevels: []logrus.Level{ + logrus.ErrorLevel, + logrus.FatalLevel, + logrus.PanicLevel, + }, + Formatter: &StderrFormatter{ + TimestampFormat: "01/02/2006 15:04:05", + }, + } + newLogger.AddHook(StderrHook) + + return newLogger +} diff --git a/models/logger/stderr_formatter.go b/models/logger/stderr_formatter.go new file mode 100644 index 0000000..d625850 --- /dev/null +++ b/models/logger/stderr_formatter.go @@ -0,0 +1,17 @@ +package logger + +import ( + "fmt" + + "github.com/sirupsen/logrus" +) + +type StderrFormatter struct { + logrus.Formatter + TimestampFormat string +} + +func (formatter *StderrFormatter) Format(entry *logrus.Entry) ([]byte, error) { + timestamp := entry.Time.Format(formatter.TimestampFormat) + return []byte(fmt.Sprintf("%s Error: %s", timestamp, entry.Message)), nil +} diff --git a/models/logger/stdout_formatter.go b/models/logger/stdout_formatter.go new file mode 100644 index 0000000..2a8515f --- /dev/null +++ b/models/logger/stdout_formatter.go @@ -0,0 +1,15 @@ +package logger + +import ( + "fmt" + + "github.com/sirupsen/logrus" +) + +type StdoutFormatter struct { + logrus.TextFormatter +} + +func (formatter *StdoutFormatter) Format(entry *logrus.Entry) ([]byte, error) { + return []byte(fmt.Sprintf("%s\n", entry.Message)), nil +}