Skip to content

Commit

Permalink
Add check for difference between stdout/stderr streams (#22)
Browse files Browse the repository at this point in the history 
* add check for difference between stdin/stderr streams
* move detection to constructor and setting a field to logger state
* extract detection to isStreamsSame function
* add error handling of os.Stat() with return safe default(false)
* add tests for isStreamSame

by @stillya
  • Loading branch information
@stillya
stillya committed Jan 19, 2023
1 parent 435e156 commit 1d72ca5
Show file tree
Hide file tree
Showing 2 changed files with 73 additions and 20 deletions.
31 changes: 27 additions & 4 deletions logger.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
// The logger's output can be customized in 2 ways:
// - by setting individual formatting flags, i.e. lgr.New(lgr.Msec, lgr.CallerFunc)
// - by passing formatting template, i.e. lgr.New(lgr.Format(lgr.Short))
//
// Leveled output works for messages based on text prefix, i.e. Logf("INFO some message") means INFO level.
// Debug and trace levels can be filtered based on lgr.Trace and lgr.Debug options.
// ERROR, FATAL and PANIC levels send to err as well. FATAL terminate caller application with os.Exit(1)
Expand Down Expand Up @@ -51,6 +52,7 @@ var (
type Logger struct {
// set with Option calls
stdout, stderr io.Writer // destination writes for out and err
sameStream bool // stdout and stderr are the same stream
dbg bool // allows reporting for DEBUG level
trace bool // allows reporting for TRACE and DEBUG levels
callerFile bool // reports caller file with line number, i.e. foo/bar.go:89
Expand Down Expand Up @@ -128,6 +130,8 @@ func New(options ...Option) *Logger {
res.callerOn = strings.Contains(res.format, "{{.Caller") || res.callerFile || res.callerFunc || res.callerPkg
res.levelBracesOn = strings.Contains(res.format, "[{{.Level}}]") || res.levelBraces

res.sameStream = isStreamsSame(res.stdout, res.stderr)

return &res
}

Expand All @@ -140,7 +144,7 @@ func (l *Logger) Logf(format string, args ...interface{}) {
l.logf(format, args...)
}

//nolint gocyclo
// nolint gocyclo
func (l *Logger) logf(format string, args ...interface{}) {

var lv, msg string
Expand Down Expand Up @@ -197,7 +201,7 @@ func (l *Logger) logf(format string, args ...interface{}) {
// write to err as well for high levels, exit(1) on fatal and panic and dump stack on panic level
switch lv {
case "ERROR":
if l.stderr != l.stdout {
if !l.sameStream {
_, _ = l.stderr.Write(data)
}
if l.errorDump {
Expand All @@ -210,12 +214,12 @@ func (l *Logger) logf(format string, args ...interface{}) {
}
}
case "FATAL":
if l.stderr != l.stdout {
if !l.sameStream {
_, _ = l.stderr.Write(data)
}
l.fatal()
case "PANIC":
if l.stderr != l.stdout {
if !l.sameStream {
_, _ = l.stderr.Write(data)
}
_, _ = l.stderr.Write(getDump())
Expand Down Expand Up @@ -405,3 +409,22 @@ func getDump() []byte {
}
return stacktrace[:length]
}

// isStreamsSame checks if two streams are the same by comparing file which they refer to
func isStreamsSame(s1, s2 io.Writer) bool {
s1File, outOk := s1.(*os.File)
s2File, errOk := s2.(*os.File)
if outOk && errOk {
outStat, err := s1File.Stat()
if err != nil {
return false
}
errStat, err := s2File.Stat()
if err != nil {
return false
}
return os.SameFile(outStat, errStat)
} else {
return s1 == s2
}
}
62 changes: 46 additions & 16 deletions logger_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import (
"bytes"
"errors"
"fmt"
"os"
"strconv"
"strings"
"sync"
Expand Down Expand Up @@ -52,22 +53,22 @@ func TestLoggerWithDbg(t *testing.T) {
rout, rerr string
}{
{"aaa", []interface{}{},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) aaa\n", ""},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) aaa\n", ""},
{"DEBUG something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
"2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
{"[DEBUG] something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
"2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
{"INFO something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
{"[INFO] something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
{"blah something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) blah something 123 aaa\n", ""},
"2018/01/07 13:02:34.123 INFO (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) blah something 123 aaa\n", ""},
{"WARN something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 WARN (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
"2018/01/07 13:02:34.123 WARN (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n", ""},
{"ERROR something 123 %s", []interface{}{"aaa"},
"2018/01/07 13:02:34.123 ERROR (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n",
"2018/01/07 13:02:34.123 ERROR (lgr/logger_test.go:81 lgr.TestLoggerWithDbg.func2) something 123 aaa\n"},
"2018/01/07 13:02:34.123 ERROR (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n",
"2018/01/07 13:02:34.123 ERROR (lgr/logger_test.go:82 lgr.TestLoggerWithDbg.func2) something 123 aaa\n"},
}

rout, rerr := bytes.NewBuffer([]byte{}), bytes.NewBuffer([]byte{})
Expand Down Expand Up @@ -97,7 +98,7 @@ func TestLoggerWithDbg(t *testing.T) {
rout.Reset()
rerr.Reset()
l.Logf("[DEBUG] something 123 %s", "err")
assert.Equal(t, "2018/01/07 13:02:34.000 DEBUG (lgr/logger_test.go:99) something 123 err\n", rout.String())
assert.Equal(t, "2018/01/07 13:02:34.000 DEBUG (lgr/logger_test.go:100) something 123 err\n", rout.String())

f := `{{.DT.Format "2006/01/02 15:04:05.000"}} {{.Level}} ({{.CallerFunc}}) {{.Message}}`
l = New(Debug, Out(rout), Err(rerr), Format(f)) // caller func only
Expand Down Expand Up @@ -126,19 +127,19 @@ func TestLoggerWithCallerDepth(t *testing.T) {
}
f(l1)

assert.Equal(t, "2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:127 lgr.TestLoggerWithCallerDepth) something 123 err\n",
assert.Equal(t, "2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:128 lgr.TestLoggerWithCallerDepth) something 123 err\n",
rout.String())

rout.Reset()
rerr.Reset()
l2 := New(Debug, Out(rout), Err(rerr), Format(FullDebug), CallerDepth(0))
l2.now = func() time.Time { return time.Date(2018, 1, 7, 13, 2, 34, 123000000, time.Local) }
f(l2)
assert.Equal(t, "2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:125 lgr.TestLoggerWithCallerDepth."+
assert.Equal(t, "2018/01/07 13:02:34.123 DEBUG (lgr/logger_test.go:126 lgr.TestLoggerWithCallerDepth."+
"func2) something 123 err\n", rout.String())
}

//nolint dupl
// nolint dupl
func TestLogger_formatWithOptions(t *testing.T) {
tbl := []struct {
opts []Option
Expand Down Expand Up @@ -183,7 +184,7 @@ func TestLogger_formatWithOptions(t *testing.T) {
}
}

//nolint dupl
// nolint dupl
func TestLogger_formatWithMapper(t *testing.T) {
tbl := []struct {
opts []Option
Expand Down Expand Up @@ -255,7 +256,7 @@ func TestLogger_formatWithMapper(t *testing.T) {
}
}

//nolint dupl
// nolint dupl
func TestLogger_formatWithPartialMapper(t *testing.T) {
tbl := []struct {
opts []Option
Expand Down Expand Up @@ -363,7 +364,7 @@ func TestLoggerErrorWithDump(t *testing.T) {
assert.Equal(t, "2018/01/07 13:02:34.000 ERROR (lgr.TestLoggerErrorWithDump) oh my, error now! bad thing happened", lines[0])
assert.Equal(t, ">>> stack trace:", lines[1])
assert.Contains(t, lines[2], "github.com/go-pkgz/lgr.TestLoggerErrorWithDump(")
assert.Contains(t, lines[3], "lgr/logger_test.go:361")
assert.Contains(t, lines[3], "lgr/logger_test.go:362")
}

func TestLoggerWithErrorSameOutputs(t *testing.T) {
Expand Down Expand Up @@ -516,6 +517,35 @@ func TestLoggerHidden(t *testing.T) {
assert.Equal(t, "2018/01/07 13:02:34 INFO something ****** 123 ****** xyz\n", rout.String(), "secrets secrets")
}

func TestIsStreamsSameWithStd(t *testing.T) {
sout, serr := os.Stdout, os.Stderr
assert.True(t, isStreamsSame(sout, serr))
}

func TestIsStreamsSameWithSameFile(t *testing.T) {
dir := t.TempDir()
f, _ := os.CreateTemp(dir, "test")
assert.True(t, isStreamsSame(f, f))
}

func TestIsStreamsSameWithDiffFiles(t *testing.T) {
dir := t.TempDir()
f1, _ := os.CreateTemp(dir, "test")
f2, _ := os.CreateTemp(dir, "test")
assert.False(t, isStreamsSame(f1, f2))
}

func TestIsStreamsSameWithSameBuffer(t *testing.T) {
buf := bytes.NewBuffer([]byte{})
assert.True(t, isStreamsSame(buf, buf))
}

func TestIsStreamsSameWithDiffBuffer(t *testing.T) {
buf1, buf2 := bytes.NewBuffer([]byte{}), bytes.NewBuffer([]byte{})
sout, serr := buf1, buf2
assert.False(t, isStreamsSame(sout, serr))
}

func BenchmarkNoDbgNoFormat(b *testing.B) {
rout, rerr := bytes.NewBuffer([]byte{}), bytes.NewBuffer([]byte{})
l := New(Out(rout), Err(rerr))
Expand Down

0 comments on commit 1d72ca5

Please sign in to comment.