diff --git a/.golangci.yml b/.golangci.yml index e74f4ad..5f96da4 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -343,11 +343,6 @@ linters: skip-single-param: true mnd: - # List of function patterns to exclude from analysis. - # Values always ignored: `time.Date`, - # `strconv.FormatInt`, `strconv.FormatUint`, `strconv.FormatFloat`, - # `strconv.ParseInt`, `strconv.ParseUint`, `strconv.ParseFloat`. - # Default: [] ignored-functions: - args.Error - flag.Arg @@ -451,6 +446,8 @@ linters: linters: [ testpackage ] - path: 'dbg/dbg_test.go' linters: [ testpackage ] + - path: 'logging/example_test.go' + linters: [ testableexamples ] - source: 'TODO' linters: [ godot ] - text: 'should have a package comment' diff --git a/logging/doc.go b/logging/doc.go index 3237df8..cce3ac3 100644 --- a/logging/doc.go +++ b/logging/doc.go @@ -2,14 +2,13 @@ // consist of timestamps, an actor and event string, and a mapping of // string key-value attribute pairs. For example, // -// log.Error("serialiser", "failed to open file", -// map[string]string{ -// "error": err.Error(), -// "path": "data.bin", -// }) +// log.Error("serialiser", "failed to open file", +// map[string]string{ +// "error": err.Error(), +// "path": "data.bin", +// }) // // This produces the output message // -// [2016-04-01T15:04:30-0700] [ERROR] [actor:serialiser event:failed to open file] error=is a directory path=data.bin -// +// [2016-04-01T15:04:30-0700] [ERROR] [actor:serialiser event:failed to open file] error=is a directory path=data.bin package logging diff --git a/logging/example/example.go b/logging/example/example.go index 57aa88e..2ea9fae 100644 --- a/logging/example/example.go +++ b/logging/example/example.go @@ -25,8 +25,8 @@ func main() { log.Info("example", "filelog test", nil) exampleNewFromFile() - os.Remove("example.log") - os.Remove("example.err") + _ = os.Remove("example.log") + _ = os.Remove("example.err") } func exampleNewFromFile() { diff --git a/logging/file.go b/logging/file.go index 7a5b608..56023f5 100644 --- a/logging/file.go +++ b/logging/file.go @@ -1,6 +1,10 @@ package logging -import "os" +import ( + "os" + + "github.com/pkg/errors" +) // File writes its logs to file. type File struct { @@ -8,22 +12,6 @@ type File struct { *LogWriter } -// Close calls close on the underlying log files. -func (fl *File) Close() error { - if fl.fo != nil { - if err := fl.fo.Close(); err != nil { - return err - } - fl.fo = nil - } - - if fl.fe != nil { - return fl.fe.Close() - } - - return nil -} - // NewFile creates a new Logger that writes all logs to the file // specified by path. If overwrite is specified, the log file will be // truncated before writing. Otherwise, the log file will be appended @@ -36,7 +24,7 @@ func NewFile(path string, overwrite bool) (*File, error) { if overwrite { fl.fo, err = os.Create(path) } else { - fl.fo, err = os.OpenFile(path, os.O_WRONLY|os.O_APPEND, 0644) + fl.fo, err = os.OpenFile(path, os.O_WRONLY|os.O_APPEND, 0600) // #nosec G302 } if err != nil { @@ -59,7 +47,7 @@ func NewSplitFile(outpath, errpath string, overwrite bool) (*File, error) { if overwrite { fl.fo, err = os.Create(outpath) } else { - fl.fo, err = os.OpenFile(outpath, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644) + fl.fo, err = os.OpenFile(outpath, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0600) } if err != nil { @@ -69,14 +57,51 @@ func NewSplitFile(outpath, errpath string, overwrite bool) (*File, error) { if overwrite { fl.fe, err = os.Create(errpath) } else { - fl.fe, err = os.OpenFile(errpath, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0644) + fl.fe, err = os.OpenFile(errpath, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0600) } if err != nil { - fl.Close() + if closeErr := fl.Close(); closeErr != nil { + return nil, errors.Wrap(err, closeErr.Error()) + } return nil, err } fl.LogWriter = NewLogWriter(fl.fo, fl.fe) return fl, nil } + +// Close calls close on the underlying log files. +func (fl *File) Close() error { + if fl.fo != nil { + if err := fl.fo.Close(); err != nil { + return err + } + fl.fo = nil + } + + if fl.fe != nil { + return fl.fe.Close() + } + + return nil +} + +func (fl *File) Flush() error { + if err := fl.fo.Sync(); err != nil { + return err + } + return fl.fe.Sync() +} + +func (fl *File) Chmod(mode os.FileMode) error { + if err := fl.fo.Chmod(mode); err != nil { + return errors.WithMessage(err, "failed to chmod output log") + } + + if err := fl.fe.Chmod(mode); err != nil { + return errors.WithMessage(err, "failed to chmod error log") + } + + return nil +} diff --git a/logging/levels.go b/logging/levels.go index 2881272..64ac4fd 100644 --- a/logging/levels.go +++ b/logging/levels.go @@ -32,31 +32,6 @@ const ( // DefaultLevel is the default logging level when none is provided. const DefaultLevel = LevelInfo -// Cheap integer to fixed-width decimal ASCII. Give a negative width -// to avoid zero-padding. (From log/log.go in the standard library). -func itoa(i int, wid int) string { - // Assemble decimal in reverse order. - var b [20]byte - bp := len(b) - 1 - for i >= 10 || wid > 1 { - wid-- - q := i / 10 - b[bp] = byte('0' + i - q*10) - bp-- - i = q - } - // i < 10 - b[bp] = byte('0' + i) - return string(b[bp:]) -} - -func writeToOut(level Level) bool { - if level < LevelWarning { - return true - } - return false -} - var levelPrefix = [...]string{ LevelDebug: "DEBUG", LevelInfo: "INFO", diff --git a/logging/log.go b/logging/log.go index 5a32302..c187749 100644 --- a/logging/log.go +++ b/logging/log.go @@ -1,6 +1,7 @@ package logging import ( + "errors" "fmt" "io" "os" @@ -11,64 +12,64 @@ import ( // // Log messages consist of four components: // -// 1. The **level** attaches a notion of priority to the log message. -// Several log levels are available: +// 1. The **level** attaches a notion of priority to the log message. +// Several log levels are available: // -// + FATAL (32): the system is in an unsuable state, and cannot -// continue to run. Most of the logging for this will cause the -// program to exit with an error code. -// + CRITICAL (16): critical conditions. The error, if uncorrected, is -// likely to cause a fatal condition shortly. An example is running -// out of disk space. This is something that the ops team should get -// paged for. -// + ERROR (8): error conditions. A single error doesn't require an -// ops team to be paged, but repeated errors should often trigger a -// page based on threshold triggers. An example is a network -// failure: it might be a transient failure (these do happen), but -// most of the time it's self-correcting. -// + WARNING (4): warning conditions. An example of this is a bad -// request sent to a server. This isn't an error on the part of the -// program, but it may be indicative of other things. Like errors, -// the ops team shouldn't be paged for errors, but a page might be -// triggered if a certain threshold of warnings is reached (which is -// typically much higher than errors). For example, repeated -// warnings might be a sign that the system is under attack. -// + INFO (2): informational message. This is a normal log message -// that is used to deliver information, such as recording -// requests. Ops teams are never paged for informational -// messages. This is the default log level. -// + DEBUG (1): debug-level message. These are only used during -// development or if a deployed system repeatedly sees abnormal -// errors. +// + FATAL (32): the system is in an unusable state and cannot +// continue to run. Most of the logging for this will cause the +// program to exit with an error code. +// + CRITICAL (16): critical conditions. The error, if uncorrected, is +// likely to cause a fatal condition shortly. An example is running +// out of disk space. This is something that the ops team should get +// paged for. +// + ERROR (8): error conditions. A single error doesn't require an +// ops team to be paged, but repeated errors should often trigger a +// page based on threshold triggers. An example is a network +// failure: it might be a transient failure (these do happen), but +// most of the time it's self-correcting. +// + WARNING (4): warning conditions. An example of this is a bad +// request sent to a server. This isn't an error on the part of the +// program, but it may be indicative of other things. Like errors, +// the ops team shouldn't be paged for errors, but a page might be +// triggered if a certain threshold of warnings is reached (which is +// typically much higher than errors). For example, repeated +// warnings might be a sign that the system is under attack. +// + INFO (2): informational message. This is a normal log message +// used to deliver information, such as recording requests. Ops +// teams are never paged for informational messages. This is the +// default log level. +// + DEBUG (1): debug-level message. These are only used during +// development or if a deployed system repeatedly sees abnormal +// errors. // -// The numeric values indicate the priority of a given level. +// The numeric values indicate the priority of a given level. // -// 2. The **actor** is used to specify which component is generating -// the log message. This could be the program name, or it could be -// a specific component inside the system. +// 2. The **actor** is used to specify which component is generating +// the log message. This could be the program name, or it could be +// a specific component inside the system. // -// 3. The **event** is a short message indicating what happened. This is -// most like the traditional log message. +// 3. The **event** is a short message indicating what happened. This is +// most like the traditional log message. // -// 4. The **attributes** are an optional set of key-value string pairs that -// provide additional information. +// 4. The **attributes** are an optional set of key-value string pairs that +// provide additional information. // // Additionally, each log message has an associated timestamp. For the // text-based logs, this is "%FT%T%z"; for the binary logs, this is a // 64-bit Unix timestamp. An example text-based timestamp might look like :: // -// [2016-03-27T20:59:27-0700] [INFO] [actor:server event:request received] client=192.168.2.5 request-size=839 +// [2016-03-27T20:59:27-0700] [INFO] [actor:server event:request received] client=192.168.2.5 request-size=839 // // Note that this is organised in a manner that facilitates parsing:: // -// /\[(\d{4}-\d{3}-\d{2}T\d{2}:\d{2}:\d{2}[+-]\d{4})\] \[(\w+\)]\) \[actor:(.+?) event:(.+?)\]/ +// /\[(\d{4}-\d{3}-\d{2}T\d{2}:\d{2}:\d{2}[+-]\d{4})\] \[(\w+\)]\) \[actor:(.+?) event:(.+?)\]/ // // will cover the header: // -// + ``$1`` contains the timestamp -// + ``$2`` contains the level -// + ``$3`` contains the actor -// + ``$4`` contains the event +// + “$1“ contains the timestamp +// + “$2“ contains the level +// + “$3“ contains the actor +// + “$4“ contains the event. type Logger interface { // SetLevel sets the minimum log level. SetLevel(Level) @@ -131,7 +132,7 @@ func (lw *LogWriter) output(w io.Writer, lvl Level, actor, event string, attrs m } // Debug emits a debug-level message. These are only used during -// development or if a deployed system repeatedly sees abnormal +// development, or if a deployed system repeatedly sees abnormal // errors. // // Actor specifies the component emitting the message; event indicates @@ -213,7 +214,7 @@ func (lw *LogWriter) Critical(actor, event string, attrs map[string]string) { lw.output(lw.we, LevelCritical, actor, event, attrs) } -// Fatal emits a message indicating that the system is in an unsuable +// Fatal emits a message indicating that the system is in an unusable // state, and cannot continue to run. The program will exit with exit // code 1. // @@ -229,9 +230,9 @@ func (lw *LogWriter) Fatal(actor, event string, attrs map[string]string) { os.Exit(1) } -// FatalCode emits a message indicating that the system is in an unsuable +// FatalCode emits a message indicating that the system is in an unusable // state, and cannot continue to run. The program will exit with the -// exit code speicfied in the exitcode argument. +// exit code specified in the exitcode argument. // // Actor specifies the component emitting the message; event indicates // the event that caused the log message to be emitted. attrs is a map @@ -245,7 +246,7 @@ func (lw *LogWriter) FatalCode(exitcode int, actor, event string, attrs map[stri os.Exit(exitcode) } -// FatalNoDie emits a message indicating that the system is in an unsuable +// FatalNoDie emits a message indicating that the system is in an unusable // state, and cannot continue to run. The program will not exit; it is // assumed that the caller has some final clean up to perform. // @@ -314,11 +315,17 @@ func (m *Multi) Status() error { } func (m *Multi) Close() error { + var errs []error for _, l := range m.loggers { - l.Close() + if err := l.Close(); err != nil { + errs = append(errs, err) + } } - return nil + if len(errs) == 0 { + return nil + } + return errors.Join(errs...) } func (m *Multi) Debug(actor, event string, attrs map[string]string) { diff --git a/logging/log_test.go b/logging/log_test.go index 4a26765..f9b386f 100644 --- a/logging/log_test.go +++ b/logging/log_test.go @@ -1,30 +1,32 @@ -package logging +package logging_test import ( "bytes" "fmt" "os" "testing" + + "git.wntrmute.dev/kyle/goutils/logging" ) // A list of implementations that should be tested. -var implementations []Logger +var implementations []logging.Logger func init() { - lw := NewLogWriter(&bytes.Buffer{}, nil) - cw := NewConsole() + lw := logging.NewLogWriter(&bytes.Buffer{}, nil) + cw := logging.NewConsole() implementations = append(implementations, lw) implementations = append(implementations, cw) } func TestFileSetup(t *testing.T) { - fw1, err := NewFile("fw1.log", true) + fw1, err := logging.NewFile("fw1.log", true) if err != nil { t.Fatalf("failed to create new file logger: %v", err) } - fw2, err := NewSplitFile("fw2.log", "fw2.err", true) + fw2, err := logging.NewSplitFile("fw2.log", "fw2.err", true) if err != nil { t.Fatalf("failed to create new split file logger: %v", err) } @@ -33,7 +35,7 @@ func TestFileSetup(t *testing.T) { implementations = append(implementations, fw2) } -func TestImplementations(t *testing.T) { +func TestImplementations(_ *testing.T) { for _, l := range implementations { l.Info("TestImplementations", "Info message", map[string]string{"type": fmt.Sprintf("%T", l)}) @@ -44,20 +46,30 @@ func TestImplementations(t *testing.T) { func TestCloseLoggers(t *testing.T) { for _, l := range implementations { - l.Close() + if err := l.Close(); err != nil { + t.Errorf("failed to close logger: %v", err) + } } } func TestDestroyLogFiles(t *testing.T) { - os.Remove("fw1.log") - os.Remove("fw2.log") - os.Remove("fw2.err") + if err := os.Remove("fw1.log"); err != nil { + t.Errorf("failed to remove fw1.log: %v", err) + } + + if err := os.Remove("fw2.log"); err != nil { + t.Errorf("failed to remove fw2.log: %v", err) + } + + if err := os.Remove("fw2.err"); err != nil { + t.Errorf("failed to remove fw2.err: %v", err) + } } func TestMulti(t *testing.T) { - c1 := NewConsole() - c2 := NewConsole() - m := NewMulti(c1, c2) + c1 := logging.NewConsole() + c2 := logging.NewConsole() + m := logging.NewMulti(c1, c2) if !m.Good() { t.Fatal("failed to set up multi logger") }