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

refactor: introduce common logging #1453

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from
Draft

Conversation

lzap
Copy link
Collaborator

@lzap lzap commented Jan 8, 2025

This is the first patch in the series that will bring common logging across osbuild projects: image-builder, composer, composer-worker.

It builds on top of the new log/slog library which is part of Go from 1.21. By extracting handlers and common initialization and configuration code into a common library, this makes sure logging is consistent across all projects. To make the trasition smooth, a logrus proxy is introduced which proxies all logrus logging calls to slog so changes can be gradually performed.

Change of logging statements will be easy to do search-and-replace operation, however, in order to take advantage of automatic log correlation, context must be passed. I am committing to this work and I will refactor all handlers. Middeware and HTTP clients are prepared to automatically distribute correlation information.

What is changing

Instead of logrus, use the log/slog API to do all logging. Message field is now named "msg" instead "message", this can be changed if needed. All field names remain the same. Every log event contains trace_id (autogenerated, carries over via context) and build_id (git sha). For more information, please read:

https://github.com/osbuild/logging

Nothing is changing in the terms of infrastructure - all logs go into three sinks:

  • Splunk (new handler based on the existing code from composer/pkg/splunk)
  • Cloudwatch (new handler, used in provisioning in production)
  • Standard output

The PR is small, what is massive is a depdencency update in vendor/ because the new Cloudwatch handler does use AWS SDK v2 instead of the legacy v1. Plus some depdencies are dropped (e.g. logrus) and few new added.

What needs to be done next:

  • Replace logrus.LOG with slog.LOG
  • Pass context down the stack

@lzap lzap requested review from croissanne and schuellerf January 8, 2025 12:12
go.mod Outdated
@@ -4,14 +4,13 @@ go 1.22

toolchain go1.22.0

replace github.com/osbuild/logging => ../logging

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

This is a leftover, will remove.

}

logrus.Infof("Starting image-builder from Git Hash: %s", gitRev)
logrus.Infof("Changelog: https://github.com/osbuild/image-builder/commits/%s", gitRev)
Copy link
Collaborator Author

@lzap lzap Jan 8, 2025

Choose a reason for hiding this comment

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

All messages automatically get git sha in build_id so this is not necessary. The starting message repeats once more below so I am removing this one. Can put it back tho if it serves a purpose.

CustomAttrs: []slog.Attr{
slog.String("channel", "conf.DeploymentChannel"),
},
},
}
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

This is the universal configuration block that is used here and in maintainance/migrate commands as well as it will be used in composer/worker. This makes sure logging is always configured in a same way.

@ezr-ondrej
Copy link
Collaborator

This is pretty heavy on the vendored dependencies, might be good to merge #1418 first. other then that, LGTM! :)

// TODO context must be passed to the request method
req = req.WithContext(context.TODO())
doer := strc.NewTracingDoer(cc.client)
return doer.Do(req)
Copy link
Collaborator Author

@lzap lzap Jan 8, 2025

Choose a reason for hiding this comment

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

Just noticed context is actually in this HTTP client, so will change this and this one will work properly. See a note below what it does and why it is TODO right now.

// TODO context must be passed to the request method
req = req.WithContext(context.TODO())
doer := strc.NewTracingDoer(cc.client)
resp, err := doer.Do(req)
Copy link
Collaborator Author

@lzap lzap Jan 8, 2025

Choose a reason for hiding this comment

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

All the remaining HTTP clients contains the same - the doer wrapper cannot add trace_id propagation HTTP header until context is available. I will do a followup PR(s) to propagate context around.

@@ -8,7 +8,7 @@ import (
"path/filepath"
"regexp"

"github.com/sirupsen/logrus"
"github.com/osbuild/logging/pkg/logrus"
Copy link
Collaborator Author

Choose a reason for hiding this comment

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

You will see this in many places, this introduces the mentioned logrus proxy so once this PR is merged all logging is done via log/slog library. This is temporary.

assert.Equal(t, 1, len(collector.All()))
assert.Contains(t, field, "Acquired new token")
assert.NotContains(t, field, "mock-token-1")
collector.Reset()
Copy link
Collaborator Author

@lzap lzap Jan 8, 2025

Choose a reason for hiding this comment

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

This test is a bit clunky (will fall apart if tests are executed in parallel), but I did not want to remove any irrelevant code in this patch, so I created similar helper handler (aka hook) to do the same logic.

@@ -747,8 +747,6 @@ components:
properties:
version:
type: string
build_time:
type: string
Copy link
Collaborator Author

@lzap lzap Jan 8, 2025

Choose a reason for hiding this comment

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

Since osbuild/logging library automatically provides build_id logging flag (and the value), I have decided to delete file internal/common/runtime.go which provides the same but does not provide build time. This could be sort of a breaking change tho this is just an informative endpoint, maybe @jrusz use it? Can put it back no problem.

I made sure time is available in the library as well so I can put it back: osbuild/logging#7

Copy link
Contributor

Choose a reason for hiding this comment

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

I am not using it and in the test suite it's just logging the build_commit

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants