func defaultFormatFunc(email *Email) Formatter {
var err error
b := new(bytes.Buffer)
// apparently there is a race condition when I was using
// email.to... below in the SetHeader for whatever reason
// so copying the "to" values solves the issue
// I wonder if it's a flase positive in the race detector.....
to := make([]string, len(email.to), len(email.to))
copy(to, email.to)
template := email.Template()
message := gomail.NewMessage()
message.SetHeader("From", email.from)
message.SetHeader("To", to...)
return func(e *log.Entry) *gomail.Message {
b.Reset()
if err = template.ExecuteTemplate(b, "email", e); err != nil {
log.WithFields(log.F("error", err)).Error("Error parsing Email handler template")
}
message.SetHeader("Subject", e.Message)
message.SetBody(contentType, b.String())
return message
}
}
func defaultFormatFunc(h http.HTTP) http.Formatter {
var bt []byte
var err error
hc := h.(*HipChat)
b := new(bytes.Buffer)
template := hc.Template()
body := new(Body)
body.Notify = true
return func(e *log.Entry) []byte {
bt = bt[0:0]
b.Reset()
body.From = e.ApplicationID
body.Color = hc.GetDisplayColor(e.Level)
if err = template.ExecuteTemplate(b, "hipchat", e); err != nil {
log.WithFields(log.F("error", err)).Error("Error parsing HipChat handler template")
}
body.Message = b.String()
// shouldn't be possible to fail here
// at least with the default handler...
bt, _ = json.Marshal(body)
return bt
}
}
func BenchmarkLogConsoleTenFieldsParallel(b *testing.B) {
b.ResetTimer()
// log setup in TestMain
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
log.WithFields(
log.F("int", 1),
log.F("int64", int64(1)),
log.F("float", 3.0),
log.F("string", "four!"),
log.F("bool", true),
log.F("time", time.Unix(0, 0)),
log.F("error", errExample.Error()),
log.F("duration", time.Second),
log.F("user-defined type", _jane),
log.F("another string", "done!"),
).Info("Go fast.")
}
})
}
// this will redirect the output of
func handleStdLogger(done chan<- struct{}) {
r, w := io.Pipe()
defer r.Close()
defer w.Close()
stdlog.SetOutput(w)
scanner := bufio.NewScanner(r)
go func() {
done <- struct{}{}
}()
for scanner.Scan() {
log.WithFields(log.F("stdlog", true)).Notice(scanner.Text())
}
}
func main() {
cLog := console.New()
log.RegisterHandler(cLog, log.AllLevels...)
// Trace
defer log.Trace("trace").End()
log.Debug("debug")
log.Info("info")
log.Notice("notice")
log.Warn("warn")
log.Error("error")
// log.Panic("panic") // this will panic
log.Alert("alert")
// log.Fatal("fatal") // this will call os.Exit(1)
// logging with fields can be used with any of the above
log.WithFields(log.F("key", "value")).Info("test info")
}
func testFormatFunc(email *Email) Formatter {
var err error
b := new(bytes.Buffer)
return func(e *log.Entry) *gomail.Message {
b.Reset()
message := gomail.NewMessage()
message.SetHeader("From", email.From())
message.SetHeader("To", email.To()...)
if err = email.template.ExecuteTemplate(b, "email", e); err != nil {
log.WithFields(log.F("error", err)).Error("Error parsing Email handler template")
}
message.SetHeader("Subject", e.Message)
message.SetBody(contentType, b.String())
return message
}
}
func getConsoleLoggerColorTests() []test {
return []test{
{
lvl: log.DebugLevel,
msg: "debugf",
printf: "%s",
flds: nil,
want: "UTC [32m DEBUG[0m debugf\n",
},
{
lvl: log.DebugLevel,
msg: "debug",
flds: nil,
want: "UTC [32m DEBUG[0m debug\n",
},
{
lvl: log.InfoLevel,
msg: "infof",
printf: "%s",
flds: nil,
want: "UTC [34m INFO[0m infof\n",
},
{
lvl: log.InfoLevel,
msg: "info",
flds: nil,
want: "UTC [34m INFO[0m info\n",
},
{
lvl: log.NoticeLevel,
msg: "noticef",
printf: "%s",
flds: nil,
want: "UTC [36;1mNOTICE[0m noticef\n",
},
{
lvl: log.NoticeLevel,
msg: "notice",
flds: nil,
want: "UTC [36;1mNOTICE[0m notice\n",
},
{
lvl: log.WarnLevel,
msg: "warnf",
printf: "%s",
flds: nil,
want: "UTC [33;1m WARN[0m console_test.go:170 warnf\n",
},
{
lvl: log.WarnLevel,
msg: "warn",
flds: nil,
want: "UTC [33;1m WARN[0m console_test.go:168 warn\n",
},
{
lvl: log.ErrorLevel,
msg: "errorf",
printf: "%s",
flds: nil,
want: "UTC [31;1m ERROR[0m console_test.go:176 errorf\n",
},
{
lvl: log.ErrorLevel,
msg: "error",
flds: nil,
want: "UTC [31;1m ERROR[0m console_test.go:174 error\n",
},
{
lvl: log.AlertLevel,
msg: "alertf",
printf: "%s",
flds: nil,
want: "UTC [31m[4m ALERT[0m console_test.go:194 alertf\n",
},
{
lvl: log.AlertLevel,
msg: "alert",
flds: nil,
want: "UTC [31m[4m ALERT[0m console_test.go:192 alert\n",
},
{
lvl: log.PanicLevel,
msg: "panicf",
printf: "%s",
flds: nil,
want: "UTC [31m PANIC[0m console_test.go:187 panicf\n",
},
{
lvl: log.PanicLevel,
msg: "panic",
flds: nil,
want: "UTC [31m PANIC[0m console_test.go:185 panic\n",
},
{
lvl: log.DebugLevel,
msg: "debugf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [32m DEBUG[0m debugf [32mkey[0m=value\n",
},
{
lvl: log.DebugLevel,
msg: "debug",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [32m DEBUG[0m debug [32mkey[0m=value\n",
},
{
lvl: log.InfoLevel,
msg: "infof",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [34m INFO[0m infof [34mkey[0m=value\n",
},
{
lvl: log.InfoLevel,
msg: "info",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [34m INFO[0m info [34mkey[0m=value\n",
},
{
lvl: log.NoticeLevel,
msg: "noticef",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [36;1mNOTICE[0m noticef [36;1mkey[0m=value\n",
},
{
lvl: log.NoticeLevel,
msg: "notice",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [36;1mNOTICE[0m notice [36;1mkey[0m=value\n",
},
{
lvl: log.WarnLevel,
msg: "warnf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [33;1m WARN[0m console_test.go:170 warnf [33;1mkey[0m=value\n",
},
{
lvl: log.WarnLevel,
msg: "warn",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [33;1m WARN[0m console_test.go:168 warn [33;1mkey[0m=value\n",
},
{
lvl: log.ErrorLevel,
msg: "errorf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [31;1m ERROR[0m console_test.go:176 errorf [31;1mkey[0m=value\n",
},
{
lvl: log.ErrorLevel,
msg: "error",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [31;1m ERROR[0m console_test.go:174 error [31;1mkey[0m=value\n",
},
{
lvl: log.AlertLevel,
msg: "alertf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [31m[4m ALERT[0m console_test.go:194 alertf [31m[4mkey[0m=value\n",
},
{
lvl: log.AlertLevel,
msg: "alert",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [31m[4m ALERT[0m console_test.go:192 alert [31m[4mkey[0m=value\n",
},
{
lvl: log.PanicLevel,
msg: "panicf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [31m PANIC[0m console_test.go:187 panicf [31mkey[0m=value\n",
},
{
lvl: log.PanicLevel,
msg: "panic",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC [31m PANIC[0m console_test.go:185 panic [31mkey[0m=value\n",
},
{
lvl: log.DebugLevel,
msg: "debug",
flds: []log.Field{
log.F("key", "string"),
log.F("key", int(1)),
log.F("key", int8(2)),
log.F("key", int16(3)),
log.F("key", int32(4)),
log.F("key", int64(5)),
log.F("key", uint(1)),
log.F("key", uint8(2)),
log.F("key", uint16(3)),
log.F("key", uint32(4)),
log.F("key", uint64(5)),
log.F("key", true),
log.F("key", struct{ value string }{"struct"}),
},
want: "UTC [32m DEBUG[0m debug [32mkey[0m=string [32mkey[0m=1 [32mkey[0m=2 [32mkey[0m=3 [32mkey[0m=4 [32mkey[0m=5 [32mkey[0m=1 [32mkey[0m=2 [32mkey[0m=3 [32mkey[0m=4 [32mkey[0m=5 [32mkey[0m=true [32mkey[0m={struct}\n",
},
}
}
func getConsoleLoggerTests() []test {
return []test{
{
lvl: log.DebugLevel,
msg: "debug",
flds: nil,
want: "UTC DEBUG debug\n",
},
{
lvl: log.DebugLevel,
msg: "debugf",
printf: "%s",
flds: nil,
want: "UTC DEBUG debugf\n",
},
{
lvl: log.InfoLevel,
msg: "info",
flds: nil,
want: "UTC INFO info\n",
},
{
lvl: log.InfoLevel,
msg: "infof",
printf: "%s",
flds: nil,
want: "UTC INFO infof\n",
},
{
lvl: log.NoticeLevel,
msg: "notice",
flds: nil,
want: "UTC NOTICE notice\n",
},
{
lvl: log.NoticeLevel,
msg: "noticef",
printf: "%s",
flds: nil,
want: "UTC NOTICE noticef\n",
},
{
lvl: log.WarnLevel,
msg: "warn",
flds: nil,
want: "UTC WARN console_test.go:73 warn\n",
},
{
lvl: log.WarnLevel,
msg: "warnf",
printf: "%s",
flds: nil,
want: "UTC WARN console_test.go:75 warnf\n",
},
{
lvl: log.ErrorLevel,
msg: "error",
flds: nil,
want: "UTC ERROR console_test.go:79 error\n",
},
{
lvl: log.ErrorLevel,
msg: "errorf",
printf: "%s",
flds: nil,
want: "UTC ERROR console_test.go:81 errorf\n",
},
{
lvl: log.AlertLevel,
msg: "alert",
flds: nil,
want: "UTC ALERT console_test.go:97 alert\n",
},
{
lvl: log.AlertLevel,
msg: "alertf",
printf: "%s",
flds: nil,
want: "UTC ALERT console_test.go:99 alertf\n",
},
{
lvl: log.PanicLevel,
msg: "panic",
flds: nil,
want: "UTC PANIC console_test.go:90 panic\n",
},
{
lvl: log.PanicLevel,
msg: "panicf",
printf: "%s",
flds: nil,
want: "UTC PANIC console_test.go:92 panicf\n",
},
{
lvl: log.DebugLevel,
msg: "debug",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC DEBUG debug key=value\n",
},
{
lvl: log.DebugLevel,
msg: "debugf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC DEBUG debugf key=value\n",
},
{
lvl: log.InfoLevel,
msg: "info",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC INFO info key=value\n",
},
{
lvl: log.InfoLevel,
msg: "infof",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC INFO infof key=value\n",
},
{
lvl: log.NoticeLevel,
msg: "notice",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC NOTICE notice key=value\n",
},
{
lvl: log.NoticeLevel,
msg: "noticef",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC NOTICE noticef key=value\n",
},
{
lvl: log.WarnLevel,
msg: "warn",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC WARN console_test.go:73 warn key=value\n",
},
{
lvl: log.WarnLevel,
msg: "warnf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC WARN console_test.go:75 warnf key=value\n",
},
{
lvl: log.ErrorLevel,
msg: "error",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC ERROR console_test.go:79 error key=value\n",
},
{
lvl: log.ErrorLevel,
msg: "errorf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC ERROR console_test.go:81 errorf key=value\n",
},
{
lvl: log.AlertLevel,
msg: "alert",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC ALERT console_test.go:97 alert key=value\n",
},
{
lvl: log.AlertLevel,
msg: "alert",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC ALERT console_test.go:97 alert key=value\n",
},
{
lvl: log.AlertLevel,
msg: "alertf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC ALERT console_test.go:99 alertf key=value\n",
},
{
lvl: log.PanicLevel,
msg: "panicf",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC PANIC console_test.go:92 panicf key=value\n",
},
{
lvl: log.PanicLevel,
msg: "panic",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC PANIC console_test.go:90 panic key=value\n",
},
{
lvl: log.TraceLevel,
msg: "trace",
flds: nil,
want: "UTC TRACE trace",
},
{
lvl: log.TraceLevel,
msg: "tracef",
printf: "%s",
flds: nil,
want: "UTC TRACE tracef",
},
{
lvl: log.TraceLevel,
msg: "trace",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC TRACE trace key=value",
},
{
lvl: log.TraceLevel,
msg: "tracef",
printf: "%s",
flds: []log.Field{
log.F("key", "value"),
},
want: "UTC TRACE tracef key=value",
},
{
lvl: log.DebugLevel,
msg: "debug",
flds: []log.Field{
log.F("key", "string"),
log.F("key", int(1)),
log.F("key", int8(2)),
log.F("key", int16(3)),
log.F("key", int32(4)),
log.F("key", int64(5)),
log.F("key", uint(1)),
log.F("key", uint8(2)),
log.F("key", uint16(3)),
log.F("key", uint32(4)),
log.F("key", uint64(5)),
log.F("key", true),
log.F("key", struct{ value string }{"struct"}),
},
want: "UTC DEBUG debug key=string key=1 key=2 key=3 key=4 key=5 key=1 key=2 key=3 key=4 key=5 key=true key={struct}\n",
},
}
}
func getTestHTTPLoggerTests() []test {
return []test{
{
lvl: log.DebugLevel,
msg: "debug",
flds: nil,
want: "UTC DEBUG debug",
},
{
lvl: log.PanicLevel,
msg: "panic",
flds: nil,
want: "UTC PANIC http_test.go:85 panic",
},
{
lvl: log.InfoLevel,
msg: "info",
flds: nil,
want: "UTC INFO info",
},
{
lvl: log.NoticeLevel,
msg: "notice",
flds: nil,
want: "UTC NOTICE notice",
},
{
lvl: log.WarnLevel,
msg: "warn",
flds: nil,
want: "UTC WARN http_test.go:76 warn",
},
// {
// lvl: log.ErrorLevel,
// msg: "error",
// flds: nil,
// want: "UTC ERROR http_test.go:78 error",
// },
{
lvl: log.AlertLevel,
msg: "alert",
flds: nil,
want: "UTC ALERT http_test.go:88 alert",
},
{
lvl: log.DebugLevel,
msg: "debug",
flds: []log.Field{
log.F("key", "string"),
log.F("key", int(1)),
log.F("key", int8(2)),
log.F("key", int16(3)),
log.F("key", int32(4)),
log.F("key", int64(5)),
log.F("key", uint(1)),
log.F("key", uint8(2)),
log.F("key", uint16(3)),
log.F("key", uint32(4)),
log.F("key", uint64(5)),
log.F("key", true),
log.F("key", struct{ value string }{"struct"}),
},
want: "UTC DEBUG debug key=string key=1 key=2 key=3 key=4 key=5 key=1 key=2 key=3 key=4 key=5 key=true key={struct}",
},
{
lvl: log.TraceLevel,
msg: "trace",
flds: nil,
want: "UTC TRACE trace ",
},
}
}
func (email *Email) handleLog(entries <-chan *log.Entry) {
var e *log.Entry
var s gomail.SendCloser
var err error
var open bool
var alreadyTriedSending bool
var message *gomail.Message
var count uint8
formatter := email.formatFunc(email)
d := gomail.NewDialer(email.host, email.port, email.username, email.password)
for {
select {
case e = <-entries:
count = 0
alreadyTriedSending = false
message = formatter(e)
REOPEN:
// check if smtp connection open
if !open {
count++
if s, err = d.Dial(); err != nil {
log.WithFields(log.F("error", err)).Warn("ERROR connection to smtp server")
if count == 3 {
// we tried to reconnect...
e.Consumed()
break
}
goto REOPEN
}
count = 0
open = true
}
RESEND:
count++
if err = gomail.Send(s, message); err != nil {
log.WithFields(log.F("error", err)).Warn("ERROR sending to smtp server, retrying")
if count == 3 && !alreadyTriedSending {
// maybe we got disconnected...
alreadyTriedSending = true
open = false
s.Close()
goto REOPEN
} else if alreadyTriedSending {
// we reopened and tried 2 more times, can;t say we didn't try
log.WithFields(log.F("error", err)).Alert("ERROR sending log via EMAIL, RETRY and REOPEN failed")
e.Consumed()
break
}
goto RESEND
}
e.Consumed()
case <-time.After(email.keepalive):
if open {
s.Close()
open = false
}
}
}
}
