Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Configurable depth #2

Merged
merged 3 commits into from
Oct 7, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 16 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,20 @@ requestLogger := logger.WithFields(nacelle.LogFields{
requestLogger.Info("Accepted request from %s", remoteAddr)
```

### Caller Stack

Sometimes it is useful to define helper functions that logs messages for you in a common way (applying common context, performing additional behavior on errors, etc). Unfortunately, this can interfere with the way the caller file and line number are discovered. The logger has a `WithIndirectCaller` method that will increase the depth used when scanning the stack for callers. This should be used at each log location that aggregates log calls (e.g. any place where knowing this source location would not be helpful).

```go
func logForMe(message string) {
parentLogger.WithIndirectCaller(1).Log(message)
}

logForMe("foobar")
```

Using a logger instance directly does not require this additional hint.

### Adapters

Nacelle ships with a handful of useful logging adapters. These are extensions of the logger interface that add additional behavior or additional structured data. A custom adapter can be created for behavior that is not provided here.
Expand Down Expand Up @@ -59,7 +73,7 @@ logger := NewRollupAdapter(
time.Second, // rollup window
)

for i:=0; i < 10000; i++ {
for i := 0; i < 10000; i++ {
logger.Debug("Some problem here!")
}
```
Expand All @@ -71,6 +85,7 @@ The following environment variables change the behavior of the loggers when usin
| Environment Variable | Default | Description |
| ---------------------------- | ------- | ----------- |
| LOG_COLORIZE | true | Colorize log messages by level when true. Works with `console` encoding only. |
| LOG_JSON_FIELD_NAMES | | A JSON-encoded map to rename the fields for `message`, `timestamp`, and/or `level`. |
| LOG_DISPLAY_FIELDS | true | Omit log fields from output when false. Works with `console` encoding only. |
| LOG_DISPLAY_MULTILINE_FIELDS | false | Print fields on one line when true, one field per line when false. Works with `console` encoding only. |
| LOG_ENCODING | console | `console` for human-readable output and `json` for JSON-formatted output. |
Expand Down
2 changes: 1 addition & 1 deletion base_logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ func (s *baseShim) LogWithFields(level LogLevel, fields LogFields, format string
}

seq := atomic.AddUint64(&s.wrapper.sequence, 1)
fields = addCaller(fields).normalizeTimeValues()
fields = fields.normalizeTimeValues()
fields["sequenceNumber"] = seq

s.wrapper.logger.Log(
Expand Down
2 changes: 1 addition & 1 deletion base_logger_mock_test.go

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

8 changes: 4 additions & 4 deletions caller.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,20 +6,20 @@ import (
"strings"
)

func addCaller(fields LogFields) LogFields {
func addCaller(fields LogFields, depth int) LogFields {
if fields == nil {
fields = LogFields{}
}

if _, ok := fields["caller"]; !ok {
fields["caller"] = getCaller()
fields["caller"] = getCaller(depth)
}

return fields
}

func getCaller() string {
for i := 3; ; i++ {
func getCaller(depth int) string {
for i := 3 + depth; ; i++ {
_, file, line, _ := runtime.Caller(i)
if file == "<autogenerated>" {
continue
Expand Down
41 changes: 41 additions & 0 deletions caller_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,46 @@ func (s *CallerSuite) testRollup(init func(*Config) (Logger, error)) {
Expect(data2["caller"]).To(Equal(fmt.Sprintf("log/caller_test.go:%d", start)))
}

func (s *CallerSuite) testAdapter(init func(*Config) (Logger, error)) {
stderr := captureStderr(func() {
logger, err := init(&Config{LogLevel: "info", LogEncoding: "json"})
Expect(err).To(BeNil())
// Push caller stack out once for each indirection
indirectLogger := logger.WithIndirectCaller(3)

log3 := func(message string) { indirectLogger.Info(message) }
log2 := func(message string) { log3(message) }
log1 := func(message string) { log2(message) }

log1("X")
log1("Y")
log1("Z")
logger.Sync()
})

lines := strings.Split(strings.TrimSpace(stderr), "\n")
Expect(lines).To(HaveLen(3))

var (
data1 = LogFields{}
data2 = LogFields{}
data3 = LogFields{}
)

Expect(json.Unmarshal([]byte(lines[0]), &data1)).To(BeNil())
Expect(json.Unmarshal([]byte(lines[1]), &data2)).To(BeNil())
Expect(json.Unmarshal([]byte(lines[2]), &data3)).To(BeNil())

// Note: this value refers to the line number containing `logger.Info("X")` in
// the function literal above. If code is added before that line, this value
// must be updated.
start := 140

Expect(data1["caller"]).To(Equal(fmt.Sprintf("log/caller_test.go:%d", start+0)))
Expect(data2["caller"]).To(Equal(fmt.Sprintf("log/caller_test.go:%d", start+1)))
Expect(data3["caller"]).To(Equal(fmt.Sprintf("log/caller_test.go:%d", start+2)))
}

func (s *CallerSuite) testFields(init func(*Config) (Logger, error)) {
s.testBasic(func(config *Config) (Logger, error) {
logger, err := init(config)
Expand Down Expand Up @@ -172,6 +212,7 @@ func (s *CallerSuite) TestTrimPath(t sweet.T) {
}

func (s *CallerSuite) TestLogger(t sweet.T) { s.testBasic(InitLogger) }
func (s *CallerSuite) TestAdapter(t sweet.T) { s.testAdapter(InitLogger) }
func (s *CallerSuite) TestLoggerWithFields(t sweet.T) { s.testFields(InitLogger) }
func (s *CallerSuite) TestLoggerWithReplayAdapter(t sweet.T) { s.testReplayAdapter(InitLogger) }
func (s *CallerSuite) TestLoggerWithRollupAdapter(t sweet.T) { s.testRollupAdapter(InitLogger) }
Expand Down
2 changes: 1 addition & 1 deletion config.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ type Config struct {
LogLevel string `env:"log_level" file:"log_level" default:"info"`
LogEncoding string `env:"log_encoding" file:"log_encoding" default:"console"`
LogColorize bool `env:"log_colorize" file:"log_colorize" default:"true"`
LogJSONFieldNames map[string]string `env:"log_json_field_names" file:"log_json_field_names"` // TODO - not in config
LogJSONFieldNames map[string]string `env:"log_json_field_names" file:"log_json_field_names"`
LogInitialFields LogFields `env:"log_fields" file:"log_fields"`
LogShortTime bool `env:"log_short_time" file:"log_short_time" default:"false"`
LogDisplayFields bool `env:"log_display_fields" file:"log_display_fields" default:"true"`
Expand Down
1 change: 1 addition & 0 deletions logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ package log

type (
Logger interface {
WithIndirectCaller(frames int) Logger
WithFields(LogFields) Logger
LogWithFields(LogLevel, LogFields, string, ...interface{})
Sync() error
Expand Down
2 changes: 1 addition & 1 deletion main_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -57,7 +57,7 @@ func (ts *testShim) LogWithFields(level LogLevel, fields LogFields, format strin

ts.messages = append(ts.messages, &logMessage{
level: level,
fields: addCaller(fields),
fields: fields,
format: format,
args: args,
})
Expand Down
Loading