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

logging: convert logger package from zap to slog #2539

Closed
wants to merge 33 commits into from
Closed

Conversation

miampf
Copy link
Contributor

@miampf miampf commented Oct 30, 2023

Context

Proposed change(s)

  • rewrite the logger package in internal/logger to use slog instead of zap
  • rewrite references to the logger package to be compatible with slog
  • add non-formatting functions for similar usage to fmt.Print(a, b)

Additional info

  • code in operators/ was not changed and still uses zap since it didn't depend on the logger package

Checklist

  • Update docs
  • Add labels (e.g., for changelog category)
  • Is PR title adequate for changelog?
  • Link to Milestone

@miampf miampf added the no changelog Change won't be listed in release changelog label Oct 30, 2023
@miampf miampf added this to the v2.13.0 milestone Oct 30, 2023
@netlify
Copy link

netlify bot commented Oct 30, 2023

Deploy Preview for constellation-docs canceled.

Name Link
🔨 Latest commit b312f59
🔍 Latest deploy log https://app.netlify.com/sites/constellation-docs/deploys/653fb39bbfb54b00089a488f

Copy link
Member

@daniel-weisse daniel-weisse left a comment

Choose a reason for hiding this comment

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

Thanks, looks mostly good.
Just a couple of small things

Comment on lines +64 to +70
const (
LevelDebug = slog.LevelDebug
LevelInfo = slog.LevelInfo
LevelWarn = slog.LevelWarn
LevelError = slog.LevelError
LevelFatal = 12
)
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
const (
LevelDebug = slog.LevelDebug
LevelInfo = slog.LevelInfo
LevelWarn = slog.LevelWarn
LevelError = slog.LevelError
LevelFatal = 12
)
// Log levels defined for the logger.
const (
LevelDebug = slog.LevelDebug
LevelInfo = slog.LevelInfo
LevelWarn = slog.LevelWarn
LevelError = slog.LevelError
LevelFatal = 12
)

Missing doc string.

Comment on lines +88 to +89
func replaceAttrFunction(groups []string, a slog.Attr) slog.Attr {
// change the time format to rfc 3339
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
func replaceAttrFunction(groups []string, a slog.Attr) slog.Attr {
// change the time format to rfc 3339
func replaceAttrFunction(_ []string, a slog.Attr) slog.Attr {
// change the time format to rfc 3339

groups is unused

Copy link
Member

Choose a reason for hiding this comment

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

When we originally designed the package we decided to only provide access to Printf style logging functions to reduce complexity of the package and enforce (mostly) uniform usage.
Log statements that use log.Info(msg, arg1, arg2) should instead use log.With(key1, arg1, key2, arg2).Infof(msg) or log.Infof(formtStr, arg1, arg2)

I think this still hold true, so I don't see a good reason to keep the additional Print style logging functions.

Comment on lines +72 to +86
func getOriginalCaller() (original [1]uintptr) {
var pcs [1]uintptr
runtime.Callers(3, pcs[:]) // skip Callers, getOriginalCaller and the function calling getOriginalCaller
return pcs
}

func createAndLogRecord(logger *slog.Logger, level slog.Level, originalFunction [1]uintptr, args ...any) {
record := slog.NewRecord(time.Now(), level, fmt.Sprint(args...), originalFunction[0])
_ = logger.Handler().Handle(context.Background(), record)
}

func createAndLogRecordf(logger *slog.Logger, level slog.Level, originalFunction [1]uintptr, format string, args ...any) {
record := slog.NewRecord(time.Now(), level, fmt.Sprintf(format, args...), originalFunction[0])
_ = logger.Handler().Handle(context.Background(), record)
}
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
func getOriginalCaller() (original [1]uintptr) {
var pcs [1]uintptr
runtime.Callers(3, pcs[:]) // skip Callers, getOriginalCaller and the function calling getOriginalCaller
return pcs
}
func createAndLogRecord(logger *slog.Logger, level slog.Level, originalFunction [1]uintptr, args ...any) {
record := slog.NewRecord(time.Now(), level, fmt.Sprint(args...), originalFunction[0])
_ = logger.Handler().Handle(context.Background(), record)
}
func createAndLogRecordf(logger *slog.Logger, level slog.Level, originalFunction [1]uintptr, format string, args ...any) {
record := slog.NewRecord(time.Now(), level, fmt.Sprintf(format, args...), originalFunction[0])
_ = logger.Handler().Handle(context.Background(), record)
}
func createAndLogRecordf(logger *slog.Logger, level slog.Level, callerSkip int, format string, args ...any) {
var originalFunction uintptr[1]
runtime.Callers(callerSkip, pcs[:])
record := slog.NewRecord(time.Now(), level, fmt.Sprintf(format, args...), originalFunction[0])
_ = logger.Handler().Handle(context.Background(), record)
}

You can add resolving of the original caller to the createAndLogRecord function directly to reduce overhead in the log functions.
The grpc logging adapter also needs a different caller skip depth (7) than our logging (3), so we should make that configurable.

@@ -68,24 +67,24 @@ func main() {

attestVariant, err := variant.FromString(os.Getenv(constants.AttestationVariant))
if err != nil {
log.With(zap.Error(err)).Fatalf("Failed to parse attestation variant")
log.With(slog.Any("error", err)).Fatalf("Failed to parse attestation variant")
Copy link
Member

Choose a reason for hiding this comment

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

Since error is probably the most used additional field for log messages, it might be worth to add a wrapper for this to our logging package. This would more easily ensure uniform logging for error.
E.g.

// Err creates an error attribute for structured logging.
func Err(err error) slog.Attr {
	return slog.Attr{
		Key:   "error",
		Value: slog.StringValue(err.Error()),
	}
}

@@ -103,7 +102,7 @@ func (u *Uploader) Upload(ctx context.Context, req *osimage.UploadRequest) ([]ve
}
defer func() {
if err := u.ensureBlobDeleted(ctx, blobName); err != nil {
u.log.Errorf("post-cleaning: deleting temporary blob from s3", err)
u.log.Error("post-cleaning: deleting temporary blob from s3", err)
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
u.log.Error("post-cleaning: deleting temporary blob from s3", err)
u.log.With(slog.Any("error", err)).Error("post-cleaning: deleting temporary blob from s3 failed")

@@ -6,7 +6,7 @@ SPDX-License-Identifier: AGPL-3.0-only

/*
Package logger provides logging functionality for Constellation services.
It is a thin wrapper around the zap package, providing a consistent interface for logging.
It is a thin wrapper around the slog package, providing a consistent interface for logging.
Copy link
Member

Choose a reason for hiding this comment

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

Wasn't the purpose of the ticket to get rid of the wrapper and use slog directly?

Copy link
Contributor

Choose a reason for hiding this comment

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

cc @miampf

After internal discussion, we concluded that we rather want to get rid of the wrapper entirely and replace the logging calls we do in our code with using slog directly, feel free to consult me before implementation or if unsure anywhere. This was a misunderstanding and I didn't explain the issue to you properly - sorry for that. However, pivoting here does not mean that the work you did so far is worthless. You should be able to reuse almost everything you have so far.

@miampf
Copy link
Contributor Author

miampf commented Nov 20, 2023

Since it was decided that the wrapper should be completely removed, I will create a new branch for implementing that.

@miampf miampf closed this Nov 20, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
no changelog Change won't be listed in release changelog
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants