From 022701a5822c30cb2b9a5db093dad21549ff2a6a Mon Sep 17 00:00:00 2001 From: Lunny Xiao Date: Wed, 3 Apr 2019 22:16:30 +0800 Subject: [PATCH] moved from gitea main repository --- base.go | 328 ++++++++++++++++++++++++++++++++++++++++++ base_test.go | 277 ++++++++++++++++++++++++++++++++++++ colors.go | 348 +++++++++++++++++++++++++++++++++++++++++++++ conn.go | 121 ++++++++++++++++ conn_test.go | 240 +++++++++++++++++++++++++++++++ console.go | 78 ++++++++++ console_test.go | 137 ++++++++++++++++++ console_windows.go | 43 ++++++ errors.go | 62 ++++++++ event.go | 335 +++++++++++++++++++++++++++++++++++++++++++ file.go | 259 +++++++++++++++++++++++++++++++++ file_test.go | 247 ++++++++++++++++++++++++++++++++ go.mod | 9 ++ go.sum | 12 ++ level.go | 111 +++++++++++++++ level_test.go | 55 +++++++ log.go | 245 +++++++++++++++++++++++++++++++ log_test.go | 154 ++++++++++++++++++++ logger.go | 156 ++++++++++++++++++++ provider.go | 26 ++++ smtp.go | 111 +++++++++++++++ smtp_test.go | 86 +++++++++++ stack.go | 83 +++++++++++ 23 files changed, 3523 insertions(+) create mode 100644 base.go create mode 100644 base_test.go create mode 100644 colors.go create mode 100644 conn.go create mode 100644 conn_test.go create mode 100644 console.go create mode 100644 console_test.go create mode 100644 console_windows.go create mode 100644 errors.go create mode 100644 event.go create mode 100644 file.go create mode 100644 file_test.go create mode 100644 go.mod create mode 100644 go.sum create mode 100644 level.go create mode 100644 level_test.go create mode 100644 log.go create mode 100644 log_test.go create mode 100644 logger.go create mode 100644 provider.go create mode 100644 smtp.go create mode 100644 smtp_test.go create mode 100644 stack.go diff --git a/base.go b/base.go new file mode 100644 index 0000000..5577737 --- /dev/null +++ b/base.go @@ -0,0 +1,328 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "bytes" + "fmt" + "io" + "regexp" + "strings" + "sync" +) + +// These flags define which text to prefix to each log entry generated +// by the Logger. Bits are or'ed together to control what's printed. +// There is no control over the order they appear (the order listed +// here) or the format they present (as described in the comments). +// The prefix is followed by a colon only if more than time is stated +// is specified. For example, flags Ldate | Ltime +// produce, 2009/01/23 01:23:23 message. +// The standard is: +// 2009/01/23 01:23:23 ...a/b/c/d.go:23:runtime.Caller() [I]: message +const ( + Ldate = 1 << iota // the date in the local time zone: 2009/01/23 + Ltime // the time in the local time zone: 01:23:23 + Lmicroseconds // microsecond resolution: 01:23:23.123123. assumes Ltime. + Llongfile // full file name and line number: /a/b/c/d.go:23 + Lshortfile // final file name element and line number: d.go:23. overrides Llongfile + Lfuncname // function name of the caller: runtime.Caller() + Lshortfuncname // last part of the function name + LUTC // if Ldate or Ltime is set, use UTC rather than the local time zone + Llevelinitial // Initial character of the provided level in brackets eg. [I] for info + Llevel // Provided level in brackets [INFO] + + // Last 20 characters of the filename + Lmedfile = Lshortfile | Llongfile + + // LstdFlags is the initial value for the standard logger + LstdFlags = Ldate | Ltime | Lmedfile | Lshortfuncname | Llevelinitial +) + +var flagFromString = map[string]int{ + "none": 0, + "date": Ldate, + "time": Ltime, + "microseconds": Lmicroseconds, + "longfile": Llongfile, + "shortfile": Lshortfile, + "funcname": Lfuncname, + "shortfuncname": Lshortfuncname, + "utc": LUTC, + "levelinitial": Llevelinitial, + "level": Llevel, + "medfile": Lmedfile, + "stdflags": LstdFlags, +} + +// FlagsFromString takes a comma separated list of flags and returns +// the flags for this string +func FlagsFromString(from string) int { + flags := 0 + for _, flag := range strings.Split(strings.ToLower(from), ",") { + f, ok := flagFromString[strings.TrimSpace(flag)] + if ok { + flags = flags | f + } + } + return flags +} + +type byteArrayWriter []byte + +func (b *byteArrayWriter) Write(p []byte) (int, error) { + *b = append(*b, p...) + return len(p), nil +} + +// BaseLogger represent a basic logger for Gitea +type BaseLogger struct { + out io.WriteCloser + mu sync.Mutex + + Level Level `json:"level"` + StacktraceLevel Level `json:"stacktraceLevel"` + Flags int `json:"flags"` + Prefix string `json:"prefix"` + Colorize bool `json:"colorize"` + Expression string `json:"expression"` + regexp *regexp.Regexp +} + +func (b *BaseLogger) createLogger(out io.WriteCloser, level ...Level) { + b.mu.Lock() + defer b.mu.Unlock() + b.out = out + switch b.Flags { + case 0: + b.Flags = LstdFlags + case -1: + b.Flags = 0 + } + if len(level) > 0 { + b.Level = level[0] + } + b.createExpression() +} + +func (b *BaseLogger) createExpression() { + if len(b.Expression) > 0 { + var err error + b.regexp, err = regexp.Compile(b.Expression) + if err != nil { + b.regexp = nil + } + } +} + +// GetLevel returns the logging level for this logger +func (b *BaseLogger) GetLevel() Level { + return b.Level +} + +// GetStacktraceLevel returns the stacktrace logging level for this logger +func (b *BaseLogger) GetStacktraceLevel() Level { + return b.StacktraceLevel +} + +// Copy of cheap integer to fixed-width decimal to ascii from logger. +func itoa(buf *[]byte, i int, wid int) { + 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) + *buf = append(*buf, b[bp:]...) +} + +func (b *BaseLogger) createMsg(buf *[]byte, event *Event) { + *buf = append(*buf, b.Prefix...) + t := event.time + if b.Flags&(Ldate|Ltime|Lmicroseconds) != 0 { + if b.Colorize { + *buf = append(*buf, fgCyanBytes...) + } + if b.Flags&LUTC != 0 { + t = t.UTC() + } + if b.Flags&Ldate != 0 { + year, month, day := t.Date() + itoa(buf, year, 4) + *buf = append(*buf, '/') + itoa(buf, int(month), 2) + *buf = append(*buf, '/') + itoa(buf, day, 2) + *buf = append(*buf, ' ') + } + if b.Flags&(Ltime|Lmicroseconds) != 0 { + hour, min, sec := t.Clock() + itoa(buf, hour, 2) + *buf = append(*buf, ':') + itoa(buf, min, 2) + *buf = append(*buf, ':') + itoa(buf, sec, 2) + if b.Flags&Lmicroseconds != 0 { + *buf = append(*buf, '.') + itoa(buf, t.Nanosecond()/1e3, 6) + } + *buf = append(*buf, ' ') + } + if b.Colorize { + *buf = append(*buf, resetBytes...) + } + + } + if b.Flags&(Lshortfile|Llongfile) != 0 { + if b.Colorize { + *buf = append(*buf, fgGreenBytes...) + } + file := event.filename + if b.Flags&Lmedfile == Lmedfile { + startIndex := len(file) - 20 + if startIndex > 0 { + file = "..." + file[startIndex:] + } + } else if b.Flags&Lshortfile != 0 { + startIndex := strings.LastIndexByte(file, '/') + if startIndex > 0 && startIndex < len(file) { + file = file[startIndex+1:] + } + } + *buf = append(*buf, file...) + *buf = append(*buf, ':') + itoa(buf, event.line, -1) + if b.Flags&(Lfuncname|Lshortfuncname) != 0 { + *buf = append(*buf, ':') + } else { + if b.Colorize { + *buf = append(*buf, resetBytes...) + } + *buf = append(*buf, ' ') + } + } + if b.Flags&(Lfuncname|Lshortfuncname) != 0 { + if b.Colorize { + *buf = append(*buf, fgGreenBytes...) + } + funcname := event.caller + if b.Flags&Lshortfuncname != 0 { + lastIndex := strings.LastIndexByte(funcname, '.') + if lastIndex > 0 && len(funcname) > lastIndex+1 { + funcname = funcname[lastIndex+1:] + } + } + *buf = append(*buf, funcname...) + if b.Colorize { + *buf = append(*buf, resetBytes...) + } + *buf = append(*buf, ' ') + + } + if b.Flags&(Llevel|Llevelinitial) != 0 { + level := strings.ToUpper(event.level.String()) + if b.Colorize { + *buf = append(*buf, levelToColor[event.level]...) + } + *buf = append(*buf, '[') + if b.Flags&Llevelinitial != 0 { + *buf = append(*buf, level[0]) + } else { + *buf = append(*buf, level...) + } + *buf = append(*buf, ']') + if b.Colorize { + *buf = append(*buf, resetBytes...) + } + *buf = append(*buf, ' ') + } + + var msg = []byte(event.msg) + if len(msg) > 0 && msg[len(msg)-1] == '\n' { + msg = msg[:len(msg)-1] + } + + pawMode := allowColor + if !b.Colorize { + pawMode = removeColor + } + + baw := byteArrayWriter(*buf) + (&protectedANSIWriter{ + w: &baw, + mode: pawMode, + }).Write([]byte(msg)) + *buf = baw + + if event.stacktrace != "" && b.StacktraceLevel <= event.level { + lines := bytes.Split([]byte(event.stacktrace), []byte("\n")) + if len(lines) > 1 { + for _, line := range lines { + *buf = append(*buf, "\n\t"...) + *buf = append(*buf, line...) + } + } + *buf = append(*buf, '\n') + } + *buf = append(*buf, '\n') +} + +// LogEvent logs the event to the internal writer +func (b *BaseLogger) LogEvent(event *Event) error { + if b.Level > event.level { + return nil + } + + b.mu.Lock() + defer b.mu.Unlock() + if !b.Match(event) { + return nil + } + var buf []byte + b.createMsg(&buf, event) + _, err := b.out.Write(buf) + return err +} + +// Match checks if the given event matches the logger's regexp expression +func (b *BaseLogger) Match(event *Event) bool { + if b.regexp == nil { + return true + } + if b.regexp.Match([]byte(fmt.Sprintf("%s:%d:%s", event.filename, event.line, event.caller))) { + return true + } + // Match on the non-colored msg - therefore strip out colors + var msg []byte + baw := byteArrayWriter(msg) + (&protectedANSIWriter{ + w: &baw, + mode: removeColor, + }).Write([]byte(event.msg)) + msg = baw + if b.regexp.Match(msg) { + return true + } + return false +} + +// Close the base logger +func (b *BaseLogger) Close() { + b.mu.Lock() + defer b.mu.Unlock() + if b.out != nil { + b.out.Close() + } +} + +// GetName returns empty for these provider loggers +func (b *BaseLogger) GetName() string { + return "" +} diff --git a/base_test.go b/base_test.go new file mode 100644 index 0000000..3686c26 --- /dev/null +++ b/base_test.go @@ -0,0 +1,277 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "strings" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +type CallbackWriteCloser struct { + callback func([]byte, bool) +} + +func (c CallbackWriteCloser) Write(p []byte) (int, error) { + c.callback(p, false) + return len(p), nil +} + +func (c CallbackWriteCloser) Close() error { + c.callback(nil, true) + return nil +} + +func TestBaseLogger(t *testing.T) { + var written []byte + var closed bool + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + written = p + closed = close + }, + } + prefix := "TestPrefix " + b := BaseLogger{ + out: c, + Level: INFO, + Flags: LstdFlags | LUTC, + Prefix: prefix, + } + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + assert.Equal(t, INFO, b.GetLevel()) + + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = DEBUG + expected = "" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + + event.level = TRACE + expected = "" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + + event.level = WARN + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = ERROR + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = CRITICAL + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + b.Close() + assert.Equal(t, true, closed) +} + +func TestBaseLoggerDated(t *testing.T) { + var written []byte + var closed bool + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + written = p + closed = close + }, + } + prefix := "" + b := BaseLogger{ + out: c, + Level: WARN, + Flags: Ldate | Ltime | Lmicroseconds | Lshortfile | Llevel, + Prefix: prefix, + } + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 115, location) + + dateString := date.Format("2006/01/02 15:04:05.000000") + + event := Event{ + level: WARN, + msg: "TEST MESSAGE TEST\n", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + assert.Equal(t, WARN, b.GetLevel()) + + expected := fmt.Sprintf("%s%s %s:%d [%s] %s", prefix, dateString, "FILENAME", event.line, strings.ToUpper(event.level.String()), event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = INFO + expected = "" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = ERROR + expected = fmt.Sprintf("%s%s %s:%d [%s] %s", prefix, dateString, "FILENAME", event.line, strings.ToUpper(event.level.String()), event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = DEBUG + expected = "" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = CRITICAL + expected = fmt.Sprintf("%s%s %s:%d [%s] %s", prefix, dateString, "FILENAME", event.line, strings.ToUpper(event.level.String()), event.msg) + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = TRACE + expected = "" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + b.Close() + assert.Equal(t, true, closed) +} + +func TestBaseLoggerMultiLineNoFlagsRegexp(t *testing.T) { + var written []byte + var closed bool + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + written = p + closed = close + }, + } + prefix := "" + b := BaseLogger{ + Level: DEBUG, + StacktraceLevel: ERROR, + Flags: -1, + Prefix: prefix, + Expression: "FILENAME", + } + b.createLogger(c) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 115, location) + + event := Event{ + level: DEBUG, + msg: "TEST\nMESSAGE\nTEST", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + assert.Equal(t, DEBUG, b.GetLevel()) + + expected := "TEST\n\tMESSAGE\n\tTEST\n" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.filename = "ELSEWHERE" + + b.LogEvent(&event) + assert.Equal(t, "", string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.caller = "FILENAME" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event = Event{ + level: DEBUG, + msg: "TEST\nFILENAME\nTEST", + caller: "CALLER", + filename: "FULL/ELSEWHERE", + line: 1, + time: date, + } + expected = "TEST\n\tFILENAME\n\tTEST\n" + b.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + +} + +func TestBrokenRegexp(t *testing.T) { + var closed bool + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + closed = close + }, + } + + b := BaseLogger{ + Level: DEBUG, + StacktraceLevel: ERROR, + Flags: -1, + Prefix: prefix, + Expression: "\\", + } + b.createLogger(c) + assert.Empty(t, b.regexp) + b.Close() + assert.Equal(t, true, closed) +} diff --git a/colors.go b/colors.go new file mode 100644 index 0000000..fa8a664 --- /dev/null +++ b/colors.go @@ -0,0 +1,348 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "io" + "strconv" + "strings" +) + +const escape = "\033" + +// ColorAttribute defines a single SGR Code +type ColorAttribute int + +// Base ColorAttributes +const ( + Reset ColorAttribute = iota + Bold + Faint + Italic + Underline + BlinkSlow + BlinkRapid + ReverseVideo + Concealed + CrossedOut +) + +// Foreground text colors +const ( + FgBlack ColorAttribute = iota + 30 + FgRed + FgGreen + FgYellow + FgBlue + FgMagenta + FgCyan + FgWhite +) + +// Foreground Hi-Intensity text colors +const ( + FgHiBlack ColorAttribute = iota + 90 + FgHiRed + FgHiGreen + FgHiYellow + FgHiBlue + FgHiMagenta + FgHiCyan + FgHiWhite +) + +// Background text colors +const ( + BgBlack ColorAttribute = iota + 40 + BgRed + BgGreen + BgYellow + BgBlue + BgMagenta + BgCyan + BgWhite +) + +// Background Hi-Intensity text colors +const ( + BgHiBlack ColorAttribute = iota + 100 + BgHiRed + BgHiGreen + BgHiYellow + BgHiBlue + BgHiMagenta + BgHiCyan + BgHiWhite +) + +var colorAttributeToString = map[ColorAttribute]string{ + Reset: "Reset", + Bold: "Bold", + Faint: "Faint", + Italic: "Italic", + Underline: "Underline", + BlinkSlow: "BlinkSlow", + BlinkRapid: "BlinkRapid", + ReverseVideo: "ReverseVideo", + Concealed: "Concealed", + CrossedOut: "CrossedOut", + FgBlack: "FgBlack", + FgRed: "FgRed", + FgGreen: "FgGreen", + FgYellow: "FgYellow", + FgBlue: "FgBlue", + FgMagenta: "FgMagenta", + FgCyan: "FgCyan", + FgWhite: "FgWhite", + FgHiBlack: "FgHiBlack", + FgHiRed: "FgHiRed", + FgHiGreen: "FgHiGreen", + FgHiYellow: "FgHiYellow", + FgHiBlue: "FgHiBlue", + FgHiMagenta: "FgHiMagenta", + FgHiCyan: "FgHiCyan", + FgHiWhite: "FgHiWhite", + BgBlack: "BgBlack", + BgRed: "BgRed", + BgGreen: "BgGreen", + BgYellow: "BgYellow", + BgBlue: "BgBlue", + BgMagenta: "BgMagenta", + BgCyan: "BgCyan", + BgWhite: "BgWhite", + BgHiBlack: "BgHiBlack", + BgHiRed: "BgHiRed", + BgHiGreen: "BgHiGreen", + BgHiYellow: "BgHiYellow", + BgHiBlue: "BgHiBlue", + BgHiMagenta: "BgHiMagenta", + BgHiCyan: "BgHiCyan", + BgHiWhite: "BgHiWhite", +} + +func (c *ColorAttribute) String() string { + return colorAttributeToString[*c] +} + +var colorAttributeFromString = map[string]ColorAttribute{} + +// ColorAttributeFromString will return a ColorAttribute given a string +func ColorAttributeFromString(from string) ColorAttribute { + lowerFrom := strings.TrimSpace(strings.ToLower(from)) + return colorAttributeFromString[lowerFrom] +} + +// ColorString converts a list of ColorAttributes to a color string +func ColorString(attrs ...ColorAttribute) string { + return string(ColorBytes(attrs...)) +} + +// ColorBytes converts a list of ColorAttributes to a byte array +func ColorBytes(attrs ...ColorAttribute) []byte { + bytes := make([]byte, 0, 20) + bytes = append(bytes, escape[0], '[') + if len(attrs) > 0 { + bytes = append(bytes, strconv.Itoa(int(attrs[0]))...) + for _, a := range attrs[1:] { + bytes = append(bytes, ';') + bytes = append(bytes, strconv.Itoa(int(a))...) + } + } else { + bytes = append(bytes, strconv.Itoa(int(Bold))...) + } + bytes = append(bytes, 'm') + return bytes +} + +var levelToColor = map[Level]string{ + TRACE: ColorString(Bold, FgCyan), + DEBUG: ColorString(Bold, FgBlue), + INFO: ColorString(Bold, FgGreen), + WARN: ColorString(Bold, FgYellow), + ERROR: ColorString(Bold, FgRed), + CRITICAL: ColorString(Bold, BgMagenta), + FATAL: ColorString(Bold, BgRed), + NONE: ColorString(Reset), +} + +var resetBytes = ColorBytes(Reset) +var fgCyanBytes = ColorBytes(FgCyan) +var fgGreenBytes = ColorBytes(FgGreen) +var fgBoldBytes = ColorBytes(Bold) + +type protectedANSIWriterMode int + +const ( + escapeAll protectedANSIWriterMode = iota + allowColor + removeColor +) + +type protectedANSIWriter struct { + w io.Writer + mode protectedANSIWriterMode +} + +// Write will protect against unusual characters +func (c *protectedANSIWriter) Write(bytes []byte) (int, error) { + end := len(bytes) + totalWritten := 0 +normalLoop: + for i := 0; i < end; { + lasti := i + + if c.mode == escapeAll { + for i < end && (bytes[i] >= ' ' || bytes[i] == '\n') { + i++ + } + } else { + for i < end && bytes[i] >= ' ' { + i++ + } + } + + if i > lasti { + written, err := c.w.Write(bytes[lasti:i]) + totalWritten = totalWritten + written + if err != nil { + return totalWritten, err + } + + } + if i >= end { + break + } + + // If we're not just escaping all we should prefix all newlines with a \t + if c.mode != escapeAll { + if bytes[i] == '\n' { + written, err := c.w.Write([]byte{'\n', '\t'}) + if written > 0 { + totalWritten++ + } + if err != nil { + return totalWritten, err + } + i++ + continue normalLoop + } + + if bytes[i] == escape[0] && i+1 < end && bytes[i+1] == '[' { + for j := i + 2; j < end; j++ { + if bytes[j] >= '0' && bytes[j] <= '9' { + continue + } + if bytes[j] == ';' { + continue + } + if bytes[j] == 'm' { + if c.mode == allowColor { + written, err := c.w.Write(bytes[i : j+1]) + totalWritten = totalWritten + written + if err != nil { + return totalWritten, err + } + } else { + totalWritten = j + } + i = j + 1 + continue normalLoop + } + break + } + } + } + + // Process naughty character + if _, err := fmt.Fprintf(c.w, `\%#o03d`, bytes[i]); err != nil { + return totalWritten, err + } + i++ + totalWritten++ + } + return totalWritten, nil +} + +// ColoredValue will Color the provided value +type ColoredValue struct { + ColorBytes *[]byte + ResetBytes *[]byte + Value *interface{} +} + +// NewColoredValue is a helper function to create a ColoredValue from a Value +// If no color is provided it defaults to Bold with standard Reset +// If a ColoredValue is provided it is not changed +func NewColoredValue(value interface{}, color ...ColorAttribute) *ColoredValue { + return NewColoredValuePointer(&value, color...) +} + +// NewColoredValuePointer is a helper function to create a ColoredValue from a Value Pointer +// If no color is provided it defaults to Bold with standard Reset +// If a ColoredValue is provided it is not changed +func NewColoredValuePointer(value *interface{}, color ...ColorAttribute) *ColoredValue { + if val, ok := (*value).(*ColoredValue); ok { + return val + } + if len(color) > 0 { + bytes := ColorBytes(color...) + return &ColoredValue{ + ColorBytes: &bytes, + ResetBytes: &resetBytes, + Value: value, + } + } + return &ColoredValue{ + ColorBytes: &fgBoldBytes, + ResetBytes: &resetBytes, + Value: value, + } + +} + +// NewColoredValueBytes creates a value from the provided value with color bytes +// If a ColoredValue is provided it is not changed +func NewColoredValueBytes(value interface{}, colorBytes *[]byte) *ColoredValue { + if val, ok := value.(*ColoredValue); ok { + return val + } + return &ColoredValue{ + ColorBytes: colorBytes, + ResetBytes: &resetBytes, + Value: &value, + } +} + +// Format will format the provided value and protect against ANSI spoofing within the value +func (cv *ColoredValue) Format(s fmt.State, c rune) { + s.Write([]byte(*cv.ColorBytes)) + fmt.Fprintf(&protectedANSIWriter{w: s}, fmtString(s, c), *(cv.Value)) + s.Write([]byte(*cv.ResetBytes)) +} + +func fmtString(s fmt.State, c rune) string { + var width, precision string + base := make([]byte, 0, 8) + base = append(base, '%') + for _, c := range []byte(" +-#0") { + if s.Flag(int(c)) { + base = append(base, c) + } + } + if w, ok := s.Width(); ok { + width = strconv.Itoa(w) + } + if p, ok := s.Precision(); ok { + precision = "." + strconv.Itoa(p) + } + return fmt.Sprintf("%s%s%s%c", base, width, precision, c) +} + +func init() { + for attr, from := range colorAttributeToString { + colorAttributeFromString[strings.ToLower(from)] = attr + } +} diff --git a/conn.go b/conn.go new file mode 100644 index 0000000..d48bb4b --- /dev/null +++ b/conn.go @@ -0,0 +1,121 @@ +// Copyright 2014 The Gogs Authors. All rights reserved. +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "encoding/json" + "io" + "net" +) + +type connWriter struct { + innerWriter io.WriteCloser + ReconnectOnMsg bool `json:"reconnectOnMsg"` + Reconnect bool `json:"reconnect"` + Net string `json:"net"` + Addr string `json:"addr"` +} + +// Close the inner writer +func (i *connWriter) Close() error { + if i.innerWriter != nil { + return i.innerWriter.Close() + } + return nil +} + +// Write the data to the connection +func (i *connWriter) Write(p []byte) (int, error) { + if i.neededConnectOnMsg() { + if err := i.connect(); err != nil { + return 0, err + } + } + + if i.ReconnectOnMsg { + defer i.innerWriter.Close() + } + + return i.innerWriter.Write(p) +} + +func (i *connWriter) neededConnectOnMsg() bool { + if i.Reconnect { + i.Reconnect = false + return true + } + + if i.innerWriter == nil { + return true + } + + return i.ReconnectOnMsg +} + +func (i *connWriter) connect() error { + if i.innerWriter != nil { + i.innerWriter.Close() + i.innerWriter = nil + } + + conn, err := net.Dial(i.Net, i.Addr) + if err != nil { + return err + } + + if tcpConn, ok := conn.(*net.TCPConn); ok { + tcpConn.SetKeepAlive(true) + } + + i.innerWriter = conn + return nil +} + +// ConnLogger implements LoggerProvider. +// it writes messages in keep-live tcp connection. +type ConnLogger struct { + BaseLogger + ReconnectOnMsg bool `json:"reconnectOnMsg"` + Reconnect bool `json:"reconnect"` + Net string `json:"net"` + Addr string `json:"addr"` +} + +// NewConn creates new ConnLogger returning as LoggerProvider. +func NewConn() LoggerProvider { + conn := new(ConnLogger) + conn.Level = TRACE + return conn +} + +// Init inits connection writer with json config. +// json config only need key "level". +func (log *ConnLogger) Init(jsonconfig string) error { + err := json.Unmarshal([]byte(jsonconfig), log) + if err != nil { + return err + } + log.createLogger(&connWriter{ + ReconnectOnMsg: log.ReconnectOnMsg, + Reconnect: log.Reconnect, + Net: log.Net, + Addr: log.Addr, + }, log.Level) + return nil +} + +// Flush does nothing for this implementation +func (log *ConnLogger) Flush() { +} + +// GetName returns the default name for this implementation +func (log *ConnLogger) GetName() string { + return "conn" +} + +func init() { + Register("conn", NewConn) +} diff --git a/conn_test.go b/conn_test.go new file mode 100644 index 0000000..380a115 --- /dev/null +++ b/conn_test.go @@ -0,0 +1,240 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "io/ioutil" + "net" + "strings" + "sync" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func listenReadAndClose(t *testing.T, l net.Listener, expected string) { + conn, err := l.Accept() + assert.NoError(t, err) + defer conn.Close() + written, err := ioutil.ReadAll(conn) + + assert.NoError(t, err) + assert.Equal(t, expected, string(written)) + return +} + +func TestConnLogger(t *testing.T) { + var written []byte + + protocol := "tcp" + address := ":3099" + + l, err := net.Listen(protocol, address) + if err != nil { + t.Fatal(err) + } + defer l.Close() + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + + logger := NewConn() + connLogger := logger.(*ConnLogger) + + logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, true, true, protocol, address)) + + assert.Equal(t, flags, connLogger.Flags) + assert.Equal(t, level, connLogger.Level) + assert.Equal(t, level, logger.GetLevel()) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + var wg sync.WaitGroup + wg.Add(2) + go func() { + defer wg.Done() + listenReadAndClose(t, l, expected) + }() + go func() { + defer wg.Done() + err := logger.LogEvent(&event) + assert.NoError(t, err) + }() + wg.Wait() + + written = written[:0] + + event.level = WARN + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + wg.Add(2) + go func() { + defer wg.Done() + listenReadAndClose(t, l, expected) + }() + go func() { + defer wg.Done() + err := logger.LogEvent(&event) + assert.NoError(t, err) + }() + wg.Wait() + + logger.Close() +} + +func TestConnLoggerBadConfig(t *testing.T) { + logger := NewConn() + + err := logger.Init("{") + assert.Equal(t, "unexpected end of JSON input", err.Error()) + logger.Close() +} + +func TestConnLoggerCloseBeforeSend(t *testing.T) { + protocol := "tcp" + address := ":3099" + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + + logger := NewConn() + + logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, false, protocol, address)) + logger.Close() +} + +func TestConnLoggerFailConnect(t *testing.T) { + protocol := "tcp" + address := ":3099" + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + + logger := NewConn() + + logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, false, protocol, address)) + + assert.Equal(t, level, logger.GetLevel()) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + //dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + err := logger.LogEvent(&event) + assert.Error(t, err) + + logger.Close() +} + +func TestConnLoggerClose(t *testing.T) { + var written []byte + + protocol := "tcp" + address := ":3099" + + l, err := net.Listen(protocol, address) + if err != nil { + t.Fatal(err) + } + defer l.Close() + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + + logger := NewConn() + connLogger := logger.(*ConnLogger) + + logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, false, protocol, address)) + + assert.Equal(t, flags, connLogger.Flags) + assert.Equal(t, level, connLogger.Level) + assert.Equal(t, level, logger.GetLevel()) + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + var wg sync.WaitGroup + wg.Add(2) + go func() { + defer wg.Done() + err := logger.LogEvent(&event) + assert.NoError(t, err) + logger.Close() + }() + go func() { + defer wg.Done() + listenReadAndClose(t, l, expected) + }() + wg.Wait() + + logger = NewConn() + connLogger = logger.(*ConnLogger) + + logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"reconnectOnMsg\":%t,\"reconnect\":%t,\"net\":\"%s\",\"addr\":\"%s\"}", prefix, level.String(), flags, false, true, protocol, address)) + + assert.Equal(t, flags, connLogger.Flags) + assert.Equal(t, level, connLogger.Level) + assert.Equal(t, level, logger.GetLevel()) + + written = written[:0] + + event.level = WARN + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + wg.Add(2) + go func() { + defer wg.Done() + listenReadAndClose(t, l, expected) + }() + go func() { + defer wg.Done() + err := logger.LogEvent(&event) + assert.NoError(t, err) + logger.Close() + + }() + wg.Wait() + logger.Flush() + logger.Close() +} diff --git a/console.go b/console.go new file mode 100644 index 0000000..cf2dfa4 --- /dev/null +++ b/console.go @@ -0,0 +1,78 @@ +// Copyright 2014 The Gogs Authors. All rights reserved. +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "encoding/json" + "io" + "os" +) + +// CanColorStdout reports if we can color the Stdout +// Although we could do terminal sniffing and the like - in reality +// most tools on *nix are happy to display ansi colors. +// We will terminal sniff on Windows in console_windows.go +var CanColorStdout = true + +// CanColorStderr reports if we can color the Stderr +var CanColorStderr = true + +type nopWriteCloser struct { + w io.WriteCloser +} + +func (n *nopWriteCloser) Write(p []byte) (int, error) { + return n.w.Write(p) +} + +func (n *nopWriteCloser) Close() error { + return nil +} + +// ConsoleLogger implements LoggerProvider and writes messages to terminal. +type ConsoleLogger struct { + BaseLogger + Stderr bool `json:"stderr"` +} + +// NewConsoleLogger create ConsoleLogger returning as LoggerProvider. +func NewConsoleLogger() LoggerProvider { + log := &ConsoleLogger{} + log.createLogger(&nopWriteCloser{ + w: os.Stdout, + }) + return log +} + +// Init inits connection writer with json config. +// json config only need key "level". +func (log *ConsoleLogger) Init(config string) error { + err := json.Unmarshal([]byte(config), log) + if err != nil { + return err + } + if log.Stderr { + log.createLogger(&nopWriteCloser{ + w: os.Stderr, + }) + } else { + log.createLogger(log.out) + } + return nil +} + +// Flush when log should be flushed +func (log *ConsoleLogger) Flush() { +} + +// GetName returns the default name for this implementation +func (log *ConsoleLogger) GetName() string { + return "console" +} + +func init() { + Register("console", NewConsoleLogger) +} diff --git a/console_test.go b/console_test.go new file mode 100644 index 0000000..a028b5b --- /dev/null +++ b/console_test.go @@ -0,0 +1,137 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "strings" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestConsoleLoggerBadConfig(t *testing.T) { + logger := NewConsoleLogger() + + err := logger.Init("{") + assert.Equal(t, "unexpected end of JSON input", err.Error()) + logger.Close() +} + +func TestConsoleLoggerMinimalConfig(t *testing.T) { + for _, level := range Levels() { + var written []byte + var closed bool + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + written = p + closed = close + }, + } + prefix := "" + flags := LstdFlags + + cw := NewConsoleLogger() + realCW := cw.(*ConsoleLogger) + cw.Init(fmt.Sprintf("{\"level\":\"%s\"}", level)) + nwc := realCW.out.(*nopWriteCloser) + nwc.w = c + + assert.Equal(t, flags, realCW.Flags) + assert.Equal(t, FromString(level), realCW.Level) + assert.Equal(t, FromString(level), cw.GetLevel()) + assert.Equal(t, prefix, realCW.Prefix) + assert.Equal(t, "", string(written)) + cw.Close() + assert.Equal(t, false, closed) + + } +} + +func TestConsoleLogger(t *testing.T) { + var written []byte + var closed bool + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + written = p + closed = close + }, + } + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + + cw := NewConsoleLogger() + realCW := cw.(*ConsoleLogger) + realCW.Colorize = false + nwc := realCW.out.(*nopWriteCloser) + nwc.w = c + + cw.Init(fmt.Sprintf("{\"expression\":\"FILENAME\",\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d}", prefix, level.String(), flags)) + + assert.Equal(t, flags, realCW.Flags) + assert.Equal(t, level, realCW.Level) + assert.Equal(t, level, cw.GetLevel()) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + cw.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + event.level = DEBUG + expected = "" + cw.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + + event.level = TRACE + expected = "" + cw.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + + nonMatchEvent := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FI_LENAME", + line: 1, + time: date, + } + event.level = INFO + expected = "" + cw.LogEvent(&nonMatchEvent) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + + event.level = WARN + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + cw.LogEvent(&event) + assert.Equal(t, expected, string(written)) + assert.Equal(t, false, closed) + written = written[:0] + + cw.Close() + assert.Equal(t, false, closed) +} diff --git a/console_windows.go b/console_windows.go new file mode 100644 index 0000000..61469aa --- /dev/null +++ b/console_windows.go @@ -0,0 +1,43 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "os" + + "github.com/mattn/go-isatty" + "golang.org/x/sys/windows" +) + +func enableVTMode(console windows.Handle) bool { + mode := uint32(0) + err := windows.GetConsoleMode(console, &mode) + if err != nil { + return false + } + + // EnableVirtualTerminalProcessing is the console mode to allow ANSI code + // interpretation on the console. See: + // https://docs.microsoft.com/en-us/windows/console/setconsolemode + // It only works on windows 10. Earlier terminals will fail with an err which we will + // handle to say don't color + mode = mode | windows.ENABLE_VIRTUAL_TERMINAL_PROCESSING + err = windows.SetConsoleMode(console, mode) + return err == nil +} + +func init() { + if isatty.IsTerminal(os.Stdout.Fd()) { + CanColorStdout = enableVTMode(windows.Stdout) + } else { + CanColorStdout = isatty.IsCygwinTerminal(os.Stderr.Fd()) + } + + if isatty.IsTerminal(os.Stderr.Fd()) { + CanColorStderr = enableVTMode(windows.Stderr) + } else { + CanColorStderr = isatty.IsCygwinTerminal(os.Stderr.Fd()) + } +} diff --git a/errors.go b/errors.go new file mode 100644 index 0000000..1fe54d4 --- /dev/null +++ b/errors.go @@ -0,0 +1,62 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import "fmt" + +// ErrTimeout represents a "Timeout" kind of error. +type ErrTimeout struct { + Name string + Provider string +} + +// IsErrTimeout checks if an error is a ErrTimeout. +func IsErrTimeout(err error) bool { + if err == nil { + return false + } + _, ok := err.(ErrTimeout) + return ok +} + +func (err ErrTimeout) Error() string { + return fmt.Sprintf("Log Timeout for %s (%s)", err.Name, err.Provider) +} + +// ErrUnknownProvider represents a "Unknown Provider" kind of error. +type ErrUnknownProvider struct { + Provider string +} + +// IsErrUnknownProvider checks if an error is a ErrUnknownProvider. +func IsErrUnknownProvider(err error) bool { + if err == nil { + return false + } + _, ok := err.(ErrUnknownProvider) + return ok +} + +func (err ErrUnknownProvider) Error() string { + return fmt.Sprintf("Unknown Log Provider \"%s\" (Was it registered?)", err.Provider) +} + +// ErrDuplicateName represents a Duplicate Name error +type ErrDuplicateName struct { + Name string +} + +// IsErrDuplicateName checks if an error is a ErrDuplicateName. +func IsErrDuplicateName(err error) bool { + if err == nil { + return false + } + _, ok := err.(ErrDuplicateName) + return ok +} + +func (err ErrDuplicateName) Error() string { + return fmt.Sprintf("Duplicate named logger: %s", err.Name) +} diff --git a/event.go b/event.go new file mode 100644 index 0000000..2ec1f95 --- /dev/null +++ b/event.go @@ -0,0 +1,335 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "sync" + "time" +) + +// Event represents a logging event +type Event struct { + level Level + msg string + caller string + filename string + line int + time time.Time + stacktrace string +} + +// EventLogger represents the behaviours of a logger +type EventLogger interface { + LogEvent(event *Event) error + Close() + Flush() + GetLevel() Level + GetStacktraceLevel() Level + GetName() string +} + +// ChannelledLog represents a cached channel to a LoggerProvider +type ChannelledLog struct { + name string + provider string + queue chan *Event + loggerProvider LoggerProvider + flush chan bool + close chan bool + closed chan bool +} + +// NewChannelledLog a new logger instance with given logger provider and config. +func NewChannelledLog(name, provider, config string, bufferLength int64) (*ChannelledLog, error) { + if log, ok := providers[provider]; ok { + l := &ChannelledLog{ + queue: make(chan *Event, bufferLength), + flush: make(chan bool), + close: make(chan bool), + closed: make(chan bool), + } + l.loggerProvider = log() + if err := l.loggerProvider.Init(config); err != nil { + return nil, err + } + l.name = name + l.provider = provider + go l.Start() + return l, nil + } + return nil, ErrUnknownProvider{provider} +} + +// Start processing the ChannelledLog +func (l *ChannelledLog) Start() { + for { + select { + case event, ok := <-l.queue: + if !ok { + l.closeLogger() + return + } + l.loggerProvider.LogEvent(event) + case _, ok := <-l.flush: + if !ok { + l.closeLogger() + return + } + l.loggerProvider.Flush() + case _, _ = <-l.close: + l.closeLogger() + return + } + } +} + +// LogEvent logs an event to this ChannelledLog +func (l *ChannelledLog) LogEvent(event *Event) error { + select { + case l.queue <- event: + return nil + case <-time.After(60 * time.Second): + // We're blocked! + return ErrTimeout{ + Name: l.name, + Provider: l.provider, + } + } +} + +func (l *ChannelledLog) closeLogger() { + l.loggerProvider.Flush() + l.loggerProvider.Close() + l.closed <- true + return +} + +// Close this ChannelledLog +func (l *ChannelledLog) Close() { + l.close <- true + <-l.closed +} + +// Flush this ChannelledLog +func (l *ChannelledLog) Flush() { + l.flush <- true +} + +// GetLevel gets the level of this ChannelledLog +func (l *ChannelledLog) GetLevel() Level { + return l.loggerProvider.GetLevel() +} + +// GetStacktraceLevel gets the level of this ChannelledLog +func (l *ChannelledLog) GetStacktraceLevel() Level { + return l.loggerProvider.GetStacktraceLevel() +} + +// GetName returns the name of this ChannelledLog +func (l *ChannelledLog) GetName() string { + return l.name +} + +// MultiChannelledLog represents a cached channel to a LoggerProvider +type MultiChannelledLog struct { + name string + bufferLength int64 + queue chan *Event + mutex sync.Mutex + loggers map[string]EventLogger + flush chan bool + close chan bool + started bool + level Level + stacktraceLevel Level + closed chan bool +} + +// NewMultiChannelledLog a new logger instance with given logger provider and config. +func NewMultiChannelledLog(name string, bufferLength int64) *MultiChannelledLog { + m := &MultiChannelledLog{ + name: name, + queue: make(chan *Event, bufferLength), + flush: make(chan bool), + bufferLength: bufferLength, + loggers: make(map[string]EventLogger), + level: NONE, + stacktraceLevel: NONE, + close: make(chan bool), + closed: make(chan bool), + } + return m +} + +// AddLogger adds a logger to this MultiChannelledLog +func (m *MultiChannelledLog) AddLogger(logger EventLogger) error { + m.mutex.Lock() + name := logger.GetName() + if _, has := m.loggers[name]; has { + m.mutex.Unlock() + return ErrDuplicateName{name} + } + m.loggers[name] = logger + if logger.GetLevel() < m.level { + m.level = logger.GetLevel() + } + if logger.GetStacktraceLevel() < m.stacktraceLevel { + m.stacktraceLevel = logger.GetStacktraceLevel() + } + m.mutex.Unlock() + go m.Start() + return nil +} + +// DelLogger removes a sub logger from this MultiChannelledLog +// NB: If you delete the last sublogger this logger will simply drop +// log events +func (m *MultiChannelledLog) DelLogger(name string) bool { + m.mutex.Lock() + logger, has := m.loggers[name] + if !has { + m.mutex.Unlock() + return false + } + delete(m.loggers, name) + m.internalResetLevel() + m.mutex.Unlock() + logger.Flush() + logger.Close() + return true +} + +// GetEventLogger returns a sub logger from this MultiChannelledLog +func (m *MultiChannelledLog) GetEventLogger(name string) EventLogger { + m.mutex.Lock() + defer m.mutex.Unlock() + return m.loggers[name] +} + +// GetEventLoggerNames returns a list of names +func (m *MultiChannelledLog) GetEventLoggerNames() []string { + m.mutex.Lock() + defer m.mutex.Unlock() + var keys []string + for k := range m.loggers { + keys = append(keys, k) + } + return keys +} + +func (m *MultiChannelledLog) closeLoggers() { + m.mutex.Lock() + for _, logger := range m.loggers { + logger.Flush() + logger.Close() + } + m.mutex.Unlock() + m.closed <- true + return +} + +// Start processing the MultiChannelledLog +func (m *MultiChannelledLog) Start() { + m.mutex.Lock() + if m.started { + m.mutex.Unlock() + return + } + m.started = true + m.mutex.Unlock() + for { + select { + case event, ok := <-m.queue: + if !ok { + m.closeLoggers() + return + } + m.mutex.Lock() + for _, logger := range m.loggers { + err := logger.LogEvent(event) + if err != nil { + fmt.Println(err) + } + } + m.mutex.Unlock() + case _, ok := <-m.flush: + if !ok { + m.closeLoggers() + return + } + m.mutex.Lock() + for _, logger := range m.loggers { + logger.Flush() + } + m.mutex.Unlock() + case <-m.close: + m.closeLoggers() + return + } + } +} + +// LogEvent logs an event to this MultiChannelledLog +func (m *MultiChannelledLog) LogEvent(event *Event) error { + select { + case m.queue <- event: + return nil + case <-time.After(60 * time.Second): + // We're blocked! + return ErrTimeout{ + Name: m.name, + Provider: "MultiChannelledLog", + } + } +} + +// Close this MultiChannelledLog +func (m *MultiChannelledLog) Close() { + m.close <- true + <-m.closed +} + +// Flush this ChannelledLog +func (m *MultiChannelledLog) Flush() { + m.flush <- true +} + +// GetLevel gets the level of this MultiChannelledLog +func (m *MultiChannelledLog) GetLevel() Level { + return m.level +} + +// GetStacktraceLevel gets the level of this MultiChannelledLog +func (m *MultiChannelledLog) GetStacktraceLevel() Level { + return m.stacktraceLevel +} + +func (m *MultiChannelledLog) internalResetLevel() Level { + m.level = NONE + for _, logger := range m.loggers { + level := logger.GetLevel() + if level < m.level { + m.level = level + } + level = logger.GetStacktraceLevel() + if level < m.stacktraceLevel { + m.stacktraceLevel = level + } + } + return m.level +} + +// ResetLevel will reset the level of this MultiChannelledLog +func (m *MultiChannelledLog) ResetLevel() Level { + m.mutex.Lock() + defer m.mutex.Unlock() + return m.internalResetLevel() +} + +// GetName gets the name of this MultiChannelledLog +func (m *MultiChannelledLog) GetName() string { + return m.name +} diff --git a/file.go b/file.go new file mode 100644 index 0000000..5c219c3 --- /dev/null +++ b/file.go @@ -0,0 +1,259 @@ +// Copyright 2014 The Gogs Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "bufio" + "compress/gzip" + "encoding/json" + "errors" + "fmt" + "os" + "path/filepath" + "strings" + "sync" + "time" +) + +// FileLogger implements LoggerProvider. +// It writes messages by lines limit, file size limit, or time frequency. +type FileLogger struct { + BaseLogger + mw *MuxWriter + // The opened file + Filename string `json:"filename"` + + // Rotate at size + Maxsize int `json:"maxsize"` + maxsizeCursize int + + // Rotate daily + Daily bool `json:"daily"` + Maxdays int64 `json:"maxdays"` + dailyOpenDate int + + Rotate bool `json:"rotate"` + + Compress bool `json:"compress"` + CompressionLevel int `json:"compressionLevel"` + + startLock sync.Mutex // Only one log can write to the file +} + +// MuxWriter an *os.File writer with locker. +type MuxWriter struct { + mu sync.Mutex + fd *os.File + owner *FileLogger +} + +// Write writes to os.File. +func (mw *MuxWriter) Write(b []byte) (int, error) { + mw.mu.Lock() + defer mw.mu.Unlock() + mw.owner.docheck(len(b)) + return mw.fd.Write(b) +} + +// Close the internal writer +func (mw *MuxWriter) Close() error { + return mw.fd.Close() +} + +// SetFd sets os.File in writer. +func (mw *MuxWriter) SetFd(fd *os.File) { + if mw.fd != nil { + mw.fd.Close() + } + mw.fd = fd +} + +// NewFileLogger create a FileLogger returning as LoggerProvider. +func NewFileLogger() LoggerProvider { + log := &FileLogger{ + Filename: "", + Maxsize: 1 << 28, //256 MB + Daily: true, + Maxdays: 7, + Rotate: true, + Compress: true, + CompressionLevel: gzip.DefaultCompression, + } + log.Level = TRACE + // use MuxWriter instead direct use os.File for lock write when rotate + log.mw = new(MuxWriter) + log.mw.owner = log + + return log +} + +// Init file logger with json config. +// config like: +// { +// "filename":"log/gogs.log", +// "maxsize":1<<30, +// "daily":true, +// "maxdays":15, +// "rotate":true +// } +func (log *FileLogger) Init(config string) error { + if err := json.Unmarshal([]byte(config), log); err != nil { + return err + } + if len(log.Filename) == 0 { + return errors.New("config must have filename") + } + // set MuxWriter as Logger's io.Writer + log.createLogger(log.mw) + return log.StartLogger() +} + +// StartLogger start file logger. create log file and set to locker-inside file writer. +func (log *FileLogger) StartLogger() error { + fd, err := log.createLogFile() + if err != nil { + return err + } + log.mw.SetFd(fd) + return log.initFd() +} + +func (log *FileLogger) docheck(size int) { + log.startLock.Lock() + defer log.startLock.Unlock() + if log.Rotate && ((log.Maxsize > 0 && log.maxsizeCursize >= log.Maxsize) || + (log.Daily && time.Now().Day() != log.dailyOpenDate)) { + if err := log.DoRotate(); err != nil { + fmt.Fprintf(os.Stderr, "FileLogger(%q): %s\n", log.Filename, err) + return + } + } + log.maxsizeCursize += size +} + +func (log *FileLogger) createLogFile() (*os.File, error) { + // Open the log file + return os.OpenFile(log.Filename, os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0660) +} + +func (log *FileLogger) initFd() error { + fd := log.mw.fd + finfo, err := fd.Stat() + if err != nil { + return fmt.Errorf("get stat: %v", err) + } + log.maxsizeCursize = int(finfo.Size()) + log.dailyOpenDate = time.Now().Day() + return nil +} + +// DoRotate means it need to write file in new file. +// new file name like xx.log.2013-01-01.2 +func (log *FileLogger) DoRotate() error { + _, err := os.Lstat(log.Filename) + if err == nil { // file exists + // Find the next available number + num := 1 + fname := "" + for ; err == nil && num <= 999; num++ { + fname = log.Filename + fmt.Sprintf(".%s.%03d", time.Now().Format("2006-01-02"), num) + _, err = os.Lstat(fname) + if log.Compress && err != nil { + _, err = os.Lstat(fname + ".gz") + } + } + // return error if the last file checked still existed + if err == nil { + return fmt.Errorf("rotate: cannot find free log number to rename %s", log.Filename) + } + + fd := log.mw.fd + fd.Close() + + // close fd before rename + // Rename the file to its newfound home + if err = os.Rename(log.Filename, fname); err != nil { + return fmt.Errorf("Rotate: %v", err) + } + + if log.Compress { + go compressOldLogFile(fname, log.CompressionLevel) + } + + // re-start logger + if err = log.StartLogger(); err != nil { + return fmt.Errorf("Rotate StartLogger: %v", err) + } + + go log.deleteOldLog() + } + + return nil +} + +func compressOldLogFile(fname string, compressionLevel int) error { + reader, err := os.Open(fname) + if err != nil { + return err + } + defer reader.Close() + buffer := bufio.NewReader(reader) + fw, err := os.OpenFile(fname+".gz", os.O_WRONLY|os.O_CREATE, 0660) + if err != nil { + return err + } + defer fw.Close() + zw, err := gzip.NewWriterLevel(fw, compressionLevel) + if err != nil { + return err + } + defer zw.Close() + _, err = buffer.WriteTo(zw) + if err != nil { + zw.Close() + fw.Close() + os.Remove(fname + ".gz") + return err + } + reader.Close() + return os.Remove(fname) +} + +func (log *FileLogger) deleteOldLog() { + dir := filepath.Dir(log.Filename) + filepath.Walk(dir, func(path string, info os.FileInfo, err error) (returnErr error) { + defer func() { + if r := recover(); r != nil { + returnErr = fmt.Errorf("Unable to delete old log '%s', error: %+v", path, r) + } + }() + + if !info.IsDir() && info.ModTime().Unix() < (time.Now().Unix()-60*60*24*log.Maxdays) { + if strings.HasPrefix(filepath.Base(path), filepath.Base(log.Filename)) { + + if err := os.Remove(path); err != nil { + returnErr = fmt.Errorf("Failed to remove %s: %v", path, err) + } + } + } + return returnErr + }) +} + +// Flush flush file logger. +// there are no buffering messages in file logger in memory. +// flush file means sync file from disk. +func (log *FileLogger) Flush() { + log.mw.fd.Sync() +} + +// GetName returns the default name for this implementation +func (log *FileLogger) GetName() string { + return "file" +} + +func init() { + Register("file", NewFileLogger) +} diff --git a/file_test.go b/file_test.go new file mode 100644 index 0000000..9527069 --- /dev/null +++ b/file_test.go @@ -0,0 +1,247 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "compress/gzip" + "fmt" + "io/ioutil" + "os" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestFileLoggerFails(t *testing.T) { + tmpDir, err := ioutil.TempDir("", "TestFileLogger") + assert.NoError(t, err) + defer os.RemoveAll(tmpDir) + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + //filename := filepath.Join(tmpDir, "test.log") + + fileLogger := NewFileLogger() + //realFileLogger, ok := fileLogger.(*FileLogger) + //assert.Equal(t, true, ok) + + // Fail if there is bad json + err = fileLogger.Init("{") + assert.Error(t, err) + + // Fail if there is no filename + err = fileLogger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"filename\":\"%s\"}", prefix, level.String(), flags, "")) + assert.Error(t, err) + + // Fail if the file isn't a filename + err = fileLogger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"filename\":\"%s\"}", prefix, level.String(), flags, filepath.ToSlash(tmpDir))) + assert.Error(t, err) + +} + +func TestFileLogger(t *testing.T) { + tmpDir, err := ioutil.TempDir("", "TestFileLogger") + assert.NoError(t, err) + defer os.RemoveAll(tmpDir) + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + filename := filepath.Join(tmpDir, "test.log") + + fileLogger := NewFileLogger() + realFileLogger, ok := fileLogger.(*FileLogger) + assert.Equal(t, true, ok) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + + fileLogger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"filename\":\"%s\",\"maxsize\":%d,\"compress\":false}", prefix, level.String(), flags, filepath.ToSlash(filename), len(expected)*2)) + + assert.Equal(t, flags, realFileLogger.Flags) + assert.Equal(t, level, realFileLogger.Level) + assert.Equal(t, level, fileLogger.GetLevel()) + + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err := ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + event.level = DEBUG + expected = expected + "" + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + event.level = TRACE + expected = expected + "" + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + event.level = WARN + expected = expected + fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + // Should rotate + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename + fmt.Sprintf(".%s.%03d", time.Now().Format("2006-01-02"), 1)) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + assert.Equal(t, expected, string(logData)) + + for num := 2; num <= 999; num++ { + file, err := os.OpenFile(filename+fmt.Sprintf(".%s.%03d", time.Now().Format("2006-01-02"), num), os.O_RDONLY|os.O_CREATE, 0666) + assert.NoError(t, err) + file.Close() + } + err = realFileLogger.DoRotate() + assert.Error(t, err) + + expected = expected + fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + // Should fail to rotate + expected = expected + fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + fileLogger.Close() +} + +func TestCompressFileLogger(t *testing.T) { + tmpDir, err := ioutil.TempDir("", "TestFileLogger") + assert.NoError(t, err) + defer os.RemoveAll(tmpDir) + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + filename := filepath.Join(tmpDir, "test.log") + + fileLogger := NewFileLogger() + realFileLogger, ok := fileLogger.(*FileLogger) + assert.Equal(t, true, ok) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + + fileLogger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"filename\":\"%s\",\"maxsize\":%d,\"compress\":true}", prefix, level.String(), flags, filepath.ToSlash(filename), len(expected)*2)) + + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err := ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + event.level = WARN + expected = expected + fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + fileLogger.LogEvent(&event) + fileLogger.Flush() + logData, err = ioutil.ReadFile(filename) + assert.NoError(t, err) + assert.Equal(t, expected, string(logData)) + + // Should rotate + fileLogger.LogEvent(&event) + fileLogger.Flush() + + for num := 2; num <= 999; num++ { + file, err := os.OpenFile(filename+fmt.Sprintf(".%s.%03d.gz", time.Now().Format("2006-01-02"), num), os.O_RDONLY|os.O_CREATE, 0666) + assert.NoError(t, err) + file.Close() + } + err = realFileLogger.DoRotate() + assert.Error(t, err) +} + +func TestCompressOldFile(t *testing.T) { + tmpDir, err := ioutil.TempDir("", "TestFileLogger") + assert.NoError(t, err) + defer os.RemoveAll(tmpDir) + fname := filepath.Join(tmpDir, "test") + nonGzip := filepath.Join(tmpDir, "test-nonGzip") + + f, err := os.OpenFile(fname, os.O_CREATE|os.O_WRONLY, 0660) + assert.NoError(t, err) + ng, err := os.OpenFile(nonGzip, os.O_CREATE|os.O_WRONLY, 0660) + assert.NoError(t, err) + + for i := 0; i < 999; i++ { + f.WriteString("This is a test file\n") + ng.WriteString("This is a test file\n") + } + f.Close() + ng.Close() + + err = compressOldLogFile(fname, -1) + assert.NoError(t, err) + + _, err = os.Lstat(fname + ".gz") + assert.NoError(t, err) + + f, err = os.Open(fname + ".gz") + assert.NoError(t, err) + zr, err := gzip.NewReader(f) + assert.NoError(t, err) + data, err := ioutil.ReadAll(zr) + assert.NoError(t, err) + original, err := ioutil.ReadFile(nonGzip) + assert.NoError(t, err) + assert.Equal(t, original, data) +} diff --git a/go.mod b/go.mod new file mode 100644 index 0000000..1d9a7a4 --- /dev/null +++ b/go.mod @@ -0,0 +1,9 @@ +module code.gitea.io/log + +go 1.12 + +require ( + github.com/mattn/go-isatty v0.0.7 + github.com/stretchr/testify v1.3.0 + golang.org/x/sys v0.0.0-20190318195719-6c81ef8f67ca +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..81cd0f8 --- /dev/null +++ b/go.sum @@ -0,0 +1,12 @@ +github.com/davecgh/go-spew v1.1.0 h1:ZDRjVQ15GmhC3fiQ8ni8+OwkZQO4DARzQgrnXU1Liz8= +github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= +github.com/mattn/go-isatty v0.0.7 h1:UvyT9uN+3r7yLEYSlJsbQGdsaB/a0DlgWP3pql6iwOc= +github.com/mattn/go-isatty v0.0.7/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s= +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/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= +github.com/stretchr/testify v1.3.0 h1:TivCn/peBQ7UY8ooIcPgZFpTNSz0Q2U6UrFlUfqbe0Q= +github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= +golang.org/x/sys v0.0.0-20190222072716-a9d3bda3a223/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190318195719-6c81ef8f67ca h1:o2TLx1bGN3W+Ei0EMU5fShLupLmTOU95KvJJmfYhAzM= +golang.org/x/sys v0.0.0-20190318195719-6c81ef8f67ca/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= diff --git a/level.go b/level.go new file mode 100644 index 0000000..6131fcb --- /dev/null +++ b/level.go @@ -0,0 +1,111 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "bytes" + "encoding/json" + "fmt" + "os" + "strings" +) + +// Level is the level of the logger +type Level int + +const ( + // TRACE represents the lowest log level + TRACE Level = iota + // DEBUG is for debug logging + DEBUG + // INFO is for information + INFO + // WARN is for warning information + WARN + // ERROR is for error reporting + ERROR + // CRITICAL is for critical errors + CRITICAL + // FATAL is for fatal errors + FATAL + // NONE is for no logging + NONE +) + +var toString = map[Level]string{ + TRACE: "trace", + DEBUG: "debug", + INFO: "info", + WARN: "warn", + ERROR: "error", + CRITICAL: "critical", + FATAL: "fatal", + NONE: "none", +} + +var toLevel = map[string]Level{ + "trace": TRACE, + "debug": DEBUG, + "info": INFO, + "warn": WARN, + "error": ERROR, + "critical": CRITICAL, + "fatal": FATAL, + "none": NONE, +} + +// Levels returns all the possible logging levels +func Levels() []string { + keys := make([]string, 0) + for key := range toLevel { + keys = append(keys, key) + } + return keys +} + +func (l Level) String() string { + s, ok := toString[l] + if ok { + return s + } + return "info" +} + +// MarshalJSON takes a Level and turns it into text +func (l Level) MarshalJSON() ([]byte, error) { + buffer := bytes.NewBufferString(`"`) + buffer.WriteString(toString[l]) + buffer.WriteString(`"`) + return buffer.Bytes(), nil +} + +// FromString takes a level string and returns a Level +func FromString(level string) Level { + temp, ok := toLevel[strings.ToLower(level)] + if !ok { + return INFO + } + return temp +} + +// UnmarshalJSON takes text and turns it into a Level +func (l *Level) UnmarshalJSON(b []byte) error { + var tmp interface{} + err := json.Unmarshal(b, &tmp) + if err != nil { + fmt.Fprintf(os.Stderr, "Err: %v", err) + return err + } + + switch v := tmp.(type) { + case string: + *l = FromString(string(v)) + case int: + *l = FromString(Level(v).String()) + default: + *l = INFO + } + return nil +} diff --git a/level_test.go b/level_test.go new file mode 100644 index 0000000..40f6310 --- /dev/null +++ b/level_test.go @@ -0,0 +1,55 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "encoding/json" + "fmt" + "testing" + + "github.com/stretchr/testify/assert" +) + +type testLevel struct { + Level Level `json:"level"` +} + +func TestLevelMarshalUnmarshalJSON(t *testing.T) { + levelBytes, err := json.Marshal(testLevel{ + Level: INFO, + }) + assert.NoError(t, err) + assert.Equal(t, string(makeTestLevelBytes(INFO.String())), string(levelBytes)) + + var testLevel testLevel + err = json.Unmarshal(levelBytes, &testLevel) + assert.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal(makeTestLevelBytes(`FOFOO`), &testLevel) + assert.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal([]byte(fmt.Sprintf(`{"level":%d}`, 2)), &testLevel) + assert.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal([]byte(fmt.Sprintf(`{"level":%d}`, 10012)), &testLevel) + assert.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal([]byte(`{"level":{}}`), &testLevel) + assert.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + assert.Equal(t, INFO.String(), Level(1001).String()) + + err = json.Unmarshal([]byte(`{"level":{}`), &testLevel.Level) + assert.Error(t, err) +} + +func makeTestLevelBytes(level string) []byte { + return []byte(fmt.Sprintf(`{"level":"%s"}`, level)) +} diff --git a/log.go b/log.go new file mode 100644 index 0000000..c0fd117 --- /dev/null +++ b/log.go @@ -0,0 +1,245 @@ +// Copyright 2014 The Gogs Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "os" + "path" + "runtime" + "strings" +) + +var ( + // DEFAULT is the name of the default logger + DEFAULT = "default" + // NamedLoggers map of named loggers + NamedLoggers = make(map[string]*Logger) + // GitLogger logger for git + GitLogger *Logger + prefix string +) + +// NewLogger create a logger for the default logger +func NewLogger(bufLen int64, name, provider, config string) *Logger { + err := NewNamedLogger(DEFAULT, bufLen, name, provider, config) + if err != nil { + CriticalWithSkip(1, "Unable to create default logger: %v", err) + panic(err) + } + return NamedLoggers[DEFAULT] +} + +// NewNamedLogger creates a new named logger for a given configuration +func NewNamedLogger(name string, bufLen int64, subname, provider, config string) error { + logger, ok := NamedLoggers[name] + if !ok { + logger = newLogger(name, bufLen) + + NamedLoggers[name] = logger + } + + return logger.SetLogger(subname, provider, config) +} + +// DelNamedLogger closes and deletes the named logger +func DelNamedLogger(name string) { + l, ok := NamedLoggers[name] + if ok { + delete(NamedLoggers, name) + l.Close() + } +} + +// DelLogger removes the named sublogger from the default logger +func DelLogger(name string) error { + logger := NamedLoggers[DEFAULT] + found, err := logger.DelLogger(name) + if !found { + Trace("Log %s not found, no need to delete", name) + } + return err +} + +// GetLogger returns either a named logger or the default logger +func GetLogger(name string) *Logger { + logger, ok := NamedLoggers[name] + if ok { + return logger + } + return NamedLoggers[DEFAULT] +} + +// NewGitLogger create a logger for git +// FIXME: use same log level as other loggers. +func NewGitLogger(logPath string) { + path := path.Dir(logPath) + + if err := os.MkdirAll(path, os.ModePerm); err != nil { + Fatal("Failed to create dir %s: %v", path, err) + } + + GitLogger = newLogger("git", 0) + GitLogger.SetLogger("file", "file", fmt.Sprintf(`{"level":"TRACE","filename":"%s","rotate":false}`, logPath)) +} + +// GetLevel returns the minimum logger level +func GetLevel() Level { + return NamedLoggers[DEFAULT].GetLevel() +} + +// GetStacktraceLevel returns the minimum logger level +func GetStacktraceLevel() Level { + return NamedLoggers[DEFAULT].GetStacktraceLevel() +} + +// Trace records trace log +func Trace(format string, v ...interface{}) { + Log(1, TRACE, format, v...) +} + +// IsTrace returns true if at least one logger is TRACE +func IsTrace() bool { + return GetLevel() <= TRACE +} + +// Debug records debug log +func Debug(format string, v ...interface{}) { + Log(1, DEBUG, format, v...) +} + +// IsDebug returns true if at least one logger is DEBUG +func IsDebug() bool { + return GetLevel() <= DEBUG +} + +// Info records info log +func Info(format string, v ...interface{}) { + Log(1, INFO, format, v...) +} + +// IsInfo returns true if at least one logger is INFO +func IsInfo() bool { + return GetLevel() <= INFO +} + +// Warn records warning log +func Warn(format string, v ...interface{}) { + Log(1, WARN, format, v...) +} + +// IsWarn returns true if at least one logger is WARN +func IsWarn() bool { + return GetLevel() <= WARN +} + +// Error records error log +func Error(format string, v ...interface{}) { + Log(1, ERROR, format, v...) +} + +// ErrorWithSkip records error log from "skip" calls back from this function +func ErrorWithSkip(skip int, format string, v ...interface{}) { + Log(skip+1, ERROR, format, v...) +} + +// IsError returns true if at least one logger is ERROR +func IsError() bool { + return GetLevel() <= ERROR +} + +// Critical records critical log +func Critical(format string, v ...interface{}) { + Log(1, CRITICAL, format, v...) +} + +// CriticalWithSkip records critical log from "skip" calls back from this function +func CriticalWithSkip(skip int, format string, v ...interface{}) { + Log(skip+1, CRITICAL, format, v...) +} + +// IsCritical returns true if at least one logger is CRITICAL +func IsCritical() bool { + return GetLevel() <= CRITICAL +} + +// Fatal records fatal log and exit process +func Fatal(format string, v ...interface{}) { + Log(1, FATAL, format, v...) + Close() + os.Exit(1) +} + +// FatalWithSkip records fatal log from "skip" calls back from this function +func FatalWithSkip(skip int, format string, v ...interface{}) { + Log(skip+1, FATAL, format, v...) + Close() + os.Exit(1) +} + +// IsFatal returns true if at least one logger is FATAL +func IsFatal() bool { + return GetLevel() <= FATAL +} + +// Close closes all the loggers +func Close() { + l, ok := NamedLoggers[DEFAULT] + if !ok { + return + } + delete(NamedLoggers, DEFAULT) + l.Close() +} + +// Log a message with defined skip and at logging level +// A skip of 0 refers to the caller of this command +func Log(skip int, level Level, format string, v ...interface{}) { + l, ok := NamedLoggers[DEFAULT] + if ok { + l.Log(skip+1, level, format, v...) + } +} + +// LoggerAsWriter is a io.Writer shim around the gitea log +type LoggerAsWriter struct { + ourLoggers []*Logger + level Level +} + +// NewLoggerAsWriter creates a Writer representation of the logger with setable log level +func NewLoggerAsWriter(level string, ourLoggers ...*Logger) *LoggerAsWriter { + if len(ourLoggers) == 0 { + ourLoggers = []*Logger{NamedLoggers[DEFAULT]} + } + l := &LoggerAsWriter{ + ourLoggers: ourLoggers, + level: FromString(level), + } + return l +} + +// Write implements the io.Writer interface to allow spoofing of macaron +func (l *LoggerAsWriter) Write(p []byte) (int, error) { + for _, logger := range l.ourLoggers { + // Skip = 3 because this presumes that we have been called by log.Println() + // If the caller has used log.Output or the like this will be wrong + logger.Log(3, l.level, string(p)) + } + return len(p), nil +} + +// Log takes a given string and logs it at the set log-level +func (l *LoggerAsWriter) Log(msg string) { + for _, logger := range l.ourLoggers { + // Set the skip to reference the call just above this + logger.Log(1, l.level, msg) + } +} + +func init() { + _, filename, _, _ := runtime.Caller(0) + prefix = strings.TrimSuffix(filename, "modules/log/log.go") +} diff --git a/log_test.go b/log_test.go new file mode 100644 index 0000000..9e3d752 --- /dev/null +++ b/log_test.go @@ -0,0 +1,154 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "testing" + + "github.com/stretchr/testify/assert" +) + +func baseConsoleTest(t *testing.T, logger *Logger) (chan []byte, chan bool) { + written := make(chan []byte) + closed := make(chan bool) + + c := CallbackWriteCloser{ + callback: func(p []byte, close bool) { + written <- p + closed <- close + }, + } + m := logger.MultiChannelledLog + + channelledLog := m.GetEventLogger("console") + assert.NotEmpty(t, channelledLog) + realChanLog, ok := channelledLog.(*ChannelledLog) + assert.Equal(t, true, ok) + realCL, ok := realChanLog.loggerProvider.(*ConsoleLogger) + assert.Equal(t, true, ok) + assert.Equal(t, INFO, realCL.Level) + realCL.out = c + + format := "test: %s" + args := []interface{}{"A"} + + logger.Log(0, INFO, format, args...) + line := <-written + assert.Contains(t, string(line), fmt.Sprintf(format, args...)) + assert.Equal(t, false, <-closed) + + format = "test2: %s" + logger.Warn(format, args...) + line = <-written + + assert.Contains(t, string(line), fmt.Sprintf(format, args...)) + assert.Equal(t, false, <-closed) + + format = "testerror: %s" + logger.Error(format, args...) + line = <-written + assert.Contains(t, string(line), fmt.Sprintf(format, args...)) + assert.Equal(t, false, <-closed) + return written, closed +} + +func TestNewLoggerUnexported(t *testing.T) { + level := INFO + logger := newLogger("UNEXPORTED", 0) + err := logger.SetLogger("console", "console", fmt.Sprintf(`{"level":"%s"}`, level.String())) + assert.NoError(t, err) + out := logger.MultiChannelledLog.GetEventLogger("console") + assert.NotEmpty(t, out) + chanlog, ok := out.(*ChannelledLog) + assert.Equal(t, true, ok) + assert.Equal(t, "console", chanlog.provider) + assert.Equal(t, INFO, logger.GetLevel()) + baseConsoleTest(t, logger) +} + +func TestNewLoggger(t *testing.T) { + level := INFO + logger := NewLogger(0, "console", "console", fmt.Sprintf(`{"level":"%s"}`, level.String())) + + assert.Equal(t, INFO, GetLevel()) + assert.Equal(t, false, IsTrace()) + assert.Equal(t, false, IsDebug()) + assert.Equal(t, true, IsInfo()) + assert.Equal(t, true, IsWarn()) + assert.Equal(t, true, IsError()) + + written, closed := baseConsoleTest(t, logger) + + format := "test: %s" + args := []interface{}{"A"} + + Log(0, INFO, format, args...) + line := <-written + assert.Contains(t, string(line), fmt.Sprintf(format, args...)) + assert.Equal(t, false, <-closed) + + Info(format, args...) + line = <-written + assert.Contains(t, string(line), fmt.Sprintf(format, args...)) + assert.Equal(t, false, <-closed) + + go DelLogger("console") + line = <-written + assert.Equal(t, "", string(line)) + assert.Equal(t, true, <-closed) +} + +func TestNewLogggerRecreate(t *testing.T) { + level := INFO + NewLogger(0, "console", "console", fmt.Sprintf(`{"level":"%s"}`, level.String())) + + assert.Equal(t, INFO, GetLevel()) + assert.Equal(t, false, IsTrace()) + assert.Equal(t, false, IsDebug()) + assert.Equal(t, true, IsInfo()) + assert.Equal(t, true, IsWarn()) + assert.Equal(t, true, IsError()) + + format := "test: %s" + args := []interface{}{"A"} + + Log(0, INFO, format, args...) + + NewLogger(0, "console", "console", fmt.Sprintf(`{"level":"%s"}`, level.String())) + + assert.Equal(t, INFO, GetLevel()) + assert.Equal(t, false, IsTrace()) + assert.Equal(t, false, IsDebug()) + assert.Equal(t, true, IsInfo()) + assert.Equal(t, true, IsWarn()) + assert.Equal(t, true, IsError()) + + Log(0, INFO, format, args...) + + assert.Panics(t, func() { + NewLogger(0, "console", "console", fmt.Sprintf(`{"level":"%s"`, level.String())) + }) + + go DelLogger("console") + + // We should be able to redelete without a problem + go DelLogger("console") + +} + +func TestNewNamedLogger(t *testing.T) { + level := INFO + err := NewNamedLogger("test", 0, "console", "console", fmt.Sprintf(`{"level":"%s"}`, level.String())) + assert.NoError(t, err) + logger := NamedLoggers["test"] + assert.Equal(t, level, logger.GetLevel()) + + written, closed := baseConsoleTest(t, logger) + go DelNamedLogger("test") + line := <-written + assert.Equal(t, "", string(line)) + assert.Equal(t, true, <-closed) +} diff --git a/logger.go b/logger.go new file mode 100644 index 0000000..925ab02 --- /dev/null +++ b/logger.go @@ -0,0 +1,156 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "os" + "runtime" + "strings" + "time" +) + +// Logger is default logger in the Gitea application. +// it can contain several providers and log message into all providers. +type Logger struct { + *MultiChannelledLog + bufferLength int64 +} + +// newLogger initializes and returns a new logger. +func newLogger(name string, buffer int64) *Logger { + l := &Logger{ + MultiChannelledLog: NewMultiChannelledLog(name, buffer), + bufferLength: buffer, + } + return l +} + +// SetLogger sets new logger instance with given logger provider and config. +func (l *Logger) SetLogger(name, provider, config string) error { + eventLogger, err := NewChannelledLog(name, provider, config, l.bufferLength) + if err != nil { + return fmt.Errorf("Failed to create sublogger (%s): %v", name, err) + } + + l.MultiChannelledLog.DelLogger(name) + + err = l.MultiChannelledLog.AddLogger(eventLogger) + if err != nil { + if IsErrDuplicateName(err) { + return fmt.Errorf("Duplicate named sublogger %s %v", name, l.MultiChannelledLog.GetEventLoggerNames()) + } + return fmt.Errorf("Failed to add sublogger (%s): %v", name, err) + } + + return nil +} + +// DelLogger deletes a sublogger from this logger. +func (l *Logger) DelLogger(name string) (bool, error) { + return l.MultiChannelledLog.DelLogger(name), nil +} + +// Log msg at the provided level with the provided caller defined by skip (0 being the function that calls this function) +func (l *Logger) Log(skip int, level Level, format string, v ...interface{}) error { + if l.GetLevel() > level { + return nil + } + caller := "?()" + pc, filename, line, ok := runtime.Caller(skip + 1) + if ok { + // Get caller function name. + fn := runtime.FuncForPC(pc) + if fn != nil { + caller = fn.Name() + "()" + } + } + msg := format + if len(v) > 0 { + args := make([]interface{}, len(v)) + for i := 0; i < len(args); i++ { + args[i] = NewColoredValuePointer(&v[i]) + } + msg = fmt.Sprintf(format, args...) + } + stack := "" + if l.GetStacktraceLevel() <= level { + stack = Stack(skip + 1) + } + return l.SendLog(level, caller, strings.TrimPrefix(filename, prefix), line, msg, stack) +} + +// SendLog sends a log event at the provided level with the information given +func (l *Logger) SendLog(level Level, caller, filename string, line int, msg string, stack string) error { + if l.GetLevel() > level { + return nil + } + event := &Event{ + level: level, + caller: caller, + filename: filename, + line: line, + msg: msg, + time: time.Now(), + stacktrace: stack, + } + l.LogEvent(event) + return nil +} + +// Trace records trace log +func (l *Logger) Trace(format string, v ...interface{}) { + l.Log(1, TRACE, format, v...) +} + +// Debug records debug log +func (l *Logger) Debug(format string, v ...interface{}) { + l.Log(1, DEBUG, format, v...) + +} + +// Info records information log +func (l *Logger) Info(format string, v ...interface{}) { + l.Log(1, INFO, format, v...) +} + +// Warn records warning log +func (l *Logger) Warn(format string, v ...interface{}) { + l.Log(1, WARN, format, v...) +} + +// Error records error log +func (l *Logger) Error(format string, v ...interface{}) { + l.Log(1, ERROR, format, v...) +} + +// ErrorWithSkip records error log from "skip" calls back from this function +func (l *Logger) ErrorWithSkip(skip int, format string, v ...interface{}) { + l.Log(skip+1, ERROR, format, v...) +} + +// Critical records critical log +func (l *Logger) Critical(format string, v ...interface{}) { + l.Log(1, CRITICAL, format, v...) +} + +// CriticalWithSkip records critical log from "skip" calls back from this function +func (l *Logger) CriticalWithSkip(skip int, format string, v ...interface{}) { + l.Log(skip+1, CRITICAL, format, v...) +} + +// Fatal records fatal log and exit the process +func (l *Logger) Fatal(format string, v ...interface{}) { + l.Log(1, FATAL, format, v...) + l.Close() + os.Exit(1) +} + +// FatalWithSkip records fatal log from "skip" calls back from this function and exits the process +func (l *Logger) FatalWithSkip(skip int, format string, v ...interface{}) { + l.Log(skip+1, FATAL, format, v...) + l.Close() + os.Exit(1) +} diff --git a/provider.go b/provider.go new file mode 100644 index 0000000..b31bf39 --- /dev/null +++ b/provider.go @@ -0,0 +1,26 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +// LoggerProvider represents behaviors of a logger provider. +type LoggerProvider interface { + Init(config string) error + EventLogger +} + +type loggerProvider func() LoggerProvider + +var providers = make(map[string]loggerProvider) + +// Register registers given logger provider to providers. +func Register(name string, log loggerProvider) { + if log == nil { + panic("log: register provider is nil") + } + if _, dup := providers[name]; dup { + panic("log: register called twice for provider \"" + name + "\"") + } + providers[name] = log +} diff --git a/smtp.go b/smtp.go new file mode 100644 index 0000000..2e78d71 --- /dev/null +++ b/smtp.go @@ -0,0 +1,111 @@ +// Copyright 2014 The Gogs Authors. All rights reserved. +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "encoding/json" + "net/smtp" + "strings" +) + +const ( + subjectPhrase = "Diagnostic message from server" +) + +type smtpWriter struct { + owner *SMTPLogger +} + +// Write sends the message as an email +func (s *smtpWriter) Write(p []byte) (int, error) { + return s.owner.sendMail(p) +} + +// Close does nothing +func (s *smtpWriter) Close() error { + return nil +} + +// SMTPLogger implements LoggerProvider and is used to send emails via given SMTP-server. +type SMTPLogger struct { + BaseLogger + Username string `json:"Username"` + Password string `json:"password"` + Host string `json:"host"` + Subject string `json:"subject"` + RecipientAddresses []string `json:"sendTos"` + sendMailFn func(string, smtp.Auth, string, []string, []byte) error +} + +// NewSMTPLogger creates smtp writer. +func NewSMTPLogger() LoggerProvider { + s := &SMTPLogger{} + s.Level = TRACE + s.sendMailFn = smtp.SendMail + return s +} + +// Init smtp writer with json config. +// config like: +// { +// "Username":"example@gmail.com", +// "password:"password", +// "host":"smtp.gmail.com:465", +// "subject":"email title", +// "sendTos":["email1","email2"], +// "level":LevelError +// } +func (log *SMTPLogger) Init(jsonconfig string) error { + err := json.Unmarshal([]byte(jsonconfig), log) + if err != nil { + return err + } + log.createLogger(&smtpWriter{ + owner: log, + }) + log.sendMailFn = smtp.SendMail + return nil +} + +// WriteMsg writes message in smtp writer. +// it will send an email with subject and only this message. +func (log *SMTPLogger) sendMail(p []byte) (int, error) { + hp := strings.Split(log.Host, ":") + + // Set up authentication information. + auth := smtp.PlainAuth( + "", + log.Username, + log.Password, + hp[0], + ) + // Connect to the server, authenticate, set the sender and recipient, + // and send the email all in one step. + contentType := "Content-Type: text/plain" + "; charset=UTF-8" + mailmsg := []byte("To: " + strings.Join(log.RecipientAddresses, ";") + "\r\nFrom: " + log.Username + "<" + log.Username + + ">\r\nSubject: " + log.Subject + "\r\n" + contentType + "\r\n\r\n") + mailmsg = append(mailmsg, p...) + return len(p), log.sendMailFn( + log.Host, + auth, + log.Username, + log.RecipientAddresses, + mailmsg, + ) +} + +// Flush when log should be flushed +func (log *SMTPLogger) Flush() { +} + +// GetName returns the default name for this implementation +func (log *SMTPLogger) GetName() string { + return "smtp" +} + +func init() { + Register("smtp", NewSMTPLogger) +} diff --git a/smtp_test.go b/smtp_test.go new file mode 100644 index 0000000..216d555 --- /dev/null +++ b/smtp_test.go @@ -0,0 +1,86 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "fmt" + "net/smtp" + "strings" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestSMTPLogger(t *testing.T) { + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + username := "testuser" + password := "testpassword" + host := "testhost" + subject := "testsubject" + sendTos := []string{"testto1", "testto2"} + + logger := NewSMTPLogger() + smtpLogger, ok := logger.(*SMTPLogger) + assert.Equal(t, true, ok) + + err := logger.Init(fmt.Sprintf("{\"prefix\":\"%s\",\"level\":\"%s\",\"flags\":%d,\"username\":\"%s\",\"password\":\"%s\",\"host\":\"%s\",\"subject\":\"%s\",\"sendTos\":[\"%s\",\"%s\"]}", prefix, level.String(), flags, username, password, host, subject, sendTos[0], sendTos[1])) + assert.NoError(t, err) + + assert.Equal(t, flags, smtpLogger.Flags) + assert.Equal(t, level, smtpLogger.Level) + assert.Equal(t, level, logger.GetLevel()) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + level: INFO, + msg: "TEST MSG", + caller: "CALLER", + filename: "FULL/FILENAME", + line: 1, + time: date, + } + + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + + var envToHost string + var envFrom string + var envTo []string + var envMsg []byte + smtpLogger.sendMailFn = func(addr string, a smtp.Auth, from string, to []string, msg []byte) error { + envToHost = addr + envFrom = from + envTo = to + envMsg = msg + return nil + } + + err = logger.LogEvent(&event) + assert.NoError(t, err) + assert.Equal(t, host, envToHost) + assert.Equal(t, username, envFrom) + assert.Equal(t, sendTos, envTo) + assert.Contains(t, string(envMsg), expected) + + logger.Flush() + + event.level = WARN + expected = fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.filename, event.line, event.caller, strings.ToUpper(event.level.String())[0], event.msg) + err = logger.LogEvent(&event) + assert.NoError(t, err) + assert.Equal(t, host, envToHost) + assert.Equal(t, username, envFrom) + assert.Equal(t, sendTos, envTo) + assert.Contains(t, string(envMsg), expected) + + logger.Close() +} diff --git a/stack.go b/stack.go new file mode 100644 index 0000000..ffe9aa6 --- /dev/null +++ b/stack.go @@ -0,0 +1,83 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// Use of this source code is governed by a MIT-style +// license that can be found in the LICENSE file. + +package log + +import ( + "bytes" + "fmt" + "io/ioutil" + "runtime" +) + +var ( + unknown = []byte("???") +) + +// Stack will skip back the provided number of frames and return a stack trace with source code. +// Although we could just use debug.Stack(), this routine will return the source code and +// skip back the provided number of frames - i.e. allowing us to ignore preceding function calls. +// A skip of 0 returns the stack trace for the calling function, not including this call. +// If the problem is a lack of memory of course all this is not going to work... +func Stack(skip int) string { + buf := new(bytes.Buffer) + + // Store the last file we opened as its probable that the preceding stack frame + // will be in the same file + var lines [][]byte + var lastFilename string + for i := skip + 1; ; i++ { // Skip over frames + programCounter, filename, lineNumber, ok := runtime.Caller(i) + // If we can't retrieve the information break - basically we're into go internals at this point. + if !ok { + break + } + + // Print equivalent of debug.Stack() + fmt.Fprintf(buf, "%s:%d (0x%x)\n", filename, lineNumber, programCounter) + // Now try to print the offending line + if filename != lastFilename { + data, err := ioutil.ReadFile(filename) + if err != nil { + // can't read this sourcefile + // likely we don't have the sourcecode available + continue + } + lines = bytes.Split(data, []byte{'\n'}) + lastFilename = filename + } + fmt.Fprintf(buf, "\t%s: %s\n", functionName(programCounter), source(lines, lineNumber)) + } + return buf.String() +} + +// functionName converts the provided programCounter into a function name +func functionName(programCounter uintptr) []byte { + function := runtime.FuncForPC(programCounter) + if function == nil { + return unknown + } + name := []byte(function.Name()) + + // Because we provide the filename we can drop the preceding package name. + if lastslash := bytes.LastIndex(name, []byte("/")); lastslash >= 0 { + name = name[lastslash+1:] + } + // And the current package name. + if period := bytes.Index(name, []byte(".")); period >= 0 { + name = name[period+1:] + } + // And we should just replace the interpunct with a dot + name = bytes.Replace(name, []byte("ยท"), []byte("."), -1) + return name +} + +// source returns a space-trimmed slice of the n'th line. +func source(lines [][]byte, n int) []byte { + n-- // in stack trace, lines are 1-indexed but our array is 0-indexed + if n < 0 || n >= len(lines) { + return unknown + } + return bytes.TrimSpace(lines[n]) +}