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

Initial commit #1

Merged
merged 19 commits into from
Mar 10, 2014
Merged
110 changes: 59 additions & 51 deletions README.md
Original file line number Diff line number Diff line change
@@ -1,67 +1,75 @@
# Logrus

Logrus is a simple, opinionated logging package for Go. It has three debugging
levels:
Logrus is a simple, opinionated logging package for Go. Features include:

* `LevelDebug`: Debugging, usually turned off for deploys.
* `LevelInfo`: Info, useful for monitoring in production.
* `LevelWarning`: Warnings that should definitely be noted. These are sent to
`airbrake`.
* `LevelFatal`: Fatal messages that causes the application to crash. These are
sent to `airbrake`.
* **Level logging**. Logrus has the levels: Debug, Info, Warning and Fatal.
* **Exceptions**. Warnings will log as an exception along with logging it to
out, without quitting. Fatal will do the same, but call `os.Exit(1)` after
emitting the exception.
* **JSON**. Logrus currently logs as JSON by default.

## Usage
The API is completely compatible with the Go standard lib logger, with only the
features above added.

The global logging level is set by: `logrus.Level = logrus.{LevelDebug,LevelWarning,LevelFatal}`.
## Motivation

Note that for `airbrake` to work, `airbrake.Endpoint` and `airbrake.ApiKey`
should be set.

There is a global logger, which new loggers inherit their settings from when
created (see example below), such as the place to redirect output. Logging can
be done with the global logging module:
The motivation for this library came out of a pattern seen in Go applications me
and others have been writing with functions such as:

```go
logrus.Debug("Something debugworthy happened: %s", importantStuff)
logrus.Info("Something infoworthy happened: %s", importantStuff)

logrus.Warning("Something bad happened: %s", importantStuff)
// Reports to Airbrake

logrus.Fatal("Something fatal happened: %s", importantStuff)
// Reports to Airbrake
// Then exits
```

Types are encouraged to include their own logging object. This allows to set a
context dependent prefix to know where a certain message is coming from, without
cluttering every single message with this.

```go
type Walrus struct {
TuskSize uint64
Sex bool
logger logrus.Logger
func reportFatalError(err error) {
airbrake.Notify(err)
log.Fatal(err)
}

func NewWalrus(tuskSize uint64, sex bool) *Walrus {
return &Walrus{
TuskSize: tuskSize,
Sex: bool,
logger: logrus.NewLogger("Walrus"),
}
func reportWarning(err error) {
airbrake.Notify(err)
}
```

func (walrus *Walrus) Mate(partner *Walrus) error {
if walrus.Sex == partner.Sex {
return errors.New("Incompatible mating partner.")
}

walrus.logger.Info("Walrus with tusk sizes %d and %d are mating!", walrus.TuskSize, partner.TuskSize)
// Generates a logging message: <timestamp> [Info] [Walrus] Walrus with tusk sizes <int> and <int> are mating!
JSON logging is excellent for parsing logs for analysis and troubleshooting.
It's supported natively by log aggregators such as logstash and Splunk. Logging
JSON with logrus with the `WithFields` and `WithField` API in logrus forces you
to think about what context to log, to provide valuable troubleshoot information
later.

// Walrus mating happens here
## Example

return nil
```go
import (
"github.com/Sirupsen/logrus"
)

var logger logrus.New()
func main() {
logger.WithFields(Fields{
"animal": "walrus",
"location": "New York Aquarium",
"weather": "rain",
"name": "Wally",
"event": "escape",
}).Info("Walrus has escaped the aquarium! Action required!")
// {
// "level": "info",
// "animal": "walrus",
// "location": "New York Aquarium",
// "weather":"rain",
// "name": "Wally",
// "event":"escape",
// "msg": "Walrus has escaped the aquarium! Action required!")
// "time": "2014-02-23 19:57:35.862271048 -0500 EST"
// }

logger.WithField("source", "kafka").Infof("Connection to Kafka failed with %s", "some error")
// {
// "level": "info",
// "source": "kafka",
// "msg": "Connection to Kafka failed with some error",
// "time": "2014-02-23 19:57:35.862271048 -0500 EST"
// }
}
```

Using `Warning` and `Fatal` to log to `airbrake` requires setting
`airbrake.Endpoint` and `airbrake.ApiKey`. See
[tobi/airbrake-go](https://github.com/tobi/airbrake-go).
198 changes: 198 additions & 0 deletions entry.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,198 @@
package logrus

import (
"bytes"
"encoding/json"
"errors"
"fmt"
"io"
"os"
"time"

"github.com/tobi/airbrake-go"
)

type Entry struct {
logger *Logger
Data Fields
}

func NewEntry(logger *Logger) *Entry {
return &Entry{
logger: logger,
// Default is three fields, give a little extra room. Shouldn't hurt the
// scale.
Data: make(Fields, 5),
}
}

// TODO: Other formats?
func (entry *Entry) Reader() (*bytes.Buffer, error) {
var serialized []byte
var err error

if Environment == "production" {
serialized, err = json.Marshal(entry.Data)
} else {
// TODO: Pretty-print more by coloring when stdout is a tty
serialized, err = json.MarshalIndent(entry.Data, "", " ")
}

if err != nil {
return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
}

serialized = append(serialized, '\n')

return bytes.NewBuffer(serialized), nil
}

func (entry *Entry) WithField(key string, value interface{}) *Entry {
entry.Data[key] = value
return entry
}

func (entry *Entry) WithFields(fields Fields) *Entry {
for key, value := range fields {
entry.WithField(key, value)
}

return entry
}

func (entry *Entry) log(level string, msg string) string {
// TODO: Is the default format output from String() the one we want?
entry.Data["time"] = time.Now().String()
entry.Data["level"] = level
// TODO: Is this the best name?
entry.Data["msg"] = msg

reader, err := entry.Reader()
if err != nil {
// TODO: Panic?
entry.logger.Panicf("Failed to obtain reader, %v", err)
}

// Send HTTP request in a goroutine in warning environment to not halt the
// main thread. It's sent before logging due to panic.
if level == "warning" {
// TODO: new() should spawn an airbrake goroutine and this should send to
// that channel. This prevent us from spawning hundreds of goroutines in a
// hot code path generating a warning.
go entry.airbrake(reader.String())
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it almost feels like you should have an airbrake goroutine always reading from a channel, when 💩 hits the fan this will happen a lot

Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Look a few lines up Camilobabes. There's a comment saying exactly this :)

} else if level == "fatal" || level == "panic" {
entry.airbrake(reader.String())
}

entry.logger.mu.Lock()
defer entry.logger.mu.Unlock()

_, err = io.Copy(entry.logger.Out, reader)
// TODO: Panic?
if err != nil {
entry.logger.Panicln("Failed to log message, %v", err)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A logger should probs try not to panic ever

}

return reader.String()
}

func (entry *Entry) Debug(args ...interface{}) {
if Level >= LevelDebug {
entry.log("debug", fmt.Sprint(args...))
}
}

func (entry *Entry) Info(args ...interface{}) {
if Level >= LevelInfo {
entry.log("info", fmt.Sprint(args...))
}
}

func (entry *Entry) Print(args ...interface{}) {
if Level >= LevelInfo {
entry.log("info", fmt.Sprint(args...))
}
}

func (entry *Entry) Warning(args ...interface{}) {
if Level >= LevelWarning {
entry.log("warning", fmt.Sprint(args...))
}
}

func (entry *Entry) Fatal(args ...interface{}) {
if Level >= LevelFatal {
entry.log("fatal", fmt.Sprint(args...))
}
os.Exit(1)
}

func (entry *Entry) Panic(args ...interface{}) {
if Level >= LevelPanic {
msg = entry.log("panic", fmt.Sprint(args...))
panic(msg)
}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the case of Fatal (line 127), you call os.Exit(1) invariably of the log level. In the case of Panic, you panic(...) only if the log level is great enough (line 87). I think both should behave the same.

panic(fmt.Sprint(args...))
}

// Entry Printf family functions

func (entry *Entry) Debugf(format string, args ...interface{}) {
entry.Debug(fmt.Sprintf(format, args...))
}

func (entry *Entry) Infof(format string, args ...interface{}) {
entry.Info(fmt.Sprintf(format, args...))
}

func (entry *Entry) Printf(format string, args ...interface{}) {
entry.Print(fmt.Sprintf(format, args...))
}

func (entry *Entry) Warningf(format string, args ...interface{}) {
entry.Warning(fmt.Sprintf(format, args...))
}

func (entry *Entry) Fatalf(format string, args ...interface{}) {
entry.Fatal(fmt.Sprintf(format, args...))
}

func (entry *Entry) Panicf(format string, args ...interface{}) {
entry.Panic(fmt.Sprintf(format, args...))
}

// Entry Println family functions

func (entry *Entry) Debugln(args ...interface{}) {
entry.Debug(fmt.Sprintln(args...))
}

func (entry *Entry) Infoln(args ...interface{}) {
entry.Info(fmt.Sprintln(args...))
}

func (entry *Entry) Println(args ...interface{}) {
entry.Print(fmt.Sprintln(args...))
}

func (entry *Entry) Warningln(args ...interface{}) {
entry.Warning(fmt.Sprintln(args...))
}

func (entry *Entry) Fatalln(args ...interface{}) {
entry.Fatal(fmt.Sprintln(args...))
}

func (entry *Entry) Panicln(args ...interface{}) {
entry.Panic(fmt.Sprintln(args...))
}

func (entry *Entry) airbrake(exception string) {
err := airbrake.Notify(errors.New(exception))
if err != nil {
entry.logger.WithFields(Fields{
"source": "airbrake",
"endpoint": airbrake.Endpoint,
}).Infof("Failed to send exception to Airbrake")
}
}
63 changes: 63 additions & 0 deletions examples_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,63 @@
package logrus

import (
"github.com/tobi/airbrake-go"
)

func ExampleLogger_Info() {
logger := New()
logger.Info("Simple logging call, compatible with the standard logger")
// {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The first line of the comment in examples must be:

// Output:

I've changed that locally and the examples fail because of various formatting differences, ordering of the fields and etc. You might want to find another way to test that =)

To know that the examples weren't running, you can run go test with the verbose flag:

Sirupsen/logrus $ go test . -v
testing: warning: no tests to run
PASS
ok      github.com/Sirupsen/logrus  0.011s

After adding the line:

Sirupsen/logrus $ go test . -v
=== RUN: ExampleLogger_Info
--- FAIL: ExampleLogger_Info (154.257us)
# ... stuff

Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ya, I had output there first, but removed it when I realized I had to mock time.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah just thought about that...

// "level": "info",
// "msg": "Simple logging call, compatible with the standard logger",
// "time": "2014-02-23 19:57:35.862271048 -0500 EST"
// }
}

func ExampleLogger_Warning() {
logger := New()

airbrake.Environment = "production"
airbrake.ApiKey = "valid"
airbrake.Endpoint = "https://exceptions.example.com/notifer_api/v2/notices"

// This will send an exception with Airbrake now that it has been setup.
logger.Warning("Something failed: %s", "failure")
// {
// "level": "warning",
// "msg": "Something failed: failure",
// "time": "2014-02-23 19:57:35.862271048 -0500 EST"
// }
}

func ExampleLogger_WithField() {
logger := New()
logger.WithField("source", "kafka").Infof("Connection to Kafka failed with %s", "some error")
// {
// "level": "info",
// "source": "kafka",
// "msg": "Connection to Kafka failed with some error",
// "time": "2014-02-23 19:57:35.862271048 -0500 EST"
// }
}

func ExampleLogger_WithFields() {
logger := New()
logger.WithFields(Fields{
"animal": "walrus",
"location": "New York Aquarium",
"weather": "rain",
"name": "Wally",
"event": "escape",
}).Info("Walrus has escaped the aquarium! Action required!")
// {
// "level": "info",
// "animal": "walrus",
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tabs.

// "location": "New York Aquarium",
// "weather":"rain",
// "name": "Wally",
// "event":"escape",
// "msg": "Walrus has escaped the aquarium! Action required!",
// "time": "2014-02-23 19:57:35.862271048 -0500 EST"
// }
}