grpc_slog

package module
v1.1.0 Latest Latest
Warning

This package is not in the latest version of its module.

Go to latest
Published: Sep 6, 2020 License: Apache-2.0 Imports: 14 Imported by: 0

README

slog-grpc-mw

Godoc reference GitHub release (latest by date)

gRPC Go middleware for Cdr's Slog logger: https://github.com/cdr/slog

Output Screenshot

Install

go get github.com/hassieswift621/slog-grpc-mw

Example Usage

func main() {
    // Create GRPC server.
    srv := grpc.NewServer(
        grpc.UnaryInterceptor(
            grpc_middleware.ChainUnaryServer(
                grpc_slog.UnaryServerInterceptor(grpcLogger(true)),
            ),
        ),
    )
}

func grpcLogger(verbose bool) slog.Logger {
	logger := sloghuman.Make(os.Stdout).Leveled(slog.LevelWarn).Named("grpc")

	if verbose {
		logger = logger.Leveled(slog.LevelDebug)
	}

	return logger
}

License

Copyright ©2020 Hassie.

Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at

http://www.apache.org/licenses/LICENSE-2.0

Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.

Documentation

Overview

`grpc_slog` is a gRPC logging middleware backed by Slog loggers

It accepts a user-configured `slog.Logger` that will be used for logging completed gRPC calls. The same `slog.Logger` will be used for logging completed gRPC calls, and be populated into the `context.Context` passed into gRPC handler code.

On calling `StreamServerInterceptor` or `UnaryServerInterceptor` this logging middleware will add gRPC call information to the ctx so that it will be present on subsequent use of the `ctx_slog` logger.

If a deadline is present on the gRPC request the grpc.request.deadline tag is populated when the request begins. grpc.request.deadline is a string representing the time (RFC3339) when the current call will expire.

This package also implements request and response *payload* logging, both for server-side and client-side. These will be logged as structured `jsonpb` fields for every message received/sent (both unary and streaming). For that please use `Payload*Interceptor` functions. Please note that the user-provided function that determines whether to log the full request/response payload needs to be written with care, as this can significantly slow down gRPC.

Slog can also be made as a backend for gRPC library internals. For that use `ReplaceGrpcLoggerV2`.

*Server Interceptor* Below is a JSON formatted example of a log that would be logged by the server interceptor:

{
	"level": "INFO",							// string	Slog log levels
	"msg": "finished unary call with code OK",	// string	log message
	"ts": "2020-04-08T19:16:33.7517136Z",		// string	Slog RFC3339 log timestamp
	"caller": "slog-grpc-mw/shared_test.go:30",	// string	Slog caller - file
	"func":	"github.com/hassieswift621/slog-grpc-mw_test.(*loggingPingService).Ping",	// string	Slog caller - func
	"fields": {								// object	Slog fields
		"custom_field": "custom_value",		// string	user defined field
		"custom_tags.int": 1337,			// int	user defined tag on the ctx
		"custom_tags.string": "something",	// string	user defined tag on the ctx
		"grpc.code": "OK",					// string	grpc status code
		"grpc.method": "Ping",				// string	method name
		"grpc.service": "mwitkow.testproto.TestService", 		// string	full name of the called service
		"grpc.request.deadline": "2006-01-02T15:04:05Z07:00",	// string	RFC3339 deadline of the current request if supplied
		"grpc.request.value": "something",						// string	value on the request
		"grpc.service": "mwitkow.testproto.TestService",		// string	full name of the called service
		"grpc.start_time": "2006-01-02T15:04:05Z07:00",			// string	RFC3339 representation of the start time
		"grpc.time_ms": 1.234,									// float32	run time of the call in ms
		"peer.address": "127.0.0.1:55948"						// string	IP address of calling party and the port which the call is incoming on
		"span.kind": "server",									// string	client | server
		"system": "grpc"										// string
	}
}

*Payload Interceptor* Below is a JSON formatted example of a log that would be logged by the payload interceptor:

{
	"level": "INFO",	// string	Slog log levels
	"msg": "client request payload logged as grpc.request.content",			// string	log message
	"caller": "slog-grpc-mw/payload_interceptors.go:130",					// string	Slog caller - file
	"func": "github.com/hassieswift621/slog-grpc-mw.logProtoMessageAsJson",	// string	Slog caller - func
	"fields": {						// object	Slog fields
		"grpc.request.content": {	// object	content of RPC request
			"sleepTimeMs": 9999,	// int		defined by caller
			"value": something,		// string	defined by caller
		},
		"grpc.method": "Ping",								// string	method name
		"grpc.service": "mwitkow.testproto.TestService",	// string	full name of the called service
		"span.kind": "server",								// string	client | server
		"system": "grpc"									// string
	}
}

Please see examples and tests for examples of use.

Example (Initialization)

Initialization shows a relatively complex initialization sequence.

package main

import (
	"cdr.dev/slog"

	grpc_middleware "github.com/grpc-ecosystem/go-grpc-middleware"

	grpc_ctxtags "github.com/grpc-ecosystem/go-grpc-middleware/tags"

	grpc_slog "github.com/hassieswift621/slog-grpc-mw"
	"google.golang.org/grpc"
)

var (
	logger     slog.Logger
	customFunc grpc_slog.CodeToLevel
)

func main() {
	// Shared options for the logger, with a custom gRPC code to log level function.
	opts := []grpc_slog.Option{
		grpc_slog.WithLevels(customFunc),
	}

	// Make sure that log statements internal to gRPC library are logged using the slog logger as well.
	grpc_slog.ReplaceGrpcLoggerV2(logger)

	// Create a server, make sure we put the grpc_ctxtags context before everything else.
	_ = grpc.NewServer(
		grpc_middleware.WithUnaryServerChain(
			grpc_ctxtags.UnaryServerInterceptor(grpc_ctxtags.WithFieldExtractor(grpc_ctxtags.CodeGenRequestFieldExtractor)),
			grpc_slog.UnaryServerInterceptor(logger, opts...),
		),
		grpc_middleware.WithStreamServerChain(
			grpc_ctxtags.StreamServerInterceptor(grpc_ctxtags.WithFieldExtractor(grpc_ctxtags.CodeGenRequestFieldExtractor)),
			grpc_slog.StreamServerInterceptor(logger, opts...),
		),
	)
}
Output:

Example (InitializationWithDecider)
package main

import (
	"io/ioutil"

	"cdr.dev/slog/sloggers/sloghuman"

	grpc_middleware "github.com/grpc-ecosystem/go-grpc-middleware"

	grpc_ctxtags "github.com/grpc-ecosystem/go-grpc-middleware/tags"

	grpc_slog "github.com/hassieswift621/slog-grpc-mw"
	"google.golang.org/grpc"
)

func main() {
	opts := []grpc_slog.Option{
		grpc_slog.WithDecider(func(fullMethodName string, err error) bool {
			// will not log gRPC calls if it was a call to healthcheck and no error was raised
			if err == nil && fullMethodName == "foo.bar.healthcheck" {
				return false
			}

			// by default everything will be logged
			return true
		}),
	}

	// Initialise nop logger.
	nopLogger := sloghuman.Make(ioutil.Discard)

	_ = []grpc.ServerOption{
		grpc_middleware.WithStreamServerChain(
			grpc_ctxtags.StreamServerInterceptor(),
			grpc_slog.StreamServerInterceptor(nopLogger, opts...)),
		grpc_middleware.WithUnaryServerChain(
			grpc_ctxtags.UnaryServerInterceptor(),
			grpc_slog.UnaryServerInterceptor(nopLogger, opts...)),
	}
}
Output:

Example (InitializationWithDurationFieldOverride)

Initialization shows an initialization sequence with the duration field generation overridden.

package main

import (
	"time"

	"cdr.dev/slog"

	grpc_middleware "github.com/grpc-ecosystem/go-grpc-middleware"

	grpc_ctxtags "github.com/grpc-ecosystem/go-grpc-middleware/tags"

	grpc_slog "github.com/hassieswift621/slog-grpc-mw"
	"google.golang.org/grpc"
)

var logger slog.Logger

func main() {
	opts := []grpc_slog.Option{
		grpc_slog.WithDurationField(func(duration time.Duration) slog.Field {
			return slog.F("grpc.time_ns", duration.Nanoseconds())
		}),
	}

	_ = grpc.NewServer(
		grpc_middleware.WithUnaryServerChain(
			grpc_ctxtags.UnaryServerInterceptor(),
			grpc_slog.UnaryServerInterceptor(logger, opts...),
		),
		grpc_middleware.WithStreamServerChain(
			grpc_ctxtags.StreamServerInterceptor(),
			grpc_slog.StreamServerInterceptor(logger, opts...),
		),
	)
}
Output:

Index

Examples

Constants

This section is empty.

Variables

View Source
var (
	// SystemField is used in every log statement made through grpc_slog. Can be overwritten before any initialization code.
	SystemField = slog.Field{Name: "system", Value: "grpc"}
	// ServerField is used in every server-side log statement made through grpc_slog. Can be overwritten before initialization.
	ServerField = slog.Field{Name: "span.kind", Value: "server"}
)
View Source
var (
	// ClientField is used in every client-side log statement made through grpc_slog. Can be overwritten before initialization.
	ClientField = slog.Field{"span.kind", "client"}
)
View Source
var DefaultDurationToField = DurationToTimeMillisField

DefaultDurationToField is the default implementation of converting request duration to a slog field.

View Source
var (
	// JsonPbMarshaller is the marshaller used for serializing protobuf messages.
	// If needed, this variable can be reassigned with a different marshaller with the same Marshal() signature.
	JsonPbMarshaller grpc_logging.JsonPbMarshaler = &jsonpb.Marshaler{}
)

Functions

func DefaultClientCodeToLevel

func DefaultClientCodeToLevel(code codes.Code) slog.Level

DefaultClientCodeToLevel is the default implementation of gRPC return codes to log levels for client side.

func DefaultCodeToLevel

func DefaultCodeToLevel(code codes.Code) slog.Level

DefaultCodeToLevel is the default implementation of gRPC return codes and interceptor log level for server side.

func DurationToDurationField

func DurationToDurationField(duration time.Duration) slog.Field

DurationToDurationField uses a Duration field to log the request duration and leaves it up to Log's encoder settings to determine how that is output.

func DurationToTimeMillisField

func DurationToTimeMillisField(duration time.Duration) slog.Field

DurationToTimeMillisField converts the duration to milliseconds and uses the key `grpc.time_ms`.

func PayloadStreamClientInterceptor

func PayloadStreamClientInterceptor(logger slog.Logger, decider grpc_logging.ClientPayloadLoggingDecider) grpc.StreamClientInterceptor

PayloadStreamClientInterceptor returns a new streaming client interceptor that logs the payloads of requests and responses.

func PayloadStreamServerInterceptor

func PayloadStreamServerInterceptor(logger slog.Logger, decider grpc_logging.ServerPayloadLoggingDecider) grpc.StreamServerInterceptor

PayloadStreamServerInterceptor returns a new server server interceptors that logs the payloads of requests.

This *only* works when placed *after* the `grpc_slog.StreamServerInterceptor`. However, the logging can be done to a separate instance of the logger.

func PayloadUnaryClientInterceptor

func PayloadUnaryClientInterceptor(logger slog.Logger, decider grpc_logging.ClientPayloadLoggingDecider) grpc.UnaryClientInterceptor

PayloadUnaryClientInterceptor returns a new unary client interceptor that logs the payloads of requests and responses.

func PayloadUnaryServerInterceptor

func PayloadUnaryServerInterceptor(logger slog.Logger, decider grpc_logging.ServerPayloadLoggingDecider) grpc.UnaryServerInterceptor

PayloadUnaryServerInterceptor returns a new unary server interceptors that logs the payloads of requests.

This *only* works when placed *after* the `grpc_slog.UnaryServerInterceptor`. However, the logging can be done to a separate instance of the logger.

func ReplaceGrpcLoggerV2

func ReplaceGrpcLoggerV2(logger slog.Logger)

ReplaceGrpcLoggerV2 replaces the grpc_log.LoggerV2 with the provided logger.

func ReplaceGrpcLoggerV2WithVerbosity

func ReplaceGrpcLoggerV2WithVerbosity(logger slog.Logger, verbosity int)

ReplaceGrpcLoggerV2WithVerbosity replaces the grpc_log.LoggerV2 with the provided logger and verbosity.

func StreamClientInterceptor

func StreamClientInterceptor(logger slog.Logger, opts ...Option) grpc.StreamClientInterceptor

StreamClientInterceptor returns a new streaming client interceptor that optionally logs the execution of external gRPC calls.

func StreamServerInterceptor

func StreamServerInterceptor(logger slog.Logger, opts ...Option) grpc.StreamServerInterceptor

StreamServerInterceptor returns a new streaming server interceptor that adds slog.Logger to the context.

func UnaryClientInterceptor

func UnaryClientInterceptor(logger slog.Logger, opts ...Option) grpc.UnaryClientInterceptor

UnaryClientInterceptor returns a new unary client interceptor that optionally logs the execution of external gRPC calls.

func UnaryServerInterceptor

func UnaryServerInterceptor(logger slog.Logger, opts ...Option) grpc.UnaryServerInterceptor

UnaryServerInterceptor returns a new unary server interceptors that adds slog.Logger to the context.

Types

type CodeToLevel

type CodeToLevel func(code codes.Code) slog.Level

CodeToLevel function defines the mapping between gRPC return codes and interceptor log level.

type DurationToField

type DurationToField func(duration time.Duration) slog.Field

DurationToField function defines how to produce duration fields for logging

type Option

type Option func(*options)

func WithCodes

func WithCodes(f grpc_logging.ErrorToCode) Option

WithCodes customizes the function for mapping errors to error codes.

func WithDecider

func WithDecider(f grpc_logging.Decider) Option

WithDecider customizes the function for deciding if the gRPC interceptor logs should log.

func WithDurationField

func WithDurationField(f DurationToField) Option

WithDurationField customizes the function for mapping request durations to log fields.

func WithLevels

func WithLevels(f CodeToLevel) Option

WithLevels customizes the function for mapping gRPC return codes and interceptor log level statements.

Directories

Path Synopsis
`ctxslog` is a ctxlogger that is backed by slog It accepts a user-configured `slog.Logger` that will be used for logging.
`ctxslog` is a ctxlogger that is backed by slog It accepts a user-configured `slog.Logger` that will be used for logging.

Jump to

Keyboard shortcuts

? : This menu
/ : Search site
f or F : Jump to
y or Y : Canonical URL