From 8a0449ffc1d4dea1bac8b05a7d1842706550d7da Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andr=C3=A9=20Duffeck?= Date: Wed, 4 Dec 2024 10:00:46 +0100 Subject: [PATCH 1/6] Pass an initialized logger to the async propagator --- pkg/storage/fs/posix/tree/tree.go | 2 +- pkg/storage/utils/decomposedfs/decomposedfs.go | 2 +- pkg/storage/utils/decomposedfs/testhelpers/helpers.go | 5 +++-- pkg/storage/utils/decomposedfs/tree/propagator/async.go | 7 +++---- .../utils/decomposedfs/tree/propagator/propagator.go | 5 +++-- pkg/storage/utils/decomposedfs/tree/tree.go | 5 +++-- pkg/storage/utils/decomposedfs/upload/store_test.go | 3 ++- pkg/storage/utils/decomposedfs/upload_async_test.go | 2 +- pkg/storage/utils/decomposedfs/upload_test.go | 2 +- 9 files changed, 18 insertions(+), 15 deletions(-) diff --git a/pkg/storage/fs/posix/tree/tree.go b/pkg/storage/fs/posix/tree/tree.go index 18228ff548..f5a287457b 100644 --- a/pkg/storage/fs/posix/tree/tree.go +++ b/pkg/storage/fs/posix/tree/tree.go @@ -108,7 +108,7 @@ func New(lu node.PathLookup, bs Blobstore, um usermapper.Mapper, trashbin *trash trashbin: trashbin, options: o, idCache: cache, - propagator: propagator.New(lu, &o.Options), + propagator: propagator.New(lu, &o.Options, log), scanQueue: scanQueue, scanDebouncer: NewScanDebouncer(o.ScanDebounceDelay, func(item scanItem) { scanQueue <- item diff --git a/pkg/storage/utils/decomposedfs/decomposedfs.go b/pkg/storage/utils/decomposedfs/decomposedfs.go index b1abd267f9..cf132a1cac 100644 --- a/pkg/storage/utils/decomposedfs/decomposedfs.go +++ b/pkg/storage/utils/decomposedfs/decomposedfs.go @@ -156,7 +156,7 @@ func NewDefault(m map[string]interface{}, bs tree.Blobstore, es events.Stream, l microstore.Table(o.IDCache.Table), store.DisablePersistence(o.IDCache.DisablePersistence), store.Authentication(o.IDCache.AuthUsername, o.IDCache.AuthPassword), - )) + ), log) permissionsSelector, err := pool.PermissionsSelector(o.PermissionsSVC, pool.WithTLSMode(o.PermTLSMode)) if err != nil { diff --git a/pkg/storage/utils/decomposedfs/testhelpers/helpers.go b/pkg/storage/utils/decomposedfs/testhelpers/helpers.go index c0502a3ea5..a7313db833 100644 --- a/pkg/storage/utils/decomposedfs/testhelpers/helpers.go +++ b/pkg/storage/utils/decomposedfs/testhelpers/helpers.go @@ -171,15 +171,16 @@ func NewTestEnv(config map[string]interface{}) (*TestEnv, error) { }, ) + log := &zerolog.Logger{} bs := &treemocks.Blobstore{} - tree := tree.New(lu, bs, o, store.Create()) + tree := tree.New(lu, bs, o, store.Create(), log) aspects := aspects.Aspects{ Lookup: lu, Tree: tree, Permissions: permissions.NewPermissions(pmock, permissionsSelector), Trashbin: &decomposedfs.DecomposedfsTrashbin{}, } - fs, err := decomposedfs.New(o, aspects, &zerolog.Logger{}) + fs, err := decomposedfs.New(o, aspects, log) if err != nil { return nil, err } diff --git a/pkg/storage/utils/decomposedfs/tree/propagator/async.go b/pkg/storage/utils/decomposedfs/tree/propagator/async.go index 14e65dea06..050e1c6ecd 100644 --- a/pkg/storage/utils/decomposedfs/tree/propagator/async.go +++ b/pkg/storage/utils/decomposedfs/tree/propagator/async.go @@ -27,7 +27,6 @@ import ( "time" "github.com/cs3org/reva/v2/pkg/appctx" - "github.com/cs3org/reva/v2/pkg/logger" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/lookup" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/metadata" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/metadata/prefixes" @@ -49,6 +48,7 @@ type AsyncPropagator struct { treeTimeAccounting bool propagationDelay time.Duration lookup node.PathLookup + log *zerolog.Logger } // Change represents a change to the tree @@ -58,16 +58,15 @@ type Change struct { } // NewAsyncPropagator returns a new AsyncPropagator instance -func NewAsyncPropagator(treeSizeAccounting, treeTimeAccounting bool, o options.AsyncPropagatorOptions, lookup node.PathLookup) AsyncPropagator { +func NewAsyncPropagator(treeSizeAccounting, treeTimeAccounting bool, o options.AsyncPropagatorOptions, lookup node.PathLookup, log *zerolog.Logger) AsyncPropagator { p := AsyncPropagator{ treeSizeAccounting: treeSizeAccounting, treeTimeAccounting: treeTimeAccounting, propagationDelay: o.PropagationDelay, lookup: lookup, + log: log, } - log := logger.New() - log.Info().Msg("async propagator starting up...") // spawn a goroutine that watches for stale .processing dirs and fixes them diff --git a/pkg/storage/utils/decomposedfs/tree/propagator/propagator.go b/pkg/storage/utils/decomposedfs/tree/propagator/propagator.go index 008e8d9881..6d77e28e45 100644 --- a/pkg/storage/utils/decomposedfs/tree/propagator/propagator.go +++ b/pkg/storage/utils/decomposedfs/tree/propagator/propagator.go @@ -30,6 +30,7 @@ import ( "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/node" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/options" "github.com/pkg/errors" + "github.com/rs/zerolog" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/trace" ) @@ -44,10 +45,10 @@ type Propagator interface { Propagate(ctx context.Context, node *node.Node, sizediff int64) error } -func New(lookup node.PathLookup, o *options.Options) Propagator { +func New(lookup node.PathLookup, o *options.Options, log *zerolog.Logger) Propagator { switch o.Propagator { case "async": - return NewAsyncPropagator(o.TreeSizeAccounting, o.TreeTimeAccounting, o.AsyncPropagatorOptions, lookup) + return NewAsyncPropagator(o.TreeSizeAccounting, o.TreeTimeAccounting, o.AsyncPropagatorOptions, lookup, log) default: return NewSyncPropagator(o.TreeSizeAccounting, o.TreeTimeAccounting, lookup) } diff --git a/pkg/storage/utils/decomposedfs/tree/tree.go b/pkg/storage/utils/decomposedfs/tree/tree.go index 83096baf41..d579ac2bec 100644 --- a/pkg/storage/utils/decomposedfs/tree/tree.go +++ b/pkg/storage/utils/decomposedfs/tree/tree.go @@ -42,6 +42,7 @@ import ( "github.com/cs3org/reva/v2/pkg/utils" "github.com/google/uuid" "github.com/pkg/errors" + "github.com/rs/zerolog" "go-micro.dev/v4/store" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/trace" @@ -76,13 +77,13 @@ type Tree struct { type PermissionCheckFunc func(rp *provider.ResourcePermissions) bool // New returns a new instance of Tree -func New(lu node.PathLookup, bs Blobstore, o *options.Options, cache store.Store) *Tree { +func New(lu node.PathLookup, bs Blobstore, o *options.Options, cache store.Store, log *zerolog.Logger) *Tree { return &Tree{ lookup: lu, blobstore: bs, options: o, idCache: cache, - propagator: propagator.New(lu, o), + propagator: propagator.New(lu, o, log), } } diff --git a/pkg/storage/utils/decomposedfs/upload/store_test.go b/pkg/storage/utils/decomposedfs/upload/store_test.go index 1473c9e296..573b93031c 100644 --- a/pkg/storage/utils/decomposedfs/upload/store_test.go +++ b/pkg/storage/utils/decomposedfs/upload/store_test.go @@ -16,6 +16,7 @@ import ( "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/options" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/timemanager" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/tree" + "github.com/rs/zerolog" ) // TestInitNewNode calls greetings.initNewNode @@ -24,7 +25,7 @@ func TestInitNewNode(t *testing.T) { root := t.TempDir() lookup := lookup.New(metadata.NewMessagePackBackend(root, cache.Config{}), &options.Options{Root: root}, &timemanager.Manager{}) - tp := tree.New(lookup, nil, &options.Options{}, nil) + tp := tree.New(lookup, nil, &options.Options{}, nil, &zerolog.Logger{}) aspects := aspects.Aspects{ Lookup: lookup, diff --git a/pkg/storage/utils/decomposedfs/upload_async_test.go b/pkg/storage/utils/decomposedfs/upload_async_test.go index 4ce18be7b8..0f6b749865 100644 --- a/pkg/storage/utils/decomposedfs/upload_async_test.go +++ b/pkg/storage/utils/decomposedfs/upload_async_test.go @@ -172,7 +172,7 @@ var _ = Describe("Async file uploads", Ordered, func() { // setup fs pub, con = make(chan interface{}), make(chan interface{}) - tree := tree.New(lu, bs, o, store.Create()) + tree := tree.New(lu, bs, o, store.Create(), &zerolog.Logger{}) aspects := aspects.Aspects{ Lookup: lu, diff --git a/pkg/storage/utils/decomposedfs/upload_test.go b/pkg/storage/utils/decomposedfs/upload_test.go index b35f36286b..6a99f95e9e 100644 --- a/pkg/storage/utils/decomposedfs/upload_test.go +++ b/pkg/storage/utils/decomposedfs/upload_test.go @@ -137,7 +137,7 @@ var _ = Describe("File uploads", func() { AddGrant: true, }, nil).Times(1) var err error - tree := tree.New(lu, bs, o, store.Create()) + tree := tree.New(lu, bs, o, store.Create(), &zerolog.Logger{}) aspects := aspects.Aspects{ Lookup: lu, From 0750dae8e2356792a5a7f117d98582f2c459cb60 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andr=C3=A9=20Duffeck?= Date: Wed, 4 Dec 2024 11:18:18 +0100 Subject: [PATCH 2/6] Pass an initialized logger to the upload store/session --- pkg/storage/utils/decomposedfs/decomposedfs.go | 2 +- pkg/storage/utils/decomposedfs/upload/session.go | 8 +------- pkg/storage/utils/decomposedfs/upload/store.go | 5 ++++- pkg/storage/utils/decomposedfs/upload/store_test.go | 6 +++--- 4 files changed, 9 insertions(+), 12 deletions(-) diff --git a/pkg/storage/utils/decomposedfs/decomposedfs.go b/pkg/storage/utils/decomposedfs/decomposedfs.go index cf132a1cac..acb11bd2ae 100644 --- a/pkg/storage/utils/decomposedfs/decomposedfs.go +++ b/pkg/storage/utils/decomposedfs/decomposedfs.go @@ -238,7 +238,7 @@ func New(o *options.Options, aspects aspects.Aspects, log *zerolog.Logger) (stor spaceTypeIndex: spaceTypeIndex, log: log, } - fs.sessionStore = upload.NewSessionStore(fs, aspects, o.Root, o.AsyncFileUploads, o.Tokens) + fs.sessionStore = upload.NewSessionStore(fs, aspects, o.Root, o.AsyncFileUploads, o.Tokens, log) if err = fs.trashbin.Setup(fs); err != nil { return nil, err } diff --git a/pkg/storage/utils/decomposedfs/upload/session.go b/pkg/storage/utils/decomposedfs/upload/session.go index bbcad25329..734ecd02d7 100644 --- a/pkg/storage/utils/decomposedfs/upload/session.go +++ b/pkg/storage/utils/decomposedfs/upload/session.go @@ -35,7 +35,6 @@ import ( typespb "github.com/cs3org/go-cs3apis/cs3/types/v1beta1" "github.com/cs3org/reva/v2/pkg/appctx" ctxpkg "github.com/cs3org/reva/v2/pkg/ctx" - "github.com/cs3org/reva/v2/pkg/logger" "github.com/cs3org/reva/v2/pkg/storage/utils/decomposedfs/node" "github.com/cs3org/reva/v2/pkg/utils" ) @@ -49,12 +48,7 @@ type OcisSession struct { // Context returns a context with the user, logger and lockid used when initiating the upload session func (s *OcisSession) Context(ctx context.Context) context.Context { // restore logger from file info - log, _ := logger.FromConfig(&logger.LogConf{ - Output: "stderr", // TODO use config from decomposedfs - Mode: "json", // TODO use config from decomposedfs - Level: s.info.Storage["LogLevel"], - }) - sub := log.With().Int("pid", os.Getpid()).Logger() + sub := s.store.log.With().Int("pid", os.Getpid()).Logger() ctx = appctx.WithLogger(ctx, &sub) ctx = ctxpkg.ContextSetLockID(ctx, s.lockID()) ctx = ctxpkg.ContextSetUser(ctx, s.executantUser()) diff --git a/pkg/storage/utils/decomposedfs/upload/store.go b/pkg/storage/utils/decomposedfs/upload/store.go index df1e4df7a5..b05ecdca67 100644 --- a/pkg/storage/utils/decomposedfs/upload/store.go +++ b/pkg/storage/utils/decomposedfs/upload/store.go @@ -44,6 +44,7 @@ import ( "github.com/google/uuid" "github.com/pkg/errors" "github.com/rogpeppe/go-internal/lockedfile" + "github.com/rs/zerolog" tusd "github.com/tus/tusd/v2/pkg/handler" ) @@ -65,10 +66,11 @@ type OcisStore struct { async bool tknopts options.TokenOptions disableVersioning bool + log *zerolog.Logger } // NewSessionStore returns a new OcisStore -func NewSessionStore(fs storage.FS, aspects aspects.Aspects, root string, async bool, tknopts options.TokenOptions) *OcisStore { +func NewSessionStore(fs storage.FS, aspects aspects.Aspects, root string, async bool, tknopts options.TokenOptions, log *zerolog.Logger) *OcisStore { return &OcisStore{ fs: fs, lu: aspects.Lookup, @@ -79,6 +81,7 @@ func NewSessionStore(fs storage.FS, aspects aspects.Aspects, root string, async tknopts: tknopts, disableVersioning: aspects.DisableVersioning, um: aspects.UserMapper, + log: log, } } diff --git a/pkg/storage/utils/decomposedfs/upload/store_test.go b/pkg/storage/utils/decomposedfs/upload/store_test.go index 573b93031c..315334ac00 100644 --- a/pkg/storage/utils/decomposedfs/upload/store_test.go +++ b/pkg/storage/utils/decomposedfs/upload/store_test.go @@ -21,17 +21,17 @@ import ( // TestInitNewNode calls greetings.initNewNode func TestInitNewNode(t *testing.T) { - + log := &zerolog.Logger{} root := t.TempDir() lookup := lookup.New(metadata.NewMessagePackBackend(root, cache.Config{}), &options.Options{Root: root}, &timemanager.Manager{}) - tp := tree.New(lookup, nil, &options.Options{}, nil, &zerolog.Logger{}) + tp := tree.New(lookup, nil, &options.Options{}, nil, log) aspects := aspects.Aspects{ Lookup: lookup, Tree: tp, } - store := NewSessionStore(nil, aspects, root, false, options.TokenOptions{}) + store := NewSessionStore(nil, aspects, root, false, options.TokenOptions{}, log) rootNode := node.New("e48c4e7a-beac-4b82-b991-a5cff7b8c39c", "e48c4e7a-beac-4b82-b991-a5cff7b8c39c", "", "", 0, "", providerv1beta1.ResourceType_RESOURCE_TYPE_CONTAINER, &userv1beta1.UserId{}, lookup) rootNode.Exists = true From 4beb6ea57037ddc9804682c21c50c3ef8305bd0d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andr=C3=A9=20Duffeck?= Date: Mon, 9 Dec 2024 08:55:37 +0100 Subject: [PATCH 3/6] Make a now-internal method private --- pkg/logger/logger.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index b2f82cdcfb..13e9272e14 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -91,7 +91,7 @@ func parseLevel(v string) zerolog.Level { func InitLoggerOrDie(v interface{}, logLevel string) *zerolog.Logger { conf := ParseLogConfOrDie(v, logLevel) - log, err := FromConfig(conf) + log, err := fromConfig(conf) if err != nil { fmt.Fprintf(os.Stderr, "error creating logger, exiting ...") os.Exit(1) @@ -125,7 +125,7 @@ type LogConf struct { Level string `mapstructure:"level"` } -func FromConfig(conf *LogConf) (*zerolog.Logger, error) { +func fromConfig(conf *LogConf) (*zerolog.Logger, error) { if conf.Level == "" { conf.Level = zerolog.DebugLevel.String() } From 694131a5e4adf150032b6ebf86bc22dfe8e526de Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andr=C3=A9=20Duffeck?= Date: Mon, 9 Dec 2024 10:10:51 +0100 Subject: [PATCH 4/6] Add changelog --- changelog/unreleased/unified-logging.md | 3 +++ 1 file changed, 3 insertions(+) create mode 100644 changelog/unreleased/unified-logging.md diff --git a/changelog/unreleased/unified-logging.md b/changelog/unreleased/unified-logging.md new file mode 100644 index 0000000000..aef0e601af --- /dev/null +++ b/changelog/unreleased/unified-logging.md @@ -0,0 +1,3 @@ +Enhancement: Get rid of some cases of unstructured logging + +https://github.com/cs3org/reva/pull/4996 From cb62e20ce2248811e7c0e5d825637c3b04cf7466 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andr=C3=A9=20Duffeck?= Date: Mon, 9 Dec 2024 10:50:36 +0100 Subject: [PATCH 5/6] Fix tests --- tests/integration/grpc/gateway_storageprovider_test.go | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/tests/integration/grpc/gateway_storageprovider_test.go b/tests/integration/grpc/gateway_storageprovider_test.go index 0a3efca07b..f20406adf9 100644 --- a/tests/integration/grpc/gateway_storageprovider_test.go +++ b/tests/integration/grpc/gateway_storageprovider_test.go @@ -25,6 +25,7 @@ import ( "time" "github.com/cs3org/reva/v2/pkg/storagespace" + "github.com/rs/zerolog" "google.golang.org/grpc/metadata" gateway "github.com/cs3org/go-cs3apis/cs3/gateway/v1beta1" @@ -191,7 +192,7 @@ var _ = Describe("gateway", func() { "permissionssvc": revads["permissions"].GrpcAddress, "treesize_accounting": true, "treetime_accounting": true, - }, nil, nil) + }, nil, &zerolog.Logger{}) Expect(err).ToNot(HaveOccurred()) res, err := shard1Fs.CreateStorageSpace(ctx, &storagep.CreateStorageSpaceRequest{ Type: "project", @@ -217,7 +218,7 @@ var _ = Describe("gateway", func() { "permissionssvc": revads["permissions"].GrpcAddress, "treesize_accounting": true, "treetime_accounting": true, - }, nil, nil) + }, nil, &zerolog.Logger{}) Expect(err).ToNot(HaveOccurred()) res, err = shard2Fs.CreateStorageSpace(ctx, &storagep.CreateStorageSpaceRequest{ Type: "project", @@ -380,7 +381,7 @@ var _ = Describe("gateway", func() { "permissionssvc": revads["permissions"].GrpcAddress, "treesize_accounting": true, "treetime_accounting": true, - }, nil, nil) + }, nil, &zerolog.Logger{}) Expect(err).ToNot(HaveOccurred()) r, err := serviceClient.CreateHome(ctx, &storagep.CreateHomeRequest{}) @@ -405,7 +406,7 @@ var _ = Describe("gateway", func() { "permissionssvc": revads["permissions"].GrpcAddress, "treesize_accounting": true, "treetime_accounting": true, - }, nil, nil) + }, nil, &zerolog.Logger{}) Expect(err).ToNot(HaveOccurred()) res, err := serviceClient.CreateStorageSpace(ctx, &storagep.CreateStorageSpaceRequest{ Type: "project", From e79aa053bb9544cbeaf5196cada1ddf8c5e969a8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andr=C3=A9=20Duffeck?= Date: Mon, 9 Dec 2024 10:50:42 +0100 Subject: [PATCH 6/6] Do not choke on empty loggers --- pkg/storage/utils/decomposedfs/decomposedfs.go | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/pkg/storage/utils/decomposedfs/decomposedfs.go b/pkg/storage/utils/decomposedfs/decomposedfs.go index acb11bd2ae..9eb7ca2f69 100644 --- a/pkg/storage/utils/decomposedfs/decomposedfs.go +++ b/pkg/storage/utils/decomposedfs/decomposedfs.go @@ -132,6 +132,10 @@ type Decomposedfs struct { // NewDefault returns an instance with default components func NewDefault(m map[string]interface{}, bs tree.Blobstore, es events.Stream, log *zerolog.Logger) (storage.FS, error) { + if log == nil { + log = &zerolog.Logger{} + } + o, err := options.New(m) if err != nil { return nil, err @@ -178,6 +182,10 @@ func NewDefault(m map[string]interface{}, bs tree.Blobstore, es events.Stream, l // New returns an implementation of the storage.FS interface that talks to // a local filesystem. func New(o *options.Options, aspects aspects.Aspects, log *zerolog.Logger) (storage.FS, error) { + if log == nil { + log = &zerolog.Logger{} + } + err := aspects.Tree.Setup() if err != nil { log.Error().Err(err).Msg("could not setup tree")