diff --git a/cmd/storage/main.go b/cmd/storage/main.go index aeb9e5b..d6e8cb0 100644 --- a/cmd/storage/main.go +++ b/cmd/storage/main.go @@ -18,6 +18,7 @@ package main import ( "log" + "log/slog" "os" "github.com/jmoiron/sqlx" @@ -30,6 +31,12 @@ import ( ) func main() { + // TODO: add CLI flags + opts := slog.HandlerOptions{ + Level: slog.LevelDebug, + } + logger := slog.New(slog.NewJSONHandler(os.Stdout, &opts)).With("component", "storage") + db, err := sqlx.Connect("sqlite", "storage.db") if err != nil { log.Fatalln(err) @@ -40,7 +47,7 @@ func main() { db.MustExec(storage.CreateVulnerabilityReportTableSQL) ctx := genericapiserver.SetupSignalContext() - options := server.NewWardleServerOptions(os.Stdout, os.Stderr, db) + options := server.NewWardleServerOptions(db, logger) cmd := server.NewCommandStartWardleServer(ctx, options) code := cli.Run(cmd) os.Exit(code) diff --git a/cmd/storage/server/start.go b/cmd/storage/server/start.go index 9b36b80..956e8f8 100644 --- a/cmd/storage/server/start.go +++ b/cmd/storage/server/start.go @@ -19,7 +19,7 @@ package server import ( "context" "fmt" - "io" + "log/slog" "math" "net" @@ -46,15 +46,13 @@ import ( // WardleServerOptions contains state for master/api server type WardleServerOptions struct { - RecommendedOptions *genericoptions.RecommendedOptions - + RecommendedOptions *genericoptions.RecommendedOptions SharedInformerFactory informers.SharedInformerFactory - StdOut io.Writer - StdErr io.Writer - - DB *sqlx.DB AlternateDNS []string + + DB *sqlx.DB + Logger *slog.Logger } func WardleVersionToKubeVersion(ver *version.Version) *version.Version { @@ -77,17 +75,14 @@ func WardleVersionToKubeVersion(ver *version.Version) *version.Version { } // NewWardleServerOptions returns a new WardleServerOptions -func NewWardleServerOptions(out, errOut io.Writer, db *sqlx.DB) *WardleServerOptions { +func NewWardleServerOptions(db *sqlx.DB, logger *slog.Logger) *WardleServerOptions { o := &WardleServerOptions{ RecommendedOptions: genericoptions.NewRecommendedOptions( "/registry/sbombastic.rancher.io", apiserver.Codecs.LegacyCodec(v1alpha1.SchemeGroupVersion), ), - - DB: db, - - StdOut: out, - StdErr: errOut, + DB: db, + Logger: logger, } // Disable etcd @@ -216,7 +211,7 @@ func (o WardleServerOptions) RunWardleServer(ctx context.Context) error { return err } - server, err := config.Complete().New(o.DB) + server, err := config.Complete().New(o.DB, o.Logger) if err != nil { return fmt.Errorf("error creating server: %w", err) } diff --git a/internal/apiserver/apiserver.go b/internal/apiserver/apiserver.go index 968a851..2feded1 100644 --- a/internal/apiserver/apiserver.go +++ b/internal/apiserver/apiserver.go @@ -18,6 +18,7 @@ package apiserver import ( "fmt" + "log/slog" "github.com/jmoiron/sqlx" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -97,7 +98,7 @@ func (cfg *Config) Complete() CompletedConfig { } // New returns a new instance of WardleServer from the given config. -func (c completedConfig) New(db *sqlx.DB) (*WardleServer, error) { +func (c completedConfig) New(db *sqlx.DB, logger *slog.Logger) (*WardleServer, error) { genericServer, err := c.GenericConfig.New("sample-apiserver", genericapiserver.NewEmptyDelegate()) if err != nil { return nil, fmt.Errorf("error creating generic server: %w", err) @@ -109,15 +110,15 @@ func (c completedConfig) New(db *sqlx.DB) (*WardleServer, error) { apiGroupInfo := genericapiserver.NewDefaultAPIGroupInfo(v1alpha1.GroupName, Scheme, metav1.ParameterCodec, Codecs) - imageStore, err := storage.NewImageStore(Scheme, c.GenericConfig.RESTOptionsGetter, db) + imageStore, err := storage.NewImageStore(Scheme, c.GenericConfig.RESTOptionsGetter, db, logger) if err != nil { return nil, fmt.Errorf("error creating Image store: %w", err) } - sbomStore, err := storage.NewSBOMStore(Scheme, c.GenericConfig.RESTOptionsGetter, db) + sbomStore, err := storage.NewSBOMStore(Scheme, c.GenericConfig.RESTOptionsGetter, db, logger) if err != nil { return nil, fmt.Errorf("error creating SBOM store: %w", err) } - vulnerabilityReportStore, err := storage.NewVulnerabilityReport(Scheme, c.GenericConfig.RESTOptionsGetter, db) + vulnerabilityReportStore, err := storage.NewVulnerabilityReport(Scheme, c.GenericConfig.RESTOptionsGetter, db, logger) if err != nil { return nil, fmt.Errorf("error creating VulnerabilityReport store: %w", err) } diff --git a/internal/storage/image_store.go b/internal/storage/image_store.go index 9495063..80523e7 100644 --- a/internal/storage/image_store.go +++ b/internal/storage/image_store.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/jmoiron/sqlx" "github.com/rancher/sbombastic/api/storage/v1alpha1" @@ -23,7 +24,7 @@ CREATE TABLE IF NOT EXISTS images ( ` // NewImageStore returns a store registry that will work against API services. -func NewImageStore(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, db *sqlx.DB) (*registry.Store, error) { +func NewImageStore(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, db *sqlx.DB, logger *slog.Logger) (*registry.Store, error) { strategy := newImageStrategy(scheme) newFunc := func() runtime.Object { return &v1alpha1.Image{} } @@ -42,6 +43,7 @@ func NewImageStore(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, table: "images", newFunc: newFunc, newListFunc: newListFunc, + logger: logger.With("store", "image"), }, }, CreateStrategy: strategy, diff --git a/internal/storage/sbom_store.go b/internal/storage/sbom_store.go index 503ac4b..bf028ec 100644 --- a/internal/storage/sbom_store.go +++ b/internal/storage/sbom_store.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/jmoiron/sqlx" "github.com/rancher/sbombastic/api/storage/v1alpha1" @@ -23,7 +24,7 @@ CREATE TABLE IF NOT EXISTS sboms ( ` // NewSBOMStore returns a store registry that will work against API services. -func NewSBOMStore(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, db *sqlx.DB) (*registry.Store, error) { +func NewSBOMStore(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, db *sqlx.DB, logger *slog.Logger) (*registry.Store, error) { strategy := newSBOMStrategy(scheme) newFunc := func() runtime.Object { return &v1alpha1.SBOM{} } @@ -42,6 +43,7 @@ func NewSBOMStore(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, table: "sboms", newFunc: newFunc, newListFunc: newListFunc, + logger: logger.With("store", "sbom"), }, }, CreateStrategy: strategy, diff --git a/internal/storage/store.go b/internal/storage/store.go index 7b02743..fbe858a 100644 --- a/internal/storage/store.go +++ b/internal/storage/store.go @@ -6,7 +6,7 @@ import ( "database/sql" "encoding/json" "errors" - "log" + "log/slog" "reflect" "strings" @@ -39,6 +39,7 @@ type store struct { table string newFunc func() runtime.Object newListFunc func() runtime.Object + logger *slog.Logger } // Returns Versioner associated with this interface. @@ -50,6 +51,8 @@ func (s *store) Versioner() storage.Versioner { // in seconds (0 means forever). If no error is returned and out is not nil, out will be // set to the read value from database. func (s *store) Create(ctx context.Context, key string, obj, out runtime.Object, _ uint64) error { + s.logger.DebugContext(ctx, "Creating object", "key", key, "object", obj) + name, namespace := extractNameAndNamespace(key) if name == "" || namespace == "" { return storage.NewInternalErrorf("invalid key: %s", key) @@ -109,6 +112,8 @@ func (s *store) Delete( ctx context.Context, key string, out runtime.Object, preconditions *storage.Preconditions, validateDeletion storage.ValidateObjectFunc, _ runtime.Object, ) error { + s.logger.DebugContext(ctx, "Deleting object", "key", key) + name, namespace := extractNameAndNamespace(key) if name == "" || namespace == "" { return storage.NewInternalErrorf("invalid key: %s", key) @@ -120,7 +125,7 @@ func (s *store) Delete( } defer func() { if err := tx.Rollback(); err != nil && !errors.Is(err, sql.ErrTxDone) { - log.Printf("failed to rollback transaction: %v", err) + s.logger.ErrorContext(ctx, "failed to rollback transaction", "error", err) } }() @@ -171,6 +176,8 @@ func (s *store) Delete( // If resource version is "0", this interface will get current object at given key // and send it in an "ADDED" event, before watch starts. func (s *store) Watch(ctx context.Context, key string, opts storage.ListOptions) (watch.Interface, error) { + s.logger.DebugContext(ctx, "Watching object", "key", key, "options", opts) + if opts.ResourceVersion == "" { return s.broadcaster.Watch() } @@ -217,6 +224,8 @@ func (s *store) Watch(ctx context.Context, key string, opts storage.ListOptions) // The returned contents may be delayed, but it is guaranteed that they will // match 'opts.ResourceVersion' according 'opts.ResourceVersionMatch'. func (s *store) Get(ctx context.Context, key string, opts storage.GetOptions, objPtr runtime.Object) error { + s.logger.DebugContext(ctx, "Getting object", "key", key, "options", opts) + name, namespace := extractNameAndNamespace(key) if name == "" || namespace == "" { return storage.NewInternalErrorf("invalid key: %s", key) @@ -259,6 +268,8 @@ func (s *store) Get(ctx context.Context, key string, opts storage.GetOptions, ob // The returned contents may be delayed, but it is guaranteed that they will // match 'opts.ResourceVersion' according 'opts.ResourceVersionMatch'. func (s *store) GetList(ctx context.Context, key string, opts storage.ListOptions, listObj runtime.Object) error { + s.logger.DebugContext(ctx, "Getting list", "key", key, "options", opts) + queryBuilder := sq.Select("*").From(s.table) namespace := extractNamespace(key) if namespace != "" { @@ -345,6 +356,8 @@ func (s *store) GuaranteedUpdate( tryUpdate storage.UpdateFunc, _ runtime.Object, ) error { + s.logger.DebugContext(ctx, "Guaranteed update", "key", key) + name, namespace := extractNameAndNamespace(key) if name == "" || namespace == "" { return storage.NewInternalErrorf("invalid key: %s", key) @@ -357,7 +370,7 @@ func (s *store) GuaranteedUpdate( defer func() { if err := tx.Rollback(); err != nil && !errors.Is(err, sql.ErrTxDone) { - log.Printf("failed to rollback transaction: %v", err) + s.logger.ErrorContext(ctx, "failed to rollback transaction", "error", err) } }() @@ -401,6 +414,8 @@ func (s *store) GuaranteedUpdate( updatedObj, _, err := tryUpdate(obj, storage.ResponseMeta{}) if err != nil { if apierrors.IsConflict(err) && strings.Contains(err.Error(), registry.OptimisticLockErrorMsg) { + s.logger.DebugContext(ctx, "Optimistic lock conflict", "key", key, "error", err) + // retry update on optimistic lock conflict continue } @@ -454,6 +469,8 @@ func (s *store) GuaranteedUpdate( // Count returns number of different entries under the key (generally being path prefix). func (s *store) Count(key string) (int64, error) { + s.logger.Debug("Counting objects", "key", key) + namespace := extractNamespace(key) queryBuilder := sq.Select("COUNT(*)").From(s.table) diff --git a/internal/storage/store_test.go b/internal/storage/store_test.go index 404a692..bcb68d5 100644 --- a/internal/storage/store_test.go +++ b/internal/storage/store_test.go @@ -2,6 +2,7 @@ package storage import ( "context" + "log/slog" "testing" "github.com/stretchr/testify/suite" @@ -42,6 +43,7 @@ func (suite *storeTestSuite) SetupTest() { table: "sboms", newFunc: func() runtime.Object { return &v1alpha1.SBOM{} }, newListFunc: func() runtime.Object { return &v1alpha1.SBOMList{} }, + logger: slog.Default(), } } diff --git a/internal/storage/vulnerabilityreport_store.go b/internal/storage/vulnerabilityreport_store.go index d3b3e48..2b40d68 100644 --- a/internal/storage/vulnerabilityreport_store.go +++ b/internal/storage/vulnerabilityreport_store.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/jmoiron/sqlx" "github.com/rancher/sbombastic/api/storage/v1alpha1" @@ -23,7 +24,7 @@ CREATE TABLE IF NOT EXISTS vulnerabilityreports ( ` // NewVulnerabilityReport returns a store registry that will work against API services. -func NewVulnerabilityReport(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, db *sqlx.DB) (*registry.Store, error) { +func NewVulnerabilityReport(scheme *runtime.Scheme, optsGetter generic.RESTOptionsGetter, db *sqlx.DB, logger *slog.Logger) (*registry.Store, error) { strategy := newVulnerabilityReportStrategy(scheme) newFunc := func() runtime.Object { return &v1alpha1.VulnerabilityReport{} } @@ -42,6 +43,7 @@ func NewVulnerabilityReport(scheme *runtime.Scheme, optsGetter generic.RESTOptio table: "vulnerabilityreports", newFunc: newFunc, newListFunc: newListFunc, + logger: logger.With("store", "vulnerabilityreport"), }, }, CreateStrategy: strategy,