Skip to content

Commit 49e889e

Browse files
committed
log: logging feature (ethereum#17097)
1 parent 38e5efb commit 49e889e

File tree

4 files changed

+184
-29
lines changed

4 files changed

+184
-29
lines changed

log/format.go

Lines changed: 44 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -77,11 +77,11 @@ type TerminalStringer interface {
7777
// a terminal with color-coded level output and terser human friendly timestamp.
7878
// This format should only be used for interactive programs or while developing.
7979
//
80-
// [TIME] [LEVEL] MESAGE key=value key=value ...
80+
// [LEVEL] [TIME] MESAGE key=value key=value ...
8181
//
8282
// Example:
8383
//
84-
// [May 16 20:58:45] [DBUG] remove route ns=haproxy addr=127.0.0.1:50002
84+
// [DBUG] [May 16 20:58:45] remove route ns=haproxy addr=127.0.0.1:50002
8585
//
8686
func TerminalFormat(usecolor bool) Format {
8787
return FormatFunc(func(r *Record) []byte {
@@ -202,6 +202,48 @@ func JSONFormat() Format {
202202
return JSONFormatEx(false, true)
203203
}
204204

205+
// JSONFormatOrderedEx formats log records as JSON arrays. If pretty is true,
206+
// records will be pretty-printed. If lineSeparated is true, records
207+
// will be logged with a new line between each record.
208+
func JSONFormatOrderedEx(pretty, lineSeparated bool) Format {
209+
jsonMarshal := json.Marshal
210+
if pretty {
211+
jsonMarshal = func(v interface{}) ([]byte, error) {
212+
return json.MarshalIndent(v, "", " ")
213+
}
214+
}
215+
return FormatFunc(func(r *Record) []byte {
216+
props := make(map[string]interface{})
217+
218+
props[r.KeyNames.Time] = r.Time
219+
props[r.KeyNames.Lvl] = r.Lvl.String()
220+
props[r.KeyNames.Msg] = r.Msg
221+
222+
ctx := make([]string, len(r.Ctx))
223+
for i := 0; i < len(r.Ctx); i += 2 {
224+
k, ok := r.Ctx[i].(string)
225+
if !ok {
226+
props[errorKey] = fmt.Sprintf("%+v is not a string key,", r.Ctx[i])
227+
}
228+
ctx[i] = k
229+
ctx[i+1] = formatLogfmtValue(r.Ctx[i+1], true)
230+
}
231+
props[r.KeyNames.Ctx] = ctx
232+
233+
b, err := jsonMarshal(props)
234+
if err != nil {
235+
b, _ = jsonMarshal(map[string]string{
236+
errorKey: err.Error(),
237+
})
238+
return b
239+
}
240+
if lineSeparated {
241+
b = append(b, '\n')
242+
}
243+
return b
244+
})
245+
}
246+
205247
// JSONFormatEx formats log records as JSON objects. If pretty is true,
206248
// records will be pretty-printed. If lineSeparated is true, records
207249
// will be logged with a new line between each record.

log/handler.go

Lines changed: 126 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -3,9 +3,13 @@ package log
33
import (
44
"fmt"
55
"io"
6+
"io/ioutil"
67
"net"
78
"os"
9+
"path/filepath"
810
"reflect"
11+
"regexp"
12+
"strings"
913
"sync"
1014

1115
"github.com/go-stack/stack"
@@ -70,6 +74,111 @@ func FileHandler(path string, fmtr Format) (Handler, error) {
7074
return closingHandler{f, StreamHandler(f, fmtr)}, nil
7175
}
7276

77+
// countingWriter wraps a WriteCloser object in order to count the written bytes.
78+
type countingWriter struct {
79+
w io.WriteCloser // the wrapped object
80+
count uint // number of bytes written
81+
}
82+
83+
// Write increments the byte counter by the number of bytes written.
84+
// Implements the WriteCloser interface.
85+
func (w *countingWriter) Write(p []byte) (n int, err error) {
86+
n, err = w.w.Write(p)
87+
w.count += uint(n)
88+
return n, err
89+
}
90+
91+
// Close implements the WriteCloser interface.
92+
func (w *countingWriter) Close() error {
93+
return w.w.Close()
94+
}
95+
96+
// prepFile opens the log file at the given path, and cuts off the invalid part
97+
// from the end, because the previous execution could have been finished by interruption.
98+
// Assumes that every line ended by '\n' contains a valid log record.
99+
func prepFile(path string) (*countingWriter, error) {
100+
f, err := os.OpenFile(path, os.O_RDWR|os.O_APPEND, 0600)
101+
if err != nil {
102+
return nil, err
103+
}
104+
_, err = f.Seek(-1, io.SeekEnd)
105+
if err != nil {
106+
return nil, err
107+
}
108+
buf := make([]byte, 1)
109+
var cut int64
110+
for {
111+
if _, err := f.Read(buf); err != nil {
112+
return nil, err
113+
}
114+
if buf[0] == '\n' {
115+
break
116+
}
117+
if _, err = f.Seek(-2, io.SeekCurrent); err != nil {
118+
return nil, err
119+
}
120+
cut++
121+
}
122+
fi, err := f.Stat()
123+
if err != nil {
124+
return nil, err
125+
}
126+
ns := fi.Size() - cut
127+
if err = f.Truncate(ns); err != nil {
128+
return nil, err
129+
}
130+
return &countingWriter{w: f, count: uint(ns)}, nil
131+
}
132+
133+
// RotatingFileHandler returns a handler which writes log records to file chunks
134+
// at the given path. When a file's size reaches the limit, the handler creates
135+
// a new file named after the timestamp of the first log record it will contain.
136+
func RotatingFileHandler(path string, limit uint, formatter Format) (Handler, error) {
137+
if err := os.MkdirAll(path, 0700); err != nil {
138+
return nil, err
139+
}
140+
files, err := ioutil.ReadDir(path)
141+
if err != nil {
142+
return nil, err
143+
}
144+
re := regexp.MustCompile(`\.log$`)
145+
last := len(files) - 1
146+
for last >= 0 && (!files[last].Mode().IsRegular() || !re.MatchString(files[last].Name())) {
147+
last--
148+
}
149+
var counter *countingWriter
150+
if last >= 0 && files[last].Size() < int64(limit) {
151+
// Open the last file, and continue to write into it until it's size reaches the limit.
152+
if counter, err = prepFile(filepath.Join(path, files[last].Name())); err != nil {
153+
return nil, err
154+
}
155+
}
156+
if counter == nil {
157+
counter = new(countingWriter)
158+
}
159+
h := StreamHandler(counter, formatter)
160+
161+
return FuncHandler(func(r *Record) error {
162+
if counter.count > limit {
163+
counter.Close()
164+
counter.w = nil
165+
}
166+
if counter.w == nil {
167+
f, err := os.OpenFile(
168+
filepath.Join(path, fmt.Sprintf("%s.log", strings.Replace(r.Time.Format("060102150405.00"), ".", "", 1))),
169+
os.O_CREATE|os.O_APPEND|os.O_WRONLY,
170+
0600,
171+
)
172+
if err != nil {
173+
return err
174+
}
175+
counter.w = f
176+
counter.count = 0
177+
}
178+
return h.Log(r)
179+
}), nil
180+
}
181+
73182
// NetHandler opens a socket to the given address and writes records
74183
// over the connection.
75184
func NetHandler(network, addr string, fmtr Format) (Handler, error) {
@@ -135,15 +244,14 @@ func CallerStackHandler(format string, h Handler) Handler {
135244
// wrapped Handler if the given function evaluates true. For example,
136245
// to only log records where the 'err' key is not nil:
137246
//
138-
// logger.SetHandler(FilterHandler(func(r *Record) bool {
139-
// for i := 0; i < len(r.Ctx); i += 2 {
140-
// if r.Ctx[i] == "err" {
141-
// return r.Ctx[i+1] != nil
142-
// }
143-
// }
144-
// return false
145-
// }, h))
146-
//
247+
// logger.SetHandler(FilterHandler(func(r *Record) bool {
248+
// for i := 0; i < len(r.Ctx); i += 2 {
249+
// if r.Ctx[i] == "err" {
250+
// return r.Ctx[i+1] != nil
251+
// }
252+
// }
253+
// return false
254+
// }, h))
147255
func FilterHandler(fn func(r *Record) bool, h Handler) Handler {
148256
return FuncHandler(func(r *Record) error {
149257
if fn(r) {
@@ -158,8 +266,7 @@ func FilterHandler(fn func(r *Record) bool, h Handler) Handler {
158266
// context matches the value. For example, to only log records
159267
// from your ui package:
160268
//
161-
// log.MatchFilterHandler("pkg", "app/ui", log.StdoutHandler)
162-
//
269+
// log.MatchFilterHandler("pkg", "app/ui", log.StdoutHandler)
163270
func MatchFilterHandler(key string, value interface{}, h Handler) Handler {
164271
return FilterHandler(func(r *Record) (pass bool) {
165272
switch key {
@@ -185,8 +292,7 @@ func MatchFilterHandler(key string, value interface{}, h Handler) Handler {
185292
// level to the wrapped Handler. For example, to only
186293
// log Error/Crit records:
187294
//
188-
// log.LvlFilterHandler(log.LvlError, log.StdoutHandler)
189-
//
295+
// log.LvlFilterHandler(log.LvlError, log.StdoutHandler)
190296
func LvlFilterHandler(maxLvl Lvl, h Handler) Handler {
191297
return FilterHandler(func(r *Record) (pass bool) {
192298
return r.Lvl <= maxLvl
@@ -198,10 +304,9 @@ func LvlFilterHandler(maxLvl Lvl, h Handler) Handler {
198304
// to different locations. For example, to log to a file and
199305
// standard error:
200306
//
201-
// log.MultiHandler(
202-
// log.Must.FileHandler("/var/log/app.log", log.LogfmtFormat()),
203-
// log.StderrHandler)
204-
//
307+
// log.MultiHandler(
308+
// log.Must.FileHandler("/var/log/app.log", log.LogfmtFormat()),
309+
// log.StderrHandler)
205310
func MultiHandler(hs ...Handler) Handler {
206311
return FuncHandler(func(r *Record) error {
207312
for _, h := range hs {
@@ -219,10 +324,10 @@ func MultiHandler(hs ...Handler) Handler {
219324
// to writing to a file if the network fails, and then to
220325
// standard out if the file write fails:
221326
//
222-
// log.FailoverHandler(
223-
// log.Must.NetHandler("tcp", ":9090", log.JSONFormat()),
224-
// log.Must.FileHandler("/var/log/app.log", log.LogfmtFormat()),
225-
// log.StdoutHandler)
327+
// log.FailoverHandler(
328+
// log.Must.NetHandler("tcp", ":9090", log.JSONFormat()),
329+
// log.Must.FileHandler("/var/log/app.log", log.LogfmtFormat()),
330+
// log.StdoutHandler)
226331
//
227332
// All writes that do not go to the first handler will add context with keys of
228333
// the form "failover_err_{idx}" which explain the error encountered while

log/handler_glog.go

Lines changed: 11 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -57,6 +57,11 @@ func NewGlogHandler(h Handler) *GlogHandler {
5757
}
5858
}
5959

60+
// SetHandler updates the handler to write records to the specified sub-handler.
61+
func (h *GlogHandler) SetHandler(nh Handler) {
62+
h.origin = nh
63+
}
64+
6065
// pattern contains a filter for the Vmodule option, holding a verbosity level
6166
// and a file pattern to match.
6267
type pattern struct {
@@ -77,14 +82,14 @@ func (h *GlogHandler) Verbosity(level Lvl) {
7782
//
7883
// For instance:
7984
//
80-
// pattern="gopher.go=3"
81-
// sets the V level to 3 in all Go files named "gopher.go"
85+
// pattern="gopher.go=3"
86+
// sets the V level to 3 in all Go files named "gopher.go"
8287
//
83-
// pattern="foo=3"
84-
// sets V to 3 in all files of any packages whose import path ends in "foo"
88+
// pattern="foo=3"
89+
// sets V to 3 in all files of any packages whose import path ends in "foo"
8590
//
86-
// pattern="foo/*=3"
87-
// sets V to 3 in all files of any packages whose import path contains "foo"
91+
// pattern="foo/*=3"
92+
// sets V to 3 in all files of any packages whose import path contains "foo"
8893
func (h *GlogHandler) Vmodule(ruleset string) error {
8994
var filter []pattern
9095
for _, rule := range strings.Split(ruleset, ",") {

log/logger.go

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ import (
1111
const timeKey = "t"
1212
const lvlKey = "lvl"
1313
const msgKey = "msg"
14+
const ctxKey = "ctx"
1415
const errorKey = "LOG15_ERROR"
1516

1617
type Lvl int
@@ -100,6 +101,7 @@ type RecordKeyNames struct {
100101
Time string
101102
Msg string
102103
Lvl string
104+
Ctx string
103105
}
104106

105107
// A Logger writes key/value pairs to a Handler
@@ -138,6 +140,7 @@ func (l *logger) write(msg string, lvl Lvl, ctx []interface{}) {
138140
Time: timeKey,
139141
Msg: msgKey,
140142
Lvl: lvlKey,
143+
Ctx: ctxKey,
141144
},
142145
})
143146
}

0 commit comments

Comments
 (0)