move to structured logging

This commit is contained in:
Asim Aslam 2019-12-18 16:02:11 +00:00
parent a82af19d43
commit f0e841595c
10 changed files with 102 additions and 71 deletions

View File

@ -24,7 +24,7 @@ func TestKubernetes(t *testing.T) {
meta := make(map[string]string) meta := make(map[string]string)
write := log.Record{ write := log.Record{
Timestamp: time.Unix(0, 0).UTC(), Timestamp: time.Unix(0, 0).UTC(),
Value: "Test log entry", Message: "Test log entry",
Metadata: meta, Metadata: meta,
} }
meta["foo"] = "bar" meta["foo"] = "bar"

View File

@ -25,11 +25,11 @@ type Log interface {
// Record is log record entry // Record is log record entry
type Record struct { type Record struct {
// Timestamp of logged event // Timestamp of logged event
Timestamp time.Time `json:"time"` Timestamp time.Time `json:"timestamp"`
// Value contains log entry
Value interface{} `json:"value"`
// Metadata to enrich log record // Metadata to enrich log record
Metadata map[string]string `json:"metadata"` Metadata map[string]string `json:"metadata"`
// Value contains log entry
Message interface{} `json:"message"`
} }
// Stream returns a log stream // Stream returns a log stream

View File

@ -35,7 +35,7 @@ func NewLog(opts ...log.Option) log.Log {
// Write writes logs into logger // Write writes logs into logger
func (l *memoryLog) Write(r log.Record) error { func (l *memoryLog) Write(r log.Record) error {
l.Buffer.Put(fmt.Sprint(r.Value)) l.Buffer.Put(fmt.Sprint(r.Message))
return nil return nil
} }
@ -74,7 +74,7 @@ func (l *memoryLog) Read(opts ...log.ReadOption) ([]log.Record, error) {
for _, entry := range entries { for _, entry := range entries {
record := log.Record{ record := log.Record{
Timestamp: entry.Timestamp, Timestamp: entry.Timestamp,
Value: entry.Value, Message: entry.Value,
} }
records = append(records, record) records = append(records, record)
} }
@ -98,7 +98,7 @@ func (l *memoryLog) Stream() (log.Stream, error) {
for _, entry := range last10 { for _, entry := range last10 {
records <- log.Record{ records <- log.Record{
Timestamp: entry.Timestamp, Timestamp: entry.Timestamp,
Value: entry.Value, Message: entry.Value,
Metadata: make(map[string]string), Metadata: make(map[string]string),
} }
} }
@ -106,7 +106,7 @@ func (l *memoryLog) Stream() (log.Stream, error) {
for entry := range stream { for entry := range stream {
records <- log.Record{ records <- log.Record{
Timestamp: entry.Timestamp, Timestamp: entry.Timestamp,
Value: entry.Value, Message: entry.Value,
Metadata: make(map[string]string), Metadata: make(map[string]string),
} }
} }

View File

@ -18,15 +18,15 @@ func TestLogger(t *testing.T) {
} }
// Log some cruft // Log some cruft
lg.Write(log.Record{Value: "foobar"}) lg.Write(log.Record{Message: "foobar"})
lg.Write(log.Record{Value: "foo bar"}) lg.Write(log.Record{Message: "foo bar"})
// Check if the logs are stored in the logger ring buffer // Check if the logs are stored in the logger ring buffer
expected := []string{"foobar", "foo bar"} expected := []string{"foobar", "foo bar"}
entries, _ := lg.Read(log.Count(len(expected))) entries, _ := lg.Read(log.Count(len(expected)))
for i, entry := range entries { for i, entry := range entries {
if !reflect.DeepEqual(entry.Value, expected[i]) { if !reflect.DeepEqual(entry.Message, expected[i]) {
t.Errorf("expected %s, got %s", expected[i], entry.Value) t.Errorf("expected %s, got %s", expected[i], entry.Message)
} }
} }
} }

View File

@ -87,7 +87,7 @@ func (o *osLog) run() {
} else { } else {
r = Record{ r = Record{
Timestamp: time.Now(), Timestamp: time.Now(),
Value: strings.TrimSuffix(line, "\n"), Message: strings.TrimSuffix(line, "\n"),
Metadata: make(map[string]string), Metadata: make(map[string]string),
} }
} }
@ -125,7 +125,7 @@ func (o *osLog) Read(...ReadOption) ([]Record, error) {
// Write writes records to log // Write writes records to log
func (o *osLog) Write(r Record) error { func (o *osLog) Write(r Record) error {
b, _ := json.Marshal(r) b, _ := json.Marshal(r)
_, err := os.Stderr.Write(b) _, err := os.Stderr.Write(append(b, byte('\n')))
return err return err
} }

View File

@ -65,7 +65,7 @@ func (d *debugClient) streamLogs(lg *logStream, stream pb.Debug_LogService) {
record := log.Record{ record := log.Record{
Timestamp: time.Unix(resp.Timestamp, 0), Timestamp: time.Unix(resp.Timestamp, 0),
Value: resp.Value, Message: resp.Message,
Metadata: metadata, Metadata: metadata,
} }

View File

@ -111,7 +111,7 @@ func (d *Debug) sendRecord(record log.Record, stream server.Stream) error {
return stream.Send(&proto.Record{ return stream.Send(&proto.Record{
Timestamp: record.Timestamp.Unix(), Timestamp: record.Timestamp.Unix(),
Value: record.Value.(string), Message: record.Message.(string),
Metadata: metadata, Metadata: metadata,
}) })
} }

View File

@ -299,10 +299,10 @@ func (m *LogRequest) GetSince() int64 {
type Record struct { type Record struct {
// timestamp of log record // timestamp of log record
Timestamp int64 `protobuf:"varint,1,opt,name=timestamp,proto3" json:"timestamp,omitempty"` Timestamp int64 `protobuf:"varint,1,opt,name=timestamp,proto3" json:"timestamp,omitempty"`
// record value
Value string `protobuf:"bytes,2,opt,name=value,proto3" json:"value,omitempty"`
// record metadata // record metadata
Metadata map[string]string `protobuf:"bytes,3,rep,name=metadata,proto3" json:"metadata,omitempty" protobuf_key:"bytes,1,opt,name=key,proto3" protobuf_val:"bytes,2,opt,name=value,proto3"` Metadata map[string]string `protobuf:"bytes,2,rep,name=metadata,proto3" json:"metadata,omitempty" protobuf_key:"bytes,1,opt,name=key,proto3" protobuf_val:"bytes,2,opt,name=value,proto3"`
// message
Message string `protobuf:"bytes,3,opt,name=message,proto3" json:"message,omitempty"`
XXX_NoUnkeyedLiteral struct{} `json:"-"` XXX_NoUnkeyedLiteral struct{} `json:"-"`
XXX_unrecognized []byte `json:"-"` XXX_unrecognized []byte `json:"-"`
XXX_sizecache int32 `json:"-"` XXX_sizecache int32 `json:"-"`
@ -340,13 +340,6 @@ func (m *Record) GetTimestamp() int64 {
return 0 return 0
} }
func (m *Record) GetValue() string {
if m != nil {
return m.Value
}
return ""
}
func (m *Record) GetMetadata() map[string]string { func (m *Record) GetMetadata() map[string]string {
if m != nil { if m != nil {
return m.Metadata return m.Metadata
@ -354,6 +347,13 @@ func (m *Record) GetMetadata() map[string]string {
return nil return nil
} }
func (m *Record) GetMessage() string {
if m != nil {
return m.Message
}
return ""
}
func init() { func init() {
proto.RegisterType((*HealthRequest)(nil), "HealthRequest") proto.RegisterType((*HealthRequest)(nil), "HealthRequest")
proto.RegisterType((*HealthResponse)(nil), "HealthResponse") proto.RegisterType((*HealthResponse)(nil), "HealthResponse")
@ -369,30 +369,31 @@ func init() {
} }
var fileDescriptor_dea322649cde1ef2 = []byte{ var fileDescriptor_dea322649cde1ef2 = []byte{
// 399 bytes of a gzipped FileDescriptorProto // 407 bytes of a gzipped FileDescriptorProto
0x1f, 0x8b, 0x08, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0xff, 0x84, 0x52, 0xc1, 0x6e, 0xd4, 0x30, 0x1f, 0x8b, 0x08, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0xff, 0x84, 0x92, 0xcf, 0x6e, 0x13, 0x31,
0x10, 0xdd, 0xac, 0x9b, 0xb4, 0x3b, 0x65, 0x17, 0x64, 0x15, 0x64, 0xad, 0x90, 0xa8, 0x7c, 0x0a, 0x10, 0xc6, 0xb3, 0xbb, 0xcd, 0xb6, 0x99, 0x92, 0x80, 0x2c, 0x40, 0x56, 0x84, 0x44, 0xe5, 0xd3,
0x42, 0x78, 0xa1, 0x5c, 0x10, 0x5c, 0x41, 0xe2, 0x50, 0x2e, 0xe6, 0x0b, 0xdc, 0x64, 0x94, 0x2e, 0x22, 0x84, 0x03, 0xe5, 0x82, 0xe0, 0x0a, 0x12, 0x87, 0x72, 0x31, 0x4f, 0xe0, 0xee, 0x8e, 0xb6,
0x34, 0x71, 0xb0, 0x27, 0x95, 0xf6, 0xc4, 0xb7, 0x70, 0xe7, 0x23, 0x51, 0x6c, 0x2f, 0x6d, 0x44, 0x81, 0x3a, 0x0e, 0xf6, 0x6c, 0xa5, 0x9c, 0x78, 0x16, 0xde, 0x80, 0x47, 0x44, 0xfe, 0xb3, 0xb4,
0xa5, 0xbd, 0xcd, 0x7b, 0xf3, 0xf4, 0x3c, 0x33, 0x7e, 0xa0, 0xda, 0x6d, 0xe5, 0xec, 0xa6, 0xb1, 0xab, 0x1e, 0x7a, 0xf3, 0xef, 0xf3, 0xe7, 0xd1, 0xcc, 0xf8, 0x03, 0x69, 0xb6, 0xad, 0xb3, 0x9b,
0xaf, 0x63, 0x51, 0xe3, 0xd5, 0xd0, 0x6c, 0x3c, 0xba, 0xdb, 0x6d, 0x85, 0x9b, 0xde, 0x59, 0x4a, 0xde, 0xbe, 0x49, 0x87, 0x0e, 0x2f, 0x87, 0x7e, 0xe3, 0xd1, 0xdd, 0x6c, 0x5b, 0xdc, 0xec, 0x9d,
0x9c, 0x0a, 0xb5, 0x7c, 0x09, 0xcb, 0x2f, 0x68, 0x6e, 0xe8, 0x5a, 0xe3, 0xcf, 0x01, 0x3d, 0x71, 0xa5, 0xac, 0xc9, 0x78, 0x16, 0xaf, 0x60, 0xf9, 0x15, 0xf5, 0x35, 0x5d, 0x29, 0xfc, 0x35, 0xa0,
0x01, 0xc7, 0x49, 0x2d, 0xb2, 0xf3, 0xac, 0x5c, 0xe8, 0x3d, 0x94, 0x25, 0xac, 0xf6, 0x52, 0xdf, 0x27, 0xc6, 0xe1, 0x38, 0xbb, 0x79, 0x71, 0x56, 0x34, 0x0b, 0x35, 0xa2, 0x68, 0x60, 0x35, 0x5a,
0xdb, 0xce, 0x23, 0x7f, 0x06, 0x85, 0x27, 0x43, 0x83, 0x4f, 0xd2, 0x84, 0x64, 0x09, 0x8f, 0xbe, 0xfd, 0xde, 0xee, 0x3c, 0xb2, 0xe7, 0x50, 0x7b, 0xd2, 0x34, 0xf8, 0x6c, 0xcd, 0x24, 0x1a, 0x78,
0x91, 0x21, 0x7f, 0xd8, 0xf3, 0x77, 0x06, 0xcb, 0x24, 0x4d, 0x9e, 0xcf, 0x61, 0x41, 0xdb, 0x16, 0xf4, 0x9d, 0x34, 0xf9, 0x87, 0x6b, 0xfe, 0x29, 0x60, 0x99, 0xad, 0xb9, 0xe6, 0x0b, 0x58, 0xd0,
0x3d, 0x99, 0xb6, 0x0f, 0xea, 0x23, 0x7d, 0x47, 0x04, 0x27, 0x32, 0x8e, 0xb0, 0x16, 0xf3, 0xd0, 0xd6, 0xa0, 0x27, 0x6d, 0xf6, 0xd1, 0x7d, 0xa4, 0x6e, 0x85, 0x58, 0x89, 0xb4, 0x23, 0xec, 0x78,
0xdb, 0xc3, 0x71, 0x96, 0xa1, 0x1f, 0x85, 0x82, 0x85, 0x46, 0x42, 0x23, 0xdf, 0x62, 0x6b, 0xdd, 0x19, 0xef, 0x46, 0x0c, 0xbd, 0x0c, 0xfb, 0x60, 0xe4, 0x55, 0xbc, 0xc8, 0x14, 0x74, 0x83, 0xc6,
0x4e, 0x1c, 0x45, 0x3e, 0xa2, 0xd1, 0x89, 0xae, 0x1d, 0x9a, 0xda, 0x8b, 0x3c, 0x3a, 0x25, 0xc8, 0xba, 0x03, 0x3f, 0x4a, 0x7a, 0xa2, 0x50, 0x89, 0xae, 0x1c, 0xea, 0xce, 0xf3, 0x79, 0xaa, 0x94,
0x57, 0x30, 0x6f, 0x2a, 0x51, 0x04, 0x72, 0xde, 0x54, 0xf2, 0x3b, 0xc0, 0xa5, 0x6d, 0x0e, 0xee, 0x91, 0xad, 0xa0, 0xec, 0x5b, 0x5e, 0x47, 0xb1, 0xec, 0x5b, 0xf1, 0x03, 0xe0, 0xc2, 0xf6, 0x0f,
0x12, 0xaf, 0xe1, 0xd0, 0xb4, 0x61, 0xb4, 0x13, 0x9d, 0x10, 0x3f, 0x83, 0xbc, 0xb2, 0x43, 0x47, 0xce, 0x92, 0xb6, 0xe1, 0x50, 0x9b, 0xd8, 0xda, 0x89, 0xca, 0xc4, 0x9e, 0xc2, 0xbc, 0xb5, 0xc3,
0x61, 0x30, 0xa6, 0x23, 0x18, 0x59, 0xbf, 0xed, 0x2a, 0x0c, 0x63, 0x31, 0x1d, 0x81, 0xfc, 0x93, 0x8e, 0x62, 0x63, 0x95, 0x4a, 0x10, 0x54, 0xbf, 0xdd, 0xb5, 0x18, 0xdb, 0xaa, 0x54, 0x02, 0xf1,
0x41, 0xa1, 0xb1, 0xb2, 0xae, 0xfe, 0xff, 0x10, 0xec, 0xfe, 0x21, 0xce, 0x20, 0xbf, 0x35, 0x37, 0xb7, 0x80, 0x5a, 0x61, 0x6b, 0x5d, 0x77, 0x7f, 0x11, 0xd5, 0xdd, 0x45, 0xbc, 0x83, 0x13, 0x83,
0x03, 0x86, 0xb7, 0x16, 0x3a, 0x02, 0xfe, 0x16, 0x4e, 0x5a, 0x24, 0x53, 0x1b, 0x32, 0x82, 0x9d, 0xa4, 0x3b, 0x4d, 0x9a, 0x97, 0x67, 0x55, 0x73, 0x7a, 0xfe, 0x4c, 0xa6, 0x87, 0xf2, 0x5b, 0xd6,
0xb3, 0xf2, 0xf4, 0xe2, 0xa9, 0x8a, 0x76, 0xea, 0x6b, 0xe2, 0x3f, 0x77, 0xe4, 0x76, 0xfa, 0x9f, 0xbf, 0xec, 0xc8, 0x1d, 0xd4, 0x7f, 0x5b, 0xe8, 0xdc, 0xa0, 0xf7, 0xba, 0x4f, 0x2b, 0x5a, 0xa8,
0x6c, 0xfd, 0x11, 0x96, 0x93, 0x16, 0x7f, 0x02, 0xec, 0x07, 0xee, 0xd2, 0x72, 0x63, 0xf9, 0xf0, 0x11, 0xd7, 0x9f, 0x60, 0x39, 0x79, 0xc4, 0x9e, 0x40, 0xf5, 0x13, 0x0f, 0x79, 0xc0, 0x70, 0x0c,
0x5b, 0x1f, 0xe6, 0xef, 0xb3, 0x8b, 0x5f, 0x90, 0x7f, 0x1a, 0xc3, 0xc4, 0x5f, 0x41, 0x11, 0xb3, 0xed, 0xde, 0xe8, 0xeb, 0x01, 0xe3, 0x6c, 0x0b, 0x95, 0xe0, 0x63, 0xf9, 0xa1, 0x38, 0xff, 0x0d,
0xc1, 0x57, 0x6a, 0x92, 0xa7, 0xf5, 0x63, 0x35, 0x0d, 0x8d, 0x9c, 0xf1, 0x12, 0xf2, 0xf0, 0xe7, 0xf3, 0xcf, 0x21, 0x50, 0xec, 0x35, 0xd4, 0x29, 0x1f, 0x6c, 0x25, 0x27, 0x99, 0x5a, 0x3f, 0x96,
0x7c, 0xa9, 0xee, 0xc7, 0x64, 0xbd, 0x52, 0x93, 0x28, 0xc8, 0x19, 0x7f, 0x01, 0xec, 0xd2, 0x36, 0xd3, 0xe0, 0x88, 0x19, 0x6b, 0x60, 0x1e, 0xff, 0x9d, 0x2d, 0xe5, 0xdd, 0xa8, 0xac, 0x57, 0x72,
0xfc, 0x54, 0xdd, 0x7d, 0xc0, 0xfa, 0x38, 0x6d, 0x24, 0x67, 0x6f, 0xb2, 0xab, 0x22, 0xa4, 0xf8, 0x12, 0x07, 0x31, 0x63, 0x2f, 0xa1, 0xba, 0xb0, 0x3d, 0x3b, 0x95, 0xb7, 0x9f, 0xb0, 0x3e, 0xce,
0xdd, 0xdf, 0x00, 0x00, 0x00, 0xff, 0xff, 0xea, 0xdf, 0xa5, 0x1d, 0xf7, 0x02, 0x00, 0x00, 0xb3, 0x8a, 0xd9, 0xdb, 0xe2, 0xb2, 0x8e, 0x49, 0x7e, 0xff, 0x2f, 0x00, 0x00, 0xff, 0xff, 0x4e,
0xd3, 0x4c, 0xce, 0xfb, 0x02, 0x00, 0x00,
} }

View File

@ -54,8 +54,8 @@ message LogRequest {
message Record { message Record {
// timestamp of log record // timestamp of log record
int64 timestamp = 1; int64 timestamp = 1;
// record value
string value = 2;
// record metadata // record metadata
map<string,string> metadata = 3; map<string,string> metadata = 2;
// message
string message = 3;
} }

View File

@ -4,9 +4,9 @@ package log
import ( import (
"fmt" "fmt"
"os" "os"
"time"
"github.com/go-log/log" "github.com/micro/go-micro/debug/log"
golog "github.com/go-log/log/log"
) )
// level is a log level // level is a log level
@ -23,7 +23,7 @@ const (
var ( var (
// the local logger // the local logger
logger log.Logger = golog.New() logger log.Log = log.DefaultLog
// default log level is info // default log level is info
level = LevelInfo level = LevelInfo
@ -49,21 +49,51 @@ func init() {
} }
} }
// Log makes use of github.com/go-log/log.Log func (l Level) String() string {
func Log(v ...interface{}) { switch l {
if len(prefix) > 0 { case LevelTrace:
logger.Log(append([]interface{}{prefix, " "}, v...)...) return "trace"
return case LevelDebug:
return "debug"
case LevelWarn:
return "warn"
case LevelInfo:
return "info"
case LevelError:
return "error"
case LevelFatal:
return "fatal"
default:
return "unknown"
} }
logger.Log(v...)
} }
// Logf makes use of github.com/go-log/log.Logf // Log makes use of github.com/micro/debug/log
func Log(v ...interface{}) {
if len(prefix) > 0 {
v = append([]interface{}{prefix, " "}, v...)
}
logger.Write(log.Record{
Timestamp: time.Now(),
Message: fmt.Sprint(v...),
Metadata: map[string]string{
"level": level.String(),
},
})
}
// Logf makes use of github.com/micro/debug/log
func Logf(format string, v ...interface{}) { func Logf(format string, v ...interface{}) {
if len(prefix) > 0 { if len(prefix) > 0 {
format = prefix + " " + format format = prefix + " " + format
} }
logger.Logf(format, v...) logger.Write(log.Record{
Timestamp: time.Now(),
Message: fmt.Sprintf(format, v...),
Metadata: map[string]string{
"level": level.String(),
},
})
} }
// WithLevel logs with the level specified // WithLevel logs with the level specified
@ -145,12 +175,12 @@ func Fatalf(format string, v ...interface{}) {
} }
// SetLogger sets the local logger // SetLogger sets the local logger
func SetLogger(l log.Logger) { func SetLogger(l log.Log) {
logger = l logger = l
} }
// GetLogger returns the local logger // GetLogger returns the local logger
func GetLogger() log.Logger { func GetLogger() log.Log {
return logger return logger
} }