Skip to content

Commit

Permalink
refactor(logging)!: switch to slog for logging
Browse files Browse the repository at this point in the history
Go now includes a nice way to do structured logs, including JSON. Use
that instead of a third party module.

BREAKING CHANGE: log format will change a little bit
  • Loading branch information
mloberg committed Mar 20, 2024
1 parent 78a26c3 commit e42cede
Show file tree
Hide file tree
Showing 8 changed files with 177 additions and 91 deletions.
26 changes: 26 additions & 0 deletions config.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,8 @@ package main

import (
"fmt"
"log/slog"
"os"
)

type Config struct {
Expand All @@ -10,6 +12,30 @@ type Config struct {
Region string
}

// NewFromEnv creates a new Config from environment variables and defaults
func NewFromEnv() *Config {
cfg := &Config{
Service: os.Getenv("SERVICE_NAME"),
Environment: os.Getenv("SERVICE_ENV"),
Region: os.Getenv("AWS_REGION"),
}

if cfg.Service == "" {
slog.Warn("SERVICE_NAME is not set, will not load service values")
}

if cfg.Environment == "" {
slog.Warn("SERVICE_ENV is not set, defaulting to dev")
cfg.Environment = "dev"
}

if cfg.Region == "" {
cfg.Region = "us-east-1"
}

return cfg
}

// ConsulPaths returns the paths from Consul to load
func (c *Config) ConsulPaths() []string {
paths := []string{
Expand Down
1 change: 0 additions & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,6 @@ require (
github.com/hashicorp/vault/api v1.12.0
github.com/hashicorp/vault/api/auth/aws v0.6.0
github.com/hashicorp/vault/api/auth/kubernetes v0.6.0
github.com/rs/zerolog v1.32.0
github.com/samber/lo v1.39.0
github.com/stretchr/testify v1.8.4
)
Expand Down
6 changes: 0 additions & 6 deletions go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,6 @@ github.com/cenkalti/backoff/v3 v3.0.0/go.mod h1:cIeZDE3IrqwwJl6VUwCN6trj1oXrTS4r
github.com/cespare/xxhash/v2 v2.1.1/go.mod h1:VGX0DQ3Q6kWi7AoAeZDth3/j3BFtOZR5XLFGgcrjCOs=
github.com/circonus-labs/circonus-gometrics v2.3.1+incompatible/go.mod h1:nmEj6Dob7S7YxXgwXpfOuvO54S+tGdZdw9fuRZt25Ag=
github.com/circonus-labs/circonusllhist v0.1.3/go.mod h1:kMXHVDlOchFAehlya5ePtbp5jckzBHf4XRpQvBOLI+I=
github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
Expand All @@ -70,7 +69,6 @@ github.com/go-sql-driver/mysql v1.5.0/go.mod h1:DCzpHaOWr8IXmIStZouvnhqoel9Qv2LB
github.com/go-stack/stack v1.8.0/go.mod h1:v0f6uXyyMGvRgIKkXu+yp6POWl0qKG85gN/melR3HDY=
github.com/go-test/deep v1.0.2 h1:onZX1rnHT3Wv6cqNgYyFOOlgVKJrksuCMCRvJStbMYw=
github.com/go-test/deep v1.0.2/go.mod h1:wGDj63lr65AM2AQyKZd/NYHGb0R+1RLqB8NKt3aSFNA=
github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
github.com/gogo/protobuf v1.1.1/go.mod h1:r8qH/GZQm5c6nD/R0oafs1akxWv10x8SbQlK7atdtwQ=
github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
github.com/golang/protobuf v1.3.1/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
Expand Down Expand Up @@ -226,9 +224,6 @@ github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsT
github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A=
github.com/rogpeppe/go-internal v1.6.1 h1:/FiVV8dS/e+YqF2JvO3yXRFbBLTIuSDkuC7aBOAvL+k=
github.com/rogpeppe/go-internal v1.6.1/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTEfhy4qGm1nDQc=
github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
github.com/rs/zerolog v1.32.0 h1:keLypqrlIjaFsbmJOBdB/qvyF8KEtCWHwobLp5l/mQ0=
github.com/rs/zerolog v1.32.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss=
github.com/ryanuber/columnize v0.0.0-20160712163229-9b3edd62028f/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
github.com/ryanuber/columnize v2.1.0+incompatible/go.mod h1:sm1tb6uqfes/u+d4ooFouqFdy9/2g9QGwK3SQygK0Ts=
github.com/ryanuber/go-glob v1.0.0 h1:iQh3xXAumdQ+4Ufa5b25cRpC5TYKlno6hsv6Cb3pkBk=
Expand Down Expand Up @@ -318,7 +313,6 @@ golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBc
golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.13.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.15.0 h1:h48lPFYpsTvQJZF4EKyI4aLHaev3CxivZmv7yZig9pc=
golang.org/x/sys v0.15.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
Expand Down
40 changes: 40 additions & 0 deletions logger.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
package main

import "log/slog"

// structuredError is an error that can be logged with additional data
type structuredError struct {
err error
args []any
}

// NewStructuredError returns a new structure error that will be logged with additional data
func serror(err error, args ...any) *structuredError {
return &structuredError{err: err, args: args}
}

func (e *structuredError) Error() string {
return e.err.Error()
}

func (e *structuredError) Unwrap() error {
return e.err
}

// LogValue returns a structured log value for use with slog
func (e structuredError) LogValue() slog.Value {
args := make([]slog.Attr, 0, (len(e.args)/2)+1)
args = append(args, slog.String("message", e.Error()))

var c interface{}
for _, a := range e.args {
if c == nil {
c = a
continue
}
args = append(args, slog.Any(c.(string), a))
c = nil
}

return slog.GroupValue(args...)
}
37 changes: 37 additions & 0 deletions logger_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
package main

import (
"bytes"
"fmt"
"log/slog"
"os"
"testing"

"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)

func TestStructuredError(t *testing.T) {
wrapped := fmt.Errorf("test error: %w", os.ErrNotExist)
err := serror(wrapped, "foo", "bar")

require.ErrorContains(t, err, "test error")
require.ErrorIs(t, err, os.ErrNotExist)

l, log := testLogger()
l.Error("test", "error", err)
assert.Contains(t, log.String(), `"error":{"message":"test error: file does not exist","foo":"bar"}`)
}

func testLogger() (*slog.Logger, *bytes.Buffer) {
log := &bytes.Buffer{}
return slog.New(slog.NewJSONHandler(log, &slog.HandlerOptions{
Level: slog.LevelDebug,
ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr {
if a.Key == "time" {
a.Value = slog.StringValue("test-time")
}
return a
},
})), log
}
101 changes: 47 additions & 54 deletions main.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,106 +3,97 @@ package main
import (
"context"
"errors"
"fmt"
"log/slog"
"os"
"os/exec"
"runtime"
"strconv"
"strings"

"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
)

var logLevel = new(slog.LevelVar)

func main() {
ctx := context.Background()

zerolog.SetGlobalLevel(zerolog.InfoLevel)
logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: logLevel}))
slog.SetDefault(logger)
if v, ok := os.LookupEnv("DEBUG_BOOTSTRAP"); ok && v != "false" {
zerolog.SetGlobalLevel(zerolog.DebugLevel)
}

cfg := &Config{
Service: os.Getenv("SERVICE_NAME"),
Environment: os.Getenv("SERVICE_ENV"),
Region: os.Getenv("AWS_REGION"),
logLevel.Set(slog.LevelDebug)
}

if cfg.Service == "" {
log.Warn().Msg("SERVICE_NAME is not set, will not load service values")
}

if cfg.Environment == "" {
log.Warn().Msg("SERVICE_ENV is not set, defaulting to dev")
cfg.Environment = "dev"
}

if cfg.Region == "" {
cfg.Region = "us-east-1"
}

logger := log.With().
Str("env", cfg.Environment).
Str("service", cfg.Service).
Str("region", cfg.Region).
Logger()
cfg := NewFromEnv()
logger = logger.With("env", cfg.Environment, "service", cfg.Service, "region", cfg.Region)
slog.SetDefault(logger)

if len(os.Args) < 2 {
logger.Fatal().Msg("Missing command")
logger.ErrorContext(ctx, "Missing command")
os.Exit(1)
}

env := NewEnvMap()

if addr := os.Getenv("CONSUL_ADDR"); addr != "" {
env.Merge(loadConsul(addr, cfg, logger))
c, err := loadConsul(ctx, addr, cfg, logger)
if err != nil {
logger.ErrorContext(ctx, "Could not load values from Consul", "error", err)
os.Exit(1)
}
env.Merge(c)
} else {
logger.Warn().Msg("Not loading values from Consul. CONSUL_ADDR is not set")
logger.WarnContext(ctx, "Not loading values from Consul. CONSUL_ADDR is not set")
}

if addr := os.Getenv("VAULT_ADDR"); addr != "" {
env.Merge(loadVault(ctx, addr, cfg, logger))
v, err := loadVault(ctx, addr, cfg, logger)
if err != nil {
logger.ErrorContext(ctx, "Could not load values from Vault", "error", err)
os.Exit(1)
}
env.Merge(v)
} else {
logger.Warn().Msg("Not loading values from Vault. VAULT_ADDR is not set")
logger.WarnContext(ctx, "Not loading values from Vault. VAULT_ADDR is not set")
}

pwd, err := os.Getwd()
if err != nil {
logger.Warn().Err(err).Msg("Cannot determine PWD")
logger.WarnContext(ctx, "Cannot determine PWD", "error", err)
}
env.Add("PWD", pwd)
env.Add("AWS_REGION", cfg.Region)
env.Add("SERVICE_ENV", cfg.Environment)
env.Add("PROCESSOR_COUNT", strconv.Itoa(runtime.NumCPU()))

os.Exit(run(os.Args[1], os.Args[2:], env.Environ(), logger))
os.Exit(run(ctx, os.Args[1], os.Args[2:], env.Environ(), logger))
}

func loadConsul(addr string, c *Config, l zerolog.Logger) Dict {
l.Debug().Msg("Loading values from Consul")
func loadConsul(ctx context.Context, addr string, c *Config, l *slog.Logger) (Dict, error) {
l.Debug("Loading values from Consul")

client, err := NewConsul(addr)
if err != nil {
l.Fatal().Err(err).Str("addr", addr).Msg("Could not connect to Consul")
return nil, serror(fmt.Errorf("Could not connect to Consul: %w", err), "addr", addr)
}

paths := c.ConsulPaths()
if p := os.Getenv("CONSUL_PATHS"); p != "" {
paths = append(paths, strings.Split(p, ",")...)
}

return loadValues(client, l, paths)
return loadValues(ctx, client, l, paths)
}

func loadVault(ctx context.Context, addr string, c *Config, l zerolog.Logger) Dict {
l.Debug().Msg("Loading values from Vault")
func loadVault(ctx context.Context, addr string, c *Config, l *slog.Logger) (Dict, error) {
l.DebugContext(ctx, "Loading values from Vault")

client, err := NewVault(addr, c.Region)
if err != nil {
l.Fatal().Err(err).Str("addr", addr).Msg("Could not connect to Vault")
return nil, serror(fmt.Errorf("Could not connect to Vault: %w", err), "addr", addr)
}

token, err := vaultToken(ctx)
if err != nil {
l.Fatal().Err(err).Msg("Could not get Vault token")
return nil, fmt.Errorf("Could not get Vault token: %w", err)
}

role := os.Getenv("VAULT_ROLE")
Expand All @@ -112,41 +103,43 @@ func loadVault(ctx context.Context, addr string, c *Config, l zerolog.Logger) Di

auth, err := client.Authenticate(ctx, token, role)
if err != nil {
l.Fatal().Err(err).Msg("Could not authenticate Vault")
return nil, fmt.Errorf("Could not authenticate Vault: %w", err)
}

if auth == "" {
l.Warn().Msg("Not loading values from Vault. Unable to authenticate Vault")
return make(Dict)
l.WarnContext(ctx, "Not loading values from Vault. Unable to authenticate Vault")
return make(Dict), nil
}

paths := c.VaultPaths()
if p := os.Getenv("VAULT_PATHS"); p != "" {
paths = append(paths, strings.Split(p, ",")...)
}

values := loadValues(client, l, paths)
values, err := loadValues(ctx, client, l, paths)
values["VAULT_TOKEN"] = auth
return values
return values, err
}

func run(name string, args, env []string, l zerolog.Logger) int {
cmd := exec.Command(name, args...) //nolint:gosec
func run(ctx context.Context, name string, args, env []string, l *slog.Logger) int {
cmd := exec.CommandContext(ctx, name, args...) //nolint:gosec
cmd.Env = append(os.Environ(), env...)
cmd.Stdin = os.Stdin
cmd.Stderr = os.Stderr
cmd.Stdout = os.Stdout

if err := cmd.Start(); err != nil {
l.Fatal().Err(err).Str("cmd", cmd.String()).Msg("Could not start command")
l.ErrorContext(ctx, "Could not start command", "error", err, "cmd", cmd.String())
return 1
}

if err := cmd.Wait(); err != nil {
var exit *exec.ExitError
if errors.As(err, &exit) {
return exit.ExitCode()
}
l.Fatal().Err(err).Str("cmd", cmd.String()).Msg("Unknown error while running command")
l.ErrorContext(ctx, "Unknown error while running command", "error", err, "cmd", cmd.String())
return 1
}

return 0
Expand Down
14 changes: 9 additions & 5 deletions utils.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,10 @@
package main

import "github.com/rs/zerolog"
import (
"context"
"fmt"
"log/slog"
)

type (
Dict map[string]string
Expand All @@ -11,19 +15,19 @@ type (
}
)

func loadValues(c Client, l zerolog.Logger, paths []string) Dict {
func loadValues(ctx context.Context, c Client, l *slog.Logger, paths []string) (Dict, error) {
values := map[string]string{}
for _, path := range paths {
l.Debug().Str("path", path).Msg("Loading values")
l.DebugContext(ctx, "Loading values", "path", path)

kv, err := c.Load(path)
if err != nil {
l.Fatal().Err(err).Str("path", path).Msg("Could not load values")
return values, serror(fmt.Errorf("Could not load values: %w", err), "path", path)
}

for k, v := range kv {
values[k] = v
}
}
return values
return values, nil
}
Loading

0 comments on commit e42cede

Please sign in to comment.