Suplog

A supercharged logging framework based upon github.com/sirupsen/logrus, which enables structured, leveled logging with hooks support. Hooks are middleware modules for logging that can augment message being logged or even send it to a remote server.

The key feature is an integrated stack tracing for any wrapped error (either from Go stdlib, or github.com/pkg/errors).

Init options

NewLogger(wr io.Writer, formatter Formatter, hooks ...Hook) Logger

Available formatters:

• suplog.JSONFormatter — suplogs all log entries as JSON objects
• suplog.TextFormatter — suplogs log entries as text lines for TTY or without TTY colors.

Available hooks:

• github.com/InjectiveLabs/suplog/hooks/debug
• github.com/InjectiveLabs/suplog/hooks/blob
• github.com/InjectiveLabs/suplog/hooks/bugsnag

Leveled Logging

Suplog supports 7 levels: Trace, Debug, Info, Warning, Error, Fatal and Panic.

log.Trace("Something very low level.")
log.Debug("Useful debugging information.")
log.Info("Something noteworthy happened!")
log.Warn("You should probably take a look at this.")
log.Error("Something failed but I'm not quitting.")
// Calls os.Exit(1) after logging
log.Fatal("Bye.")
// Calls panic() after logging
log.Panic("I'm bailing.")

You can set the logging level on an Logger, then it will only log entries with that severity or anything above it:

// Will log anything that is info or above (warn, error, fatal, panic). Default.
log.SetLevel(suplog.InfoLevel)

Different levels will produce log lines of different colors. Also, some hooks will trigger on specific levels. For example, a debug hook will add infomation about line for Debug log entries. Another hook that enables Bugsnag support will report all errors and warnings to an external service.

Structured Logging

In addition to log leveling, the new suplog package enables providing additional fields without altering the original message. By using this feature a developer can provide additional debug context.

log.WithFields(suplog.Fields{
    "module": "accounts",
    "email":  "[email protected]"
}).Error("account check failed")

In this case email field will be logged as a separate column that can be parsed and used as a filter. When using it with external services like Bugsnag, these fields will be reported in metadata tab and can be used for filtering too.

Suplog fields can be joined and chained:

func init() {
    out = log.WithField("module", "fooer")
}

func runningFoo() {
    fooOut := log.WithField("action", "foo")

    for _, itemName := range items {
        itemOut := fooOut.WithField("item", itemName)
        itemOut.Info("processing item!")
    }
}

You should use chaining to avoid duplication of field context in sub-routines!

An example of issuing a warning without changing the original error:

log.WithError(err).Warnln("something wrong happened")

Hooks

During suplog initialisation it is possible to specify suplog hooks. Hooks are plugins that will pre-process log entries and do something useful. Below are several examples that are available to suplog users.

Debug

Debug hook adds information about caller fn name and position is source code. By default applies only to Debug and Trace entries, but can be extended to any level.

import debugHook github.com/InjectiveLabs/suplog/hooks/debug

Options:

type HookOptions struct {
    // AppVersion specifies version of the app currently running.
    AppVersion string
    // Levels enables this hook for all listed levels.
    Levels []logrus.Level
    // PathSegmentsLimit allows to trim amount of source code file path segments.
    // Untrimmed: /Users/xlab/Documents/dev/go/src/github.com/InjectiveLabs/suplog/default_test.go
    // Trimmed (3): xlab/suplog/default_test.go
    PathSegmentsLimit int
}

If not specified, AppVersion is set from APP_VERSION env variable. PathSegmentsLimit is set to 3 by default, which means the latest 3 path segments of the source path.

Bugsnag

Bugsnag hook implements integration with Bugsnag.com service for error tracing and monitoring. It will send any entry above warning level, including its meta data and stack trace.

import bugsnagHook github.com/InjectiveLabs/suplog/hooks/bugsnag

Options:

type HookOptions struct {
    // Levels enables this hook for all listed levels.
    Levels       []logrus.Level

    Env               string
    AppVersion        string
    BugsnagAPIKey     string
    BugsnagEnabledEnv []string
    BugsnagPackages   []string
}

Be default reporting is enabled for all levels above Warning.

The hook can be enabled in default suplogger by setting OS ENV variables:

• APP_ENV (e.g. test, staging or prod)
• APP_VERSION
• LOG_BUGSNAG_KEY
• LOG_BUGSNAG_ENABLED — this option enables bugsnag in default suplogger for existing codebase.

Blob Uploads

Blob hook allows to upload heavy blobs of data such as request and response HTML / JSON dumps into a remote log storage. This hook utilizes Amazon S3 interface, therefore is compatible with any S3-like API.

import blobHook github.com/InjectiveLabs/suplog/hooks/blob

Options:

type HookOptions struct {
    Env               string
    BlobStoreURL      string
    BlobStoreAccount  string
    BlobStoreKey      string
    BlobStoreEndpoint string
    BlobStoreRegion   string
    BlobStoreBucket   string
    BlobRetentionTTL  time.Duration
    BlobEnabledEnv    map[string]bool
}

Be default blob uploading is enabled for all levels.

The following OS ENV variables are mapped:

• APP_ENV
• LOG_BLOB_STORE_URL
• LOG_BLOB_STORE_ACCOUNT
• LOG_BLOB_STORE_KEY
• LOG_BLOB_STORE_ENDPOINT
• LOG_BLOB_STORE_REGION
• LOG_BLOB_STORE_BUCKET
• LOG_BLOB_ENABLED — this option enables blob in default suplogger for existing codebase.

How to use:

log.WithField("blob", testBlob).Infoln("test is running, trying to submit blob")

Where field name should be exactly blob and testBlob should be []byte.

Conditional triggers

It will only log if the condition is met, otherwise it will return a NoOp logger.

OnCondition

Description

Returns a ConditionLogger if the provided condition is true. If the condition is false, it returns a NoOp logger. If a logger is provided in the variadic argument, only the first logger is used.

Behavior

• If cond is true, the function returns the first logger provided (or the default logger if none is provided).
• If cond is false, it returns a NoOp logger.

Usage

log.OnCondition(x > 0).WithField("foo", "bar").Info("This will log because condition is true")

---

OnErr

Logs only if the provided error is not nil.

Description

Returns a ConditionLogger if the provided error is not nil. If the error is nil, it returns a NoOp logger. If a logger is provided in the variadic argument, only the first logger is used.

Parameters

• err error: The error to check.
• logger ...Logger: Optional variadic argument for the logger to use.

Behavior

• If err is not nil, the function returns a logger with the error attached.
• If err is nil, it returns a NoOp logger.

Usage

log.OnError(someErr).WithField("foo", "bar").Info("something happened")

---

OnTime

Receives a ticker/timer, if if the time is met, it will log. This is useful for preventing excessive logging when log frequency is too high, similar to sampling

Description

Returns a ConditionLogger if the provided tick channel receives a tick. If no tick is received, it returns a NoOp logger. The function checks the channel non-blockingly.

Behavior

• If a tick is received from the channel, the function returns the first logger provided (or the default logger if none is provided).
• If no tick is received, it returns a NoOp logger.

Usage

ticker := time.NewTicker(1 * time.Minute)
log.OnTime(ticker.C).WithField("foo", "bar").Info("This will log every minute at most")

Context Logger (logcontext)

This package provides a mechanism for storing a suplog.Logger within a context.Context and allowing it to be mutated (e.g., adding new fields) by downstream functions in a thread-safe manner.

Usage

1. Initialization (Top-Level Middleware) Initialize the logger once at the start of your request, typically in the first middleware.

func LoggingMiddleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        // Create your base logger
        baseLogger := suplog.NewLogger(/* ... */)

        // Put it in the context using the package
        ctx := logctx.WithLogger(r.Context(), baseLogger)
        
        // The defer runs last, after all other handlers
        defer func() {
            // Get the logger (which now has all fields) and log
            finalLogger := logctx.Logger(ctx)
            finalLogger.Info("Request finished")
        }()

        // Pass the context down the chain
        next.ServeHTTP(w, r.WithContext(ctx))
    })
}

2. Adding Fields (Downstream Middlewares/Handlers) Any other function can now add fields. They do not need to create a new context, as the logger is mutated in place.

func AuthMiddleware(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
    // This mutates the logger in the context
        logctx.WithField(r.Context(), "user_id", "user-abc")
        next.ServeHTTP(w, r)
    })
}

func MyHandler(w http.ResponseWriter, r *http.Request) {
    // This also mutates the same logger
    logctx.WithFields(r.Context(), suplog.Fields{
        "request_id": "req-123",
        "foo": "bar",
    })

    // You can also retrieve it to log here
    logger := logctx.Logger(r.Context())
    logger.Info("Handler executing") // This log will have user_id, request_id, etc.

    w.Write([]byte("OK"))
}

3. Retrieving the Logger To get the current state of the logger at any time (e.g., for logging in a handler), use LoggerFromContext. This function is thread-safe and will always return the most up-to-date logger.

logger := logctx.Logger(ctx)
logger.Info("Hello")