Skip to content

SlogLogger loses error context #1265

Description

@oPOCCOMAXAo

Describe the bug
In function slogErr errors are converted into string and lose metadata, like stacktrace or extra fields of error structs.

//fxevent/slog.go:270
func slogErr(err error) slog.Attr {
 	return slog.String("error", err.Error())
}

To Reproduce
Example:

package example

import (
	"context"
	"fmt"
	"log/slog"
	"testing"

	"github.com/pkg/errors"
	"github.com/stretchr/testify/assert"
	"github.com/stretchr/testify/require"
	"go.uber.org/fx"
	"go.uber.org/fx/fxevent"
)

type TestService struct{}

func NewTestService(
	lc fx.Lifecycle,
) *TestService {
	lc.Append(fx.Hook{
		OnStart: func(context.Context) error {
			return errors.WithStack(assert.AnError)
		},
	})

	return &TestService{}
}

var _ slog.Handler = (*CustomLogger)(nil)

type CustomLogger struct {
	SeenError bool
	Text      string
}

func (c *CustomLogger) Enabled(context.Context, slog.Level) bool { return true }

func (c *CustomLogger) Handle(_ context.Context, rec slog.Record) error {
	rec.Attrs(func(attr slog.Attr) bool {
		if err, ok := attr.Value.Any().(error); ok && err != nil {
			c.SeenError = true
		}

		if attr.Key == "error" {
			c.Text = attr.Value.String()
		}

		return true
	})

	return nil
}

func (c *CustomLogger) WithAttrs([]slog.Attr) slog.Handler { return c }

func (c *CustomLogger) WithGroup(string) slog.Handler { return c }

func TestExample(t *testing.T) {
	slogHandler := CustomLogger{}

	app := fx.New(
		fx.WithLogger(func() fxevent.Logger {
			return &fxevent.SlogLogger{
				Logger: slog.New(&slogHandler),
			}
		}),
		fx.Provide(NewTestService),
		fx.Invoke(func(_ *TestService, sd fx.Shutdowner) {
			sd.Shutdown()
		}),
	)

	err := app.Start(context.Background())
	require.Error(t, err, "test error")

	<-app.Done()

	assert.False(t, slogHandler.SeenError)
	assert.Equal(t, "assert.AnError general error for testing", slogHandler.Text)

	// here partial checks as path is not stable from machine to machine
	fullErrorText := fmt.Sprintf("%+v", err)
	t.Log(fullErrorText)
	assert.Contains(t, fullErrorText, "assert.AnError")
	assert.Contains(t, fullErrorText, "example_test.go:23")
	assert.Contains(t, fullErrorText, "go.uber.org/fx@v1.23.0/internal/lifecycle/lifecycle.go:265")
}

Here slog handler doesn't have access to original error, but receives untraceable string.

Original error has extra data - stacktrace, which could be retrieved in slog handler like this:

	// here partial checks as path is not stable from machine to machine
	fullErrorText := fmt.Sprintf("%+v", err)
	t.Log(fullErrorText)
	assert.Contains(t, fullErrorText, "assert.AnError")
	assert.Contains(t, fullErrorText, "example_test.go:23")
	assert.Contains(t, fullErrorText, "go.uber.org/fx@v1.23.0/internal/lifecycle/lifecycle.go:265")

Also repo with code: https://github.com/oPOCCOMAXAo/fxexample/blob/master/example_test.go

Expected behavior

Custom slog Handler must access to original error value and process it as required by business logic. Like in this example:

func (c *CustomLogger) Handle(_ context.Context, rec slog.Record) error {
	rec.Attrs(func(attr slog.Attr) bool {
		if err, ok := attr.Value.Any().(error); ok && err != nil {
			c.SeenError = true
		}

		if attr.Key == "error" {
			c.Text = attr.Value.String()
		}

		return true
	})

	return nil
}

Additional context

This will fix the issue:

//fxevent/slog.go:270
func slogErr(err error) slog.Attr {
 	return slog.Any("error", err)
}

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions