Skip to content

Commit f9792af

Browse files
joelanfordjoelanford
committed
cmd/opm/serve: improve logging related to caches
Signed-off-by: Joe Lanford <[email protected]>
1 parent 6466294 commit f9792af

File tree

11 files changed

+84
-39
lines changed

11 files changed

+84
-39
lines changed

‎alpha/action/render.go

Lines changed: 2 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,6 @@ import (
66
"encoding/json"
77
"errors"
88
"fmt"
9-
"io"
109
"os"
1110
"path/filepath"
1211
"sort"
@@ -17,7 +16,6 @@ import (
1716
"github.com/h2non/filetype"
1817
"github.com/h2non/filetype/matchers"
1918
"github.com/operator-framework/api/pkg/operators/v1alpha1"
20-
"github.com/sirupsen/logrus"
2119
"k8s.io/apimachinery/pkg/util/sets"
2220

2321
"github.com/operator-framework/operator-registry/alpha/declcfg"
@@ -26,6 +24,7 @@ import (
2624
"github.com/operator-framework/operator-registry/pkg/image"
2725
"github.com/operator-framework/operator-registry/pkg/image/containerdregistry"
2826
"github.com/operator-framework/operator-registry/pkg/lib/bundle"
27+
"github.com/operator-framework/operator-registry/pkg/lib/log"
2928
"github.com/operator-framework/operator-registry/pkg/registry"
3029
"github.com/operator-framework/operator-registry/pkg/sqlite"
3130
)
@@ -61,12 +60,6 @@ type Render struct {
6160
skipSqliteDeprecationLog bool
6261
}
6362

64-
func nullLogger() *logrus.Entry {
65-
logger := logrus.New()
66-
logger.SetOutput(io.Discard)
67-
return logrus.NewEntry(logger)
68-
}
69-
7063
func (r Render) Run(ctx context.Context) (*declcfg.DeclarativeConfig, error) {
7164
if r.skipSqliteDeprecationLog {
7265
// exhaust once with a no-op function.
@@ -119,7 +112,7 @@ func (r Render) createRegistry() (*containerdregistry.Registry, error) {
119112
// The containerd registry impl is somewhat verbose, even on the happy path,
120113
// so discard all logger logs. Any important failures will be returned from
121114
// registry methods and eventually logged as fatal errors.
122-
containerdregistry.WithLog(nullLogger()),
115+
containerdregistry.WithLog(log.Null()),
123116
)
124117
if err != nil {
125118
return nil, err

‎cmd/opm/internal/util/util.go

Lines changed: 4 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -2,12 +2,12 @@ package util
22

33
import (
44
"errors"
5-
"io"
65
"os"
76

8-
"github.com/operator-framework/operator-registry/pkg/image/containerdregistry"
9-
"github.com/sirupsen/logrus"
107
"github.com/spf13/cobra"
8+
9+
"github.com/operator-framework/operator-registry/pkg/image/containerdregistry"
10+
"github.com/operator-framework/operator-registry/pkg/lib/log"
1111
)
1212

1313
// GetTLSOptions validates and returns TLS options set by opm flags
@@ -59,16 +59,10 @@ func CreateCLIRegistry(cmd *cobra.Command) (*containerdregistry.Registry, error)
5959
containerdregistry.WithCacheDir(cacheDir),
6060
containerdregistry.SkipTLSVerify(skipTlsVerify),
6161
containerdregistry.WithPlainHTTP(useHTTP),
62-
containerdregistry.WithLog(nullLogger()),
62+
containerdregistry.WithLog(log.Null()),
6363
)
6464
if err != nil {
6565
return nil, err
6666
}
6767
return reg, nil
6868
}
69-
70-
func nullLogger() *logrus.Entry {
71-
logger := logrus.New()
72-
logger.SetOutput(io.Discard)
73-
return logrus.NewEntry(logger)
74-
}

‎cmd/opm/render/cmd.go

Lines changed: 0 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -94,9 +94,3 @@ those images actually existing. Available template variables are:
9494
cmd.Long += "\n" + sqlite.DeprecationMessage
9595
return cmd
9696
}
97-
98-
func nullLogger() *logrus.Entry {
99-
logger := logrus.New()
100-
logger.SetOutput(io.Discard)
101-
return logrus.NewEntry(logger)
102-
}

‎cmd/opm/serve/serve.go

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -110,8 +110,6 @@ func (s *serve) run(ctx context.Context) error {
110110
s.logger.WithError(err).Warn("unable to write default nsswitch config")
111111
}
112112

113-
s.logger = s.logger.WithFields(logrus.Fields{"configs": s.configDir, "port": s.port})
114-
115113
if s.cacheDir == "" && s.cacheEnforceIntegrity {
116114
return fmt.Errorf("--cache-dir must be specified with --cache-enforce-integrity")
117115
}
@@ -123,8 +121,12 @@ func (s *serve) run(ctx context.Context) error {
123121
}
124122
defer os.RemoveAll(s.cacheDir)
125123
}
124+
s.logger = s.logger.WithFields(logrus.Fields{
125+
"configs": s.configDir,
126+
"cache": s.cacheDir,
127+
})
126128

127-
store, err := cache.New(s.cacheDir)
129+
store, err := cache.New(s.cacheDir, cache.WithLog(s.logger))
128130
if err != nil {
129131
return err
130132
}
@@ -146,6 +148,8 @@ func (s *serve) run(ctx context.Context) error {
146148
return nil
147149
}
148150

151+
s.logger = s.logger.WithFields(logrus.Fields{"port": s.port})
152+
149153
lis, err := net.Listen("tcp", ":"+s.port)
150154
if err != nil {
151155
return fmt.Errorf("failed to listen: %s", err)

‎pkg/cache/cache.go

Lines changed: 40 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -12,10 +12,12 @@ import (
1212
"strings"
1313
"sync"
1414

15+
"github.com/sirupsen/logrus"
1516
"golang.org/x/sync/errgroup"
1617

1718
"github.com/operator-framework/operator-registry/alpha/declcfg"
1819
"github.com/operator-framework/operator-registry/pkg/api"
20+
"github.com/operator-framework/operator-registry/pkg/lib/log"
1921
"github.com/operator-framework/operator-registry/pkg/registry"
2022
)
2123

@@ -29,6 +31,7 @@ type Cache interface {
2931
}
3032

3133
type backend interface {
34+
Name() string
3235
IsCachePresent() bool
3336

3437
Init() error
@@ -47,22 +50,41 @@ type backend interface {
4750
PutDigest(context.Context, string) error
4851
}
4952

53+
type CacheOptions struct {
54+
Log *logrus.Entry
55+
}
56+
57+
func WithLog(log *logrus.Entry) CacheOption {
58+
return func(o *CacheOptions) {
59+
o.Log = log
60+
}
61+
}
62+
63+
type CacheOption func(*CacheOptions)
64+
5065
// New creates a new Cache. It chooses a cache implementation based
5166
// on the files it finds in the cache directory, with a preference for the
5267
// latest iteration of the cache implementation. If the cache directory
5368
// is non-empty and a supported cache format is not found, an error is returned.
54-
func New(cacheDir string) (Cache, error) {
55-
cacheBackend, err := getDefaultBackend(cacheDir)
69+
func New(cacheDir string, cacheOpts ...CacheOption) (Cache, error) {
70+
opts := &CacheOptions{
71+
Log: log.Null(),
72+
}
73+
for _, opt := range cacheOpts {
74+
opt(opts)
75+
}
76+
cacheBackend, err := getDefaultBackend(cacheDir, opts.Log)
5677
if err != nil {
5778
return nil, err
5879
}
80+
5981
if err := cacheBackend.Open(); err != nil {
6082
return nil, fmt.Errorf("open cache: %v", err)
6183
}
62-
return &cache{backend: cacheBackend}, nil
84+
return &cache{backend: cacheBackend, log: opts.Log}, nil
6385
}
6486

65-
func getDefaultBackend(cacheDir string) (backend, error) {
87+
func getDefaultBackend(cacheDir string, log *logrus.Entry) (backend, error) {
6688
entries, err := os.ReadDir(cacheDir)
6789
if err != nil && !errors.Is(err, os.ErrNotExist) {
6890
return nil, fmt.Errorf("detect cache format: read cache directory: %v", err)
@@ -74,17 +96,26 @@ func getDefaultBackend(cacheDir string) (backend, error) {
7496
}
7597

7698
if len(entries) == 0 {
99+
log.WithField("backend", backends[0].Name()).Info("cache directory is empty, using preferred backend")
77100
return backends[0], nil
78101
}
79102

80103
for _, backend := range backends {
81104
if backend.IsCachePresent() {
105+
log.WithField("backend", backend.Name()).Info("found existing cache contents")
82106
return backend, nil
83107
}
84108
}
85109

86110
// Anything else is unexpected.
87-
return nil, fmt.Errorf("cache directory has unexpected contents")
111+
entryNames := make([]string, 0, len(entries))
112+
for _, entry := range entries {
113+
if entry.Name() == "." {
114+
continue
115+
}
116+
entryNames = append(entryNames, entry.Name())
117+
}
118+
return nil, fmt.Errorf("cache directory has unexpected contents: %v", strings.Join(entryNames, ","))
88119
}
89120

90121
func LoadOrRebuild(ctx context.Context, c Cache, fbc fs.FS) error {
@@ -100,6 +131,7 @@ var _ Cache = &cache{}
100131

101132
type cache struct {
102133
backend backend
134+
log *logrus.Entry
103135
packageIndex
104136
}
105137

@@ -199,6 +231,7 @@ func (c *cache) CheckIntegrity(ctx context.Context, fbc fs.FS) error {
199231
return fmt.Errorf("compute digest: %v", err)
200232
}
201233
if existingDigest != computedDigest {
234+
c.log.WithField("existingDigest", existingDigest).WithField("computedDigest", computedDigest).Warn("cache requires rebuild")
202235
return fmt.Errorf("cache requires rebuild: cache reports digest as %q, but computed digest is %q", existingDigest, computedDigest)
203236
}
204237
return nil
@@ -209,6 +242,8 @@ func (c *cache) Build(ctx context.Context, fbcFsys fs.FS) error {
209242
oldUmask := umask(000)
210243
defer umask(oldUmask)
211244

245+
c.log.Info("building cache")
246+
212247
if err := c.backend.Init(); err != nil {
213248
return fmt.Errorf("init cache: %v", err)
214249
}

‎pkg/cache/cache_test.go

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88

99
"github.com/stretchr/testify/require"
1010

11+
"github.com/operator-framework/operator-registry/pkg/lib/log"
1112
"github.com/operator-framework/operator-registry/pkg/registry"
1213
)
1314

@@ -222,8 +223,8 @@ func genTestCaches(t *testing.T, fbcFS fs.FS) map[string]Cache {
222223
t.Helper()
223224

224225
caches := map[string]Cache{
225-
"json": &cache{backend: newJSONBackend(t.TempDir())},
226-
"pogreb.v1": &cache{backend: newPogrebV1Backend(t.TempDir())},
226+
"json": &cache{backend: newJSONBackend(t.TempDir()), log: log.Null()},
227+
"pogreb.v1": &cache{backend: newPogrebV1Backend(t.TempDir()), log: log.Null()},
227228
}
228229

229230
for _, c := range caches {

‎pkg/cache/json.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,10 @@ type jsonBackend struct {
4040
bundles bundleKeys
4141
}
4242

43+
func (q *jsonBackend) Name() string {
44+
return "json"
45+
}
46+
4347
func (q *jsonBackend) IsCachePresent() bool {
4448
entries, err := os.ReadDir(q.baseDir)
4549
if err != nil && !errors.Is(err, os.ErrNotExist) {

‎pkg/cache/json_test.go

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,11 +8,13 @@ import (
88
"testing"
99

1010
"github.com/stretchr/testify/require"
11+
12+
"github.com/operator-framework/operator-registry/pkg/lib/log"
1113
)
1214

1315
func TestJSON_StableDigest(t *testing.T) {
1416
cacheDir := t.TempDir()
15-
c := &cache{backend: newJSONBackend(cacheDir)}
17+
c := &cache{backend: newJSONBackend(cacheDir), log: log.Null()}
1618
require.NoError(t, c.Build(context.Background(), validFS))
1719

1820
actualDigest, err := c.backend.GetDigest(context.Background())
@@ -94,7 +96,7 @@ func TestJSON_CheckIntegrity(t *testing.T) {
9496
for _, tc := range testCases {
9597
t.Run(tc.name, func(t *testing.T) {
9698
cacheDir := t.TempDir()
97-
c := &cache{backend: newJSONBackend(cacheDir)}
99+
c := &cache{backend: newJSONBackend(cacheDir), log: log.Null()}
98100

99101
if tc.build {
100102
require.NoError(t, c.Build(context.Background(), tc.fbcFS))

‎pkg/cache/pogrebv1.go

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,10 @@ type pogrebV1Backend struct {
4545
bundles bundleKeys
4646
}
4747

48+
func (q *pogrebV1Backend) Name() string {
49+
return pograbV1CacheDir
50+
}
51+
4852
func (q *pogrebV1Backend) IsCachePresent() bool {
4953
entries, err := os.ReadDir(q.baseDir)
5054
if err != nil && !errors.Is(err, os.ErrNotExist) {

‎pkg/cache/pogrebv1_test.go

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,11 +9,12 @@ import (
99
"github.com/stretchr/testify/require"
1010

1111
"github.com/operator-framework/operator-registry/pkg/api"
12+
"github.com/operator-framework/operator-registry/pkg/lib/log"
1213
)
1314

1415
func TestPogrebV1_StableDigest(t *testing.T) {
1516
cacheDir := t.TempDir()
16-
c := &cache{backend: newPogrebV1Backend(cacheDir)}
17+
c := &cache{backend: newPogrebV1Backend(cacheDir), log: log.Null()}
1718
require.NoError(t, c.Build(context.Background(), validFS))
1819

1920
actualDigest, err := c.backend.GetDigest(context.Background())
@@ -94,7 +95,7 @@ func TestPogrebV1_CheckIntegrity(t *testing.T) {
9495
for _, tc := range testCases {
9596
t.Run(tc.name, func(t *testing.T) {
9697
cacheDir := t.TempDir()
97-
c := &cache{backend: newPogrebV1Backend(cacheDir)}
98+
c := &cache{backend: newPogrebV1Backend(cacheDir), log: log.Null()}
9899

99100
if tc.build {
100101
require.NoError(t, c.Build(context.Background(), tc.fbcFS))

‎pkg/lib/log/null.go

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,13 @@
1+
package log
2+
3+
import (
4+
"io"
5+
6+
"github.com/sirupsen/logrus"
7+
)
8+
9+
func Null() *logrus.Entry {
10+
l := logrus.New()
11+
l.SetOutput(io.Discard)
12+
return logrus.NewEntry(l)
13+
}

0 commit comments

Comments
 (0)