diff --git a/e2e/go.mod b/e2e/go.mod index b57aeedf..68c5656a 100644 --- a/e2e/go.mod +++ b/e2e/go.mod @@ -4,6 +4,7 @@ go 1.15 require ( github.com/Masterminds/goutils v1.1.1 + github.com/hashicorp/go-hclog v0.16.1 // indirect github.com/hashicorp/vault/sdk v0.2.1 github.com/onsi/ginkgo v1.16.4 github.com/onsi/gomega v1.16.0 diff --git a/e2e/tests/flow/complete_cycle_test.go b/e2e/tests/flow/complete_cycle_test.go index 09cfa0bd..78924ead 100644 --- a/e2e/tests/flow/complete_cycle_test.go +++ b/e2e/tests/flow/complete_cycle_test.go @@ -11,6 +11,7 @@ import ( "strings" "time" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/vault/sdk/logical" . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" @@ -40,7 +41,7 @@ var _ = Describe("Complete cycle", func() { serverInitVariables := func() { var err error - backend, err = server.NewBackend() + backend, err = server.NewBackend(hclog.L()) Ω(err).ShouldNot(HaveOccurred()) storage = &logical.InmemStorage{} diff --git a/server/.gitignore b/server/.gitignore index e36ae1bc..199f625b 100644 --- a/server/.gitignore +++ b/server/.gitignore @@ -1,6 +1,5 @@ # Runtime /vault /publisher -/trdl.log /.minio_data /.run diff --git a/server/Makefile b/server/Makefile index fed5463f..7e75d9eb 100644 --- a/server/Makefile +++ b/server/Makefile @@ -28,9 +28,6 @@ vault/plugins/vault-plugin-secrets-trdl: $(GOSRC) build: vault/plugins/vault-plugin-secrets-trdl .run: vault/plugins/vault-plugin-secrets-trdl - rm -f trdl.log - touch trdl.log - # Run minio, create bucket docker rm -f trdl_dev_minio || true docker run --rm --volume $$(pwd):/wrk alpine rm -rf /wrk/.minio_data @@ -77,14 +74,13 @@ build: vault/plugins/vault-plugin-secrets-trdl touch .run tail: - tail -f trdl.log + docker logs -f trdl_dev_vault clean: rm -f ./vault/plugins/vault-plugin-secrets-trdl docker rm -f trdl_dev_minio || true docker rm -f trdl_dev_vault || true docker run --rm --volume $$(pwd):/wrk alpine rm -rf /wrk/.minio_data - rm -f trdl.log install-to-dev: build : "$${TRDL_DEV_SSH_HOST:?not set}" diff --git a/server/backend.go b/server/backend.go index f482a850..fb3b6fba 100644 --- a/server/backend.go +++ b/server/backend.go @@ -4,6 +4,7 @@ import ( "context" "fmt" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/vault/sdk/framework" "github.com/hashicorp/vault/sdk/logical" @@ -32,7 +33,7 @@ type Backend struct { var _ logical.Factory = Factory func Factory(ctx context.Context, conf *logical.BackendConfig) (logical.Backend, error) { - b, err := NewBackend() + b, err := NewBackend(conf.Logger) if err != nil { return nil, err } @@ -48,9 +49,9 @@ func Factory(ctx context.Context, conf *logical.BackendConfig) (logical.Backend, return b, nil } -func NewBackend() (*Backend, error) { - tasksManager := tasks_manager.NewManager() - publisherManager := publisher.NewPublisher() +func NewBackend(logger hclog.Logger) (*Backend, error) { + tasksManager := tasks_manager.NewManager(logger) + publisherManager := publisher.NewPublisher(logger) b := &Backend{ TasksManager: tasksManager, diff --git a/server/cmd/vault-plugin-secrets-trdl/main.go b/server/cmd/vault-plugin-secrets-trdl/main.go index 66d674ec..ee747113 100644 --- a/server/cmd/vault-plugin-secrets-trdl/main.go +++ b/server/cmd/vault-plugin-secrets-trdl/main.go @@ -1,7 +1,6 @@ package main import ( - "fmt" "net" "net/http" _ "net/http/pprof" @@ -22,19 +21,6 @@ func main() { IncludeLocation: true, } - var logFilePath string - if v := os.Getenv("VAULT_PLUGIN_SECRETS_TRDL_LOG_FILE"); v != "" { - logFilePath = v - } else { - logFilePath = "trdl.log" - } - - logFile, err := os.OpenFile(logFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o666) - if err != nil { - panic(fmt.Sprintf("failed to open trdl.log file: %s", err)) - } - hclogOpts.Output = logFile - if util.IsEnvVarTrue("VAULT_PLUGIN_SECRETS_TRDL_DEBUG") { hclogOpts.Level = hclog.Trace @@ -60,11 +46,9 @@ func main() { tlsProviderFunc := api.VaultPluginTLSProvider(tlsConfig) if err := plugin.Serve(&plugin.ServeOpts{ - Logger: hclog.Default(), BackendFactoryFunc: trdl.Factory, TLSProviderFunc: tlsProviderFunc, }); err != nil { - hclog.L().Error("plugin shutting down", "error", err) os.Exit(1) } } @@ -72,13 +56,13 @@ func main() { func servePprof() { listener, err := net.Listen("tcp", "127.0.0.1:0") if err != nil { - hclog.L().Warn(fmt.Sprintf("can't serve pprof: %s", err)) + // hclog.L().Warn(fmt.Sprintf("can't serve pprof: %s", err)) return } - hclog.L().Info(fmt.Sprintf("pprof for PID %d will be available on http://127.0.0.1:%d/debug/pprof", os.Getpid(), listener.Addr().(*net.TCPAddr).Port)) + // hclog.L().Info(fmt.Sprintf("pprof for PID %d will be available on http://127.0.0.1:%d/debug/pprof", os.Getpid(), listener.Addr().(*net.TCPAddr).Port)) if err := http.Serve(listener, nil); err != nil { - hclog.L().Warn(fmt.Sprintf("can't serve pprof: %s", err)) + // hclog.L().Warn(fmt.Sprintf("can't serve pprof: %s", err)) return } } diff --git a/server/path_publish.go b/server/path_publish.go index 65397e4a..eac70713 100644 --- a/server/path_publish.go +++ b/server/path_publish.go @@ -107,10 +107,10 @@ func (b *Backend) pathPublish(ctx context.Context, req *logical.Request, fields taskUUID, err := b.TasksManager.RunTask(context.Background(), req.Storage, func(ctx context.Context, storage logical.Storage) error { logboek.Context(ctx).Default().LogF("Started task\n") - hclog.L().Debug("Started task") + b.Logger().Debug("Started task") logboek.Context(ctx).Default().LogF("Cloning git repo\n") - hclog.L().Debug("Cloning git repo") + b.Logger().Debug("Cloning git repo") gitBranch := cfg.GitTrdlChannelsBranch gitRepo, err := cloneGitRepositoryBranch(cfg.GitRepoUrl, gitBranch, gitUsername, gitPassword) @@ -126,14 +126,14 @@ func (b *Backend) pathPublish(ctx context.Context, req *logical.Request, fields if lastPublishedGitCommit == headCommit { logboek.Context(ctx).Default().LogF("Head commit %q not changed: skipping publish task\n", headCommit) - hclog.L().Debug(fmt.Sprintf("Head commit %q not changed: skipping publish task", headCommit)) + b.Logger().Debug(fmt.Sprintf("Head commit %q not changed: skipping publish task", headCommit)) return nil } if lastPublishedGitCommit != "" { logboek.Context(ctx).Default().LogF("Checking previously published commit %q is ancestor to the current head commit %q\n", lastPublishedGitCommit, headCommit) - hclog.L().Debug(fmt.Sprintf("Checking previously published commit %q is ancestor to the current head commit %q", lastPublishedGitCommit, headCommit)) + b.Logger().Debug(fmt.Sprintf("Checking previously published commit %q is ancestor to the current head commit %q", lastPublishedGitCommit, headCommit)) isAncestor, err := trdlGit.IsAncestor(gitRepo, lastPublishedGitCommit, headRef.Hash().String()) if err != nil { @@ -146,7 +146,7 @@ func (b *Backend) pathPublish(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Verifying tag PGP signatures of the commit %q\n", headCommit) - hclog.L().Debug(fmt.Sprintf("Verifying tag PGP signatures of the commit %q", headCommit)) + b.Logger().Debug(fmt.Sprintf("Verifying tag PGP signatures of the commit %q", headCommit)) trustedPGPPublicKeys, err := pgp.GetTrustedPGPPublicKeys(ctx, req.Storage) if err != nil { @@ -158,10 +158,10 @@ func (b *Backend) pathPublish(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Verified commit signatures\n") - hclog.L().Debug("Verified commit signatures") + b.Logger().Debug("Verified commit signatures") logboek.Context(ctx).Default().LogF("Getting trdl_channels.yaml configuration from the commit %q\n", headCommit) - hclog.L().Debug(fmt.Sprintf("Getting trdl_channels.yaml configuration from the commit %q\n", headCommit)) + b.Logger().Debug(fmt.Sprintf("Getting trdl_channels.yaml configuration from the commit %q\n", headCommit)) cfg, err := GetTrdlChannelsConfig(gitRepo) if err != nil { @@ -170,34 +170,34 @@ func (b *Backend) pathPublish(ctx context.Context, req *logical.Request, fields cfgDump, _ := yaml.Marshal(cfg) logboek.Context(ctx).Default().LogF("Got trdl channels config:\n%s\n---\n", cfgDump) - hclog.L().Debug(fmt.Sprintf("Got trdl channels config:\n%s\n---", cfgDump)) + b.Logger().Debug(fmt.Sprintf("Got trdl channels config:\n%s\n---", cfgDump)) - if err := ValidatePublishConfig(ctx, b.Publisher, publisherRepository, cfg); err != nil { + if err := ValidatePublishConfig(ctx, b.Publisher, publisherRepository, cfg, b.Logger()); err != nil { return fmt.Errorf("unable to publish bad config: %s", err) } logboek.Context(ctx).Default().LogF("Publishing trdl channels config into the TUF repository\n") - hclog.L().Debug("Publishing trdl channels config into the TUF repository") + b.Logger().Debug("Publishing trdl channels config into the TUF repository") if err := b.Publisher.StageChannelsConfig(ctx, publisherRepository, cfg); err != nil { return fmt.Errorf("error publishing trdl channels into the repository: %s", err) } logboek.Context(ctx).Default().LogF("Committing TUF repository state\n") - hclog.L().Debug("Committing TUF repository state") + b.Logger().Debug("Committing TUF repository state") if err := publisherRepository.CommitStaged(ctx); err != nil { return fmt.Errorf("unable to commit new tuf repository state: %s", err) } logboek.Context(ctx).Default().LogF("Storing published commit record %q into the storage\n", headCommit) - hclog.L().Debug(fmt.Sprintf("Storing published commit record %q into the storage", headCommit)) + b.Logger().Debug(fmt.Sprintf("Storing published commit record %q into the storage", headCommit)) if err := storage.Put(ctx, &logical.StorageEntry{Key: storageKeyLastPublishedGitCommit, Value: []byte(headCommit)}); err != nil { return fmt.Errorf("unable to put %q into storage: %s", storageKeyLastPublishedGitCommit, err) } logboek.Context(ctx).Default().LogF("Task finished\n") - hclog.L().Debug("Task finished") + b.Logger().Debug("Task finished") return nil }) @@ -220,14 +220,14 @@ func (b *Backend) pathPublish(ctx context.Context, req *logical.Request, fields }, nil } -func ValidatePublishConfig(ctx context.Context, publisher publisher.Interface, publisherRepository publisher.RepositoryInterface, config *config.TrdlChannels) error { +func ValidatePublishConfig(ctx context.Context, publisher publisher.Interface, publisherRepository publisher.RepositoryInterface, config *config.TrdlChannels, logger hclog.Logger) error { existingReleases, err := publisher.GetExistingReleases(ctx, publisherRepository) if err != nil { return fmt.Errorf("error getting existing targets: %s", err) } logboek.Context(ctx).Default().LogF("Got existing releases list: %v\n", existingReleases) - hclog.L().Debug(fmt.Sprintf("Got existing releases list: %v\n", existingReleases)) + logger.Debug(fmt.Sprintf("Got existing releases list: %v\n", existingReleases)) var nonExistingReleases []string diff --git a/server/path_release.go b/server/path_release.go index 32dddbb3..ddd63b34 100644 --- a/server/path_release.go +++ b/server/path_release.go @@ -120,10 +120,10 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields taskUUID, err := b.TasksManager.RunTask(context.Background(), req.Storage, func(ctx context.Context, storage logical.Storage) error { logboek.Context(ctx).Default().LogF("Started task\n") - hclog.L().Debug("Started task") + b.Logger().Debug("Started task") logboek.Context(ctx).Default().LogF("Cloning git repo\n") - hclog.L().Debug("Cloning git repo") + b.Logger().Debug("Cloning git repo") gitRepo, err := cloneGitRepositoryTag(cfg.GitRepoUrl, gitTag, gitUsername, gitPassword) if err != nil { @@ -131,7 +131,7 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Verifying tag PGP signatures of the git tag %q\n", gitTag) - hclog.L().Debug("Verifying tag PGP signatures of the git tag %q", gitTag) + b.Logger().Debug("Verifying tag PGP signatures of the git tag %q", gitTag) trustedPGPPublicKeys, err := pgp.GetTrustedPGPPublicKeys(ctx, req.Storage) if err != nil { @@ -143,7 +143,7 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Getting trdl.yaml configuration from the git tag %q\n", gitTag) - hclog.L().Debug(fmt.Sprintf("Getting trdl.yaml configuration from the git tag %q\n", gitTag)) + b.Logger().Debug(fmt.Sprintf("Getting trdl.yaml configuration from the git tag %q\n", gitTag)) trdlCfg, err := getTrdlConfig(gitRepo, gitTag) if err != nil { @@ -151,18 +151,18 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Starting release artifacts tar archive build\n") - hclog.L().Debug("Starting release artifacts tar archive build") + b.Logger().Debug("Starting release artifacts tar archive build") tarBuf := buffer.New(64 * 1024 * 1024) tarReader, tarWriter := nio.Pipe(tarBuf) - err, cleanupFunc := buildReleaseArtifacts(ctx, tarWriter, gitRepo, trdlCfg.DockerImage, trdlCfg.Commands) + err, cleanupFunc := buildReleaseArtifacts(ctx, tarWriter, gitRepo, trdlCfg.DockerImage, trdlCfg.Commands, b.Logger()) if err != nil { return fmt.Errorf("unable to build release artifacts: %s", err) } defer func() { if err := cleanupFunc(); err != nil { - hclog.L().Error(fmt.Sprintf("unable to remove service docker image: %s", err)) + b.Logger().Error(fmt.Sprintf("unable to remove service docker image: %s", err)) } }() @@ -181,7 +181,7 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields if hdr.Typeflag != tar.TypeDir { logboek.Context(ctx).Default().LogF("Publishing %q into the tuf repo ...\n", hdr.Name) - hclog.L().Debug(fmt.Sprintf("Publishing %q into the tuf repo ...", hdr.Name)) + b.Logger().Debug(fmt.Sprintf("Publishing %q into the tuf repo ...", hdr.Name)) if err := b.Publisher.StageReleaseTarget(ctx, publisherRepository, releaseName, hdr.Name, twArtifacts); err != nil { return fmt.Errorf("unable to publish release target %q: %s", hdr.Name, err) @@ -190,7 +190,7 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Committing TUF repository state\n") - hclog.L().Debug("Committing TUF repository state") + b.Logger().Debug("Committing TUF repository state") if err := publisherRepository.CommitStaged(ctx); err != nil { return fmt.Errorf("unable to commit new tuf repository state: %s", err) @@ -198,7 +198,7 @@ func (b *Backend) pathRelease(ctx context.Context, req *logical.Request, fields } logboek.Context(ctx).Default().LogF("Task finished\n") - hclog.L().Debug("Task finished") + b.Logger().Debug("Task finished") return nil }) @@ -260,7 +260,7 @@ func getTrdlConfig(gitRepo *git.Repository, gitTag string) (*config.Trdl, error) return cfg, nil } -func buildReleaseArtifacts(ctx context.Context, tarWriter *nio.PipeWriter, gitRepo *git.Repository, fromImage string, runCommands []string) (error, func() error) { +func buildReleaseArtifacts(ctx context.Context, tarWriter *nio.PipeWriter, gitRepo *git.Repository, fromImage string, runCommands []string, logger hclog.Logger) (error, func() error) { cli, err := client.NewClientWithOpts(client.FromEnv, client.WithAPIVersionNegotiation()) if err != nil { return fmt.Errorf("unable to create docker client: %s", err), nil @@ -280,7 +280,7 @@ func buildReleaseArtifacts(ctx context.Context, tarWriter *nio.PipeWriter, gitRe tw := tar.NewWriter(contextWriter) logboek.Context(ctx).Default().LogF("Adding git worktree files to the build context\n") - hclog.L().Debug("Adding git worktree files to the build context") + logger.Debug("Adding git worktree files to the build context") if err := trdlGit.AddWorktreeFilesToTar(tw, gitRepo); err != nil { return fmt.Errorf("unable to add git worktree files to tar: %s", err) @@ -312,7 +312,7 @@ func buildReleaseArtifacts(ctx context.Context, tarWriter *nio.PipeWriter, gitRe }() logboek.Context(ctx).Default().LogF("Building docker image with artifacts\n") - hclog.L().Debug("Building docker image with artifacts") + logger.Debug("Building docker image with artifacts") response, err := cli.ImageBuild(ctx, contextReader, types.ImageBuildOptions{ Dockerfile: serviceDockerfilePathInContext, diff --git a/server/pkg/publisher/non_atomic_tuf_store.go b/server/pkg/publisher/non_atomic_tuf_store.go index d1067c07..4ecb2003 100644 --- a/server/pkg/publisher/non_atomic_tuf_store.go +++ b/server/pkg/publisher/non_atomic_tuf_store.go @@ -29,13 +29,15 @@ type NonAtomicTufStore struct { stagedMeta map[string]json.RawMessage stagedFiles []string + logger hclog.Logger } -func NewNonAtomicTufStore(privKeys TufRepoPrivKeys, filesystem Filesystem) *NonAtomicTufStore { +func NewNonAtomicTufStore(privKeys TufRepoPrivKeys, filesystem Filesystem, logger hclog.Logger) *NonAtomicTufStore { return &NonAtomicTufStore{ PrivKeys: privKeys, Filesystem: filesystem, stagedMeta: make(map[string]json.RawMessage), + logger: logger, } } @@ -57,7 +59,7 @@ func (store *NonAtomicTufStore) GetMeta() (map[string]json.RawMessage, error) { meta[name] = stagedData continue } - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.GetMeta %q not found in staged meta!", name)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.GetMeta %q not found in staged meta!", name)) exists, err := store.Filesystem.IsFileExist(ctx, name) if err != nil { @@ -71,23 +73,23 @@ func (store *NonAtomicTufStore) GetMeta() (map[string]json.RawMessage, error) { } meta[name] = data } else { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.GetMeta %q not found in the store filesystem!", name)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.GetMeta %q not found in the store filesystem!", name)) } } - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.GetMeta -> meta[targets]: %s", meta["targets.json"])) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.GetMeta -> meta[targets]: %s", meta["targets.json"])) return meta, nil } func (store *NonAtomicTufStore) SetMeta(name string, meta json.RawMessage) error { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.SetMeta %q", name)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.SetMeta %q", name)) store.stagedMeta[name] = meta return nil } func (store *NonAtomicTufStore) WalkStagedTargets(targetPathList []string, targetsFn tuf.TargetsWalkFunc) error { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.WalkStagedTargets %v", targetPathList)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.WalkStagedTargets %v", targetPathList)) ctx := context.Background() @@ -96,7 +98,7 @@ func (store *NonAtomicTufStore) WalkStagedTargets(targetPathList []string, targe reader, writer := nio.Pipe(buf) go func() { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.WalkStagedTargets before ReadFileStream %q", path)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.WalkStagedTargets before ReadFileStream %q", path)) if err := store.Filesystem.ReadFileStream(ctx, path, writer); err != nil { if err := writer.CloseWithError(fmt.Errorf("error reading file %q stream: %s", path, err)); err != nil { @@ -104,7 +106,7 @@ func (store *NonAtomicTufStore) WalkStagedTargets(targetPathList []string, targe } } - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.WalkStagedTargets after ReadFileStream %q", path)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.WalkStagedTargets after ReadFileStream %q", path)) if err := writer.Close(); err != nil { panic(fmt.Sprintf("ERROR: failed to close pipe writer while reading file %q stream: %s\n", path, err)) } @@ -142,7 +144,7 @@ FilterStagedPaths: } func (store *NonAtomicTufStore) StageTargetFile(ctx context.Context, targetPath string, data io.Reader) error { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.StageTargetFile %q", targetPath)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.StageTargetFile %q", targetPath)) // NOTE: consistenSnapshot cannot be supported when adding staged files before commit stage @@ -156,7 +158,7 @@ func (store *NonAtomicTufStore) StageTargetFile(ctx context.Context, targetPath } func (store *NonAtomicTufStore) Commit(consistentSnapshot bool, versions map[string]int, _ map[string]data.Hashes) error { - hclog.L().Debug("-- NonAtomicTufStore.Commit") + store.logger.Debug("-- NonAtomicTufStore.Commit") if consistentSnapshot { panic("not supported") } @@ -167,7 +169,7 @@ func (store *NonAtomicTufStore) Commit(consistentSnapshot bool, versions map[str // TODO: perms 0644 for _, metadataPath := range computeMetadataPaths(consistentSnapshot, name, versions) { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.Commit storing metadata path %q into the filesystem", metadataPath)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.Commit storing metadata path %q into the filesystem", metadataPath)) if err := store.Filesystem.WriteFileBytes(ctx, metadataPath, data); err != nil { return fmt.Errorf("error writing metadata path %q into the filesystem: %s", metadataPath, err) @@ -182,7 +184,7 @@ func (store *NonAtomicTufStore) Commit(consistentSnapshot bool, versions map[str } func (store *NonAtomicTufStore) GetSigningKeys(role string) ([]sign.Signer, error) { - hclog.L().Debug(fmt.Sprintf("-- NonAtomicTufStore.GetSigningKeys(%q) store.PrivKeys=%#v", role, store.PrivKeys)) + store.logger.Debug(fmt.Sprintf("-- NonAtomicTufStore.GetSigningKeys(%q) store.PrivKeys=%#v", role, store.PrivKeys)) toSigners := func(key *sign.PrivateKey) []sign.Signer { if key != nil { diff --git a/server/pkg/publisher/publisher.go b/server/pkg/publisher/publisher.go index 04e153ed..2016f35f 100644 --- a/server/pkg/publisher/publisher.go +++ b/server/pkg/publisher/publisher.go @@ -47,11 +47,12 @@ func NewErrIncorrectTargetPath(path string) error { } type Publisher struct { - mu sync.Mutex + mu sync.Mutex + logger hclog.Logger } -func NewPublisher() *Publisher { - return &Publisher{} +func NewPublisher(logger hclog.Logger) *Publisher { + return &Publisher{logger: logger} } func (publisher *Publisher) RotateRepositoryKeys(ctx context.Context, storage logical.Storage, repository RepositoryInterface) error { @@ -70,7 +71,7 @@ func (publisher *Publisher) RotateRepositoryKeys(ctx context.Context, storage lo return fmt.Errorf("error putting private keys json entry by key %q into the storage: %s", storageKeyTufRepositoryKeys, err) } - hclog.L().Info("Successfully rotated repository private keys") + publisher.logger.Info("Successfully rotated repository private keys") } return nil @@ -95,7 +96,7 @@ func (publisher *Publisher) initRepositoryKeys(ctx context.Context, storage logi return ErrUninitializedRepositoryKeys } - hclog.L().Debug("Will generate new repository private keys") + publisher.logger.Debug("Will generate new repository private keys") if err := repository.GenPrivKeys(); err != nil { return fmt.Errorf("error generating repository private keys: %s", err) @@ -112,7 +113,7 @@ func (publisher *Publisher) initRepositoryKeys(ctx context.Context, storage logi return fmt.Errorf("error putting private keys json entry by key %q into the storage: %s", storageKeyTufRepositoryKeys, err) } - hclog.L().Info("Generated new repository private keys") + publisher.logger.Info("Generated new repository private keys") return nil } @@ -126,7 +127,7 @@ func (publisher *Publisher) initRepositoryKeys(ctx context.Context, storage logi return fmt.Errorf("unable to set private keys into repository: %s", err) } - hclog.L().Info("Loaded repository private keys from the storage") + publisher.logger.Info("Loaded repository private keys from the storage") return nil } @@ -144,6 +145,7 @@ func (publisher *Publisher) GetRepository(ctx context.Context, storage logical.S repository, err := NewRepositoryWithOptions( S3Options{AwsConfig: awsConfig, BucketName: options.S3BucketName}, TufRepoOptions{}, + publisher.logger, ) if err != nil { return nil, fmt.Errorf("error initializing publisher repository handle: %s", err) diff --git a/server/pkg/publisher/repository.go b/server/pkg/publisher/repository.go index 4c03756c..fec7e0af 100644 --- a/server/pkg/publisher/repository.go +++ b/server/pkg/publisher/repository.go @@ -22,36 +22,39 @@ type TufRepoOptions struct { PrivKeys TufRepoPrivKeys } -func NewRepositoryWithOptions(s3Options S3Options, tufRepoOptions TufRepoOptions) (*S3Repository, error) { - s3fs := NewS3Filesystem(s3Options.AwsConfig, s3Options.BucketName) - tufStore := NewNonAtomicTufStore(tufRepoOptions.PrivKeys, s3fs) +func NewRepositoryWithOptions(s3Options S3Options, tufRepoOptions TufRepoOptions, logger hclog.Logger) (*S3Repository, error) { + s3fs := NewS3Filesystem(s3Options.AwsConfig, s3Options.BucketName, logger) + tufStore := NewNonAtomicTufStore(tufRepoOptions.PrivKeys, s3fs, logger) tufRepo, err := tuf.NewRepo(tufStore) if err != nil { return nil, fmt.Errorf("error initializing tuf repo: %s", err) } - return NewRepository(s3fs, tufStore, tufRepo), nil + return NewRepository(s3fs, tufStore, tufRepo, logger), nil } type S3Repository struct { S3Filesystem *S3Filesystem TufStore *NonAtomicTufStore TufRepo *tuf.Repo + + logger hclog.Logger } -func NewRepository(s3Filesystem *S3Filesystem, tufStore *NonAtomicTufStore, tufRepo *tuf.Repo) *S3Repository { +func NewRepository(s3Filesystem *S3Filesystem, tufStore *NonAtomicTufStore, tufRepo *tuf.Repo, logger hclog.Logger) *S3Repository { return &S3Repository{ S3Filesystem: s3Filesystem, TufStore: tufStore, TufRepo: tufRepo, + logger: logger, } } func (repository *S3Repository) SetPrivKeys(privKeys TufRepoPrivKeys) error { - hclog.L().Debug("-- S3Repository.SetPrivKeys") + repository.logger.Debug("-- S3Repository.SetPrivKeys") repository.TufStore.PrivKeys = privKeys - hclog.L().Debug(fmt.Sprintf("-- S3Repository.SetPrivKeys BEFORE AddPrivateKeyWithExpires: %#v\n", repository.TufStore.PrivKeys)) + repository.logger.Debug(fmt.Sprintf("-- S3Repository.SetPrivKeys BEFORE AddPrivateKeyWithExpires: %#v\n", repository.TufStore.PrivKeys)) for _, desc := range []struct { role string @@ -67,7 +70,7 @@ func (repository *S3Repository) SetPrivKeys(privKeys TufRepoPrivKeys) error { } } - hclog.L().Debug(fmt.Sprintf("-- S3Repository.SetPrivKeys AFTER AddPrivateKeyWithExpires: %#v\n", repository.TufStore.PrivKeys)) + repository.logger.Debug(fmt.Sprintf("-- S3Repository.SetPrivKeys AFTER AddPrivateKeyWithExpires: %#v\n", repository.TufStore.PrivKeys)) return nil } @@ -106,7 +109,7 @@ func (repository *S3Repository) Init() error { err := repository.TufRepo.Init(false) if err == tuf.ErrInitNotAllowed { - hclog.L().Info("Tuf repository already initialized: skip initialization") + repository.logger.Info("Tuf repository already initialized: skip initialization") } else if err != nil { return fmt.Errorf("unable to init tuf repository: %s", err) } diff --git a/server/pkg/publisher/s3_filesystem.go b/server/pkg/publisher/s3_filesystem.go index d993119a..51a7a2c3 100644 --- a/server/pkg/publisher/s3_filesystem.go +++ b/server/pkg/publisher/s3_filesystem.go @@ -19,16 +19,18 @@ type S3Filesystem struct { AwsConfig *aws.Config BucketName string + logger hclog.Logger + // TODO: cache opened session } -func NewS3Filesystem(awsConfig *aws.Config, bucketName string) *S3Filesystem { +func NewS3Filesystem(awsConfig *aws.Config, bucketName string, logger hclog.Logger) *S3Filesystem { if !strings.Contains(*awsConfig.Endpoint, "s3.amazonaws.com") { awsConfig.S3ForcePathStyle = new(bool) *awsConfig.S3ForcePathStyle = true } - return &S3Filesystem{AwsConfig: awsConfig, BucketName: bucketName} + return &S3Filesystem{AwsConfig: awsConfig, BucketName: bucketName, logger: logger} } func (fs *S3Filesystem) IsFileExist(ctx context.Context, path string) (bool, error) { @@ -43,7 +45,7 @@ func (fs *S3Filesystem) IsFileExist(ctx context.Context, path string) (bool, err Bucket: &fs.BucketName, Key: &path, }) - hclog.L().Debug(fmt.Sprintf("-- S3Filesystem.IsFileExist %q err=%v", path, err)) + fs.logger.Debug(fmt.Sprintf("-- S3Filesystem.IsFileExist %q err=%v", path, err)) if err != nil { if awsErr, ok := err.(awserr.Error); ok { if awsErr.Code() == "NotFound" { @@ -73,7 +75,7 @@ func (fs *S3Filesystem) ReadFile(ctx context.Context, path string, writerAt io.W return fmt.Errorf("unable to download item %q: %s", path, err) } - hclog.L().Debug(fmt.Sprintf("Downloaded %q %d bytes", path, numBytes)) + fs.logger.Debug(fmt.Sprintf("Downloaded %q %d bytes", path, numBytes)) return nil } @@ -89,7 +91,7 @@ func (fw sequentialWriterAt) WriteAt(p []byte, offset int64) (int, error) { n, err := fw.Writer.Write(p) // DEBUG - // hclog.L().Debug(fmt.Sprintf("-- sequentialWriterAt.WriteAt(%p, %d) -> %d, %v", p, offset, n, err)) + // fs.logger.Debug(fmt.Sprintf("-- sequentialWriterAt.WriteAt(%p, %d) -> %d, %v", p, offset, n, err)) return n, err } @@ -114,7 +116,7 @@ func (fs *S3Filesystem) ReadFileStream(ctx context.Context, path string, writer return fmt.Errorf("unable to download item %q: %s", path, err) } - hclog.L().Debug(fmt.Sprintf("-- S3Filesystem.ReadFileStream downloaded %q %d bytes", path, numBytes)) + fs.logger.Debug(fmt.Sprintf("-- S3Filesystem.ReadFileStream downloaded %q %d bytes", path, numBytes)) return nil } @@ -138,7 +140,7 @@ func (fs *S3Filesystem) ReadFileBytes(ctx context.Context, path string) ([]byte, return nil, fmt.Errorf("unable to download item %q: %s", path, err) } - hclog.L().Debug(fmt.Sprintf("-- S3Filesystem.ReadFileBytes downloaded %q %d bytes", path, numBytes)) + fs.logger.Debug(fmt.Sprintf("-- S3Filesystem.ReadFileBytes downloaded %q %d bytes", path, numBytes)) return buf.Bytes(), nil } @@ -162,7 +164,7 @@ func (fs *S3Filesystem) WriteFileStream(ctx context.Context, path string, data i Bucket: &fs.BucketName, Key: &path, // DEBUG - // Body: &debugReader{data}, + // Body: &debugReader{origReader: data, logger: fs.logger}, Body: data, CacheControl: &cacheControl, } @@ -175,19 +177,20 @@ func (fs *S3Filesystem) WriteFileStream(ctx context.Context, path string, data i return fmt.Errorf("error uploading %q: %s", path, err) } - hclog.L().Debug(fmt.Sprintf("Uploaded %q", result.Location)) + fs.logger.Debug(fmt.Sprintf("Uploaded %q", result.Location)) return nil } type debugReader struct { origReader io.Reader + logger hclog.Logger } func (o *debugReader) Read(p []byte) (int, error) { n, err := o.origReader.Read(p) - hclog.L().Debug(fmt.Sprintf("-- debugReader Read(%p) -> %d, %v", p, n, err)) + o.logger.Debug(fmt.Sprintf("-- debugReader Read(%p) -> %d, %v", p, n, err)) return n, err } diff --git a/server/pkg/tasks_manager/actions.go b/server/pkg/tasks_manager/actions.go index 706941f1..295c7e02 100644 --- a/server/pkg/tasks_manager/actions.go +++ b/server/pkg/tasks_manager/actions.go @@ -6,7 +6,6 @@ import ( "fmt" "time" - "github.com/hashicorp/go-hclog" "github.com/hashicorp/vault/sdk/logical" "github.com/werf/trdl/server/pkg/tasks_manager/worker" @@ -115,15 +114,15 @@ func (m *Manager) WrapTaskFunc(taskFunc func(context.Context, logical.Storage) e select { case <-ctxWithTimeout.Done(): close(resCh) - hclog.L().Debug("task failed: context canceled") + m.logger.Debug("task failed: context canceled") return ErrContextCanceled case err := <-resCh: if err != nil { - hclog.L().Debug(fmt.Sprintf("task failed: %s", err)) + m.logger.Debug(fmt.Sprintf("task failed: %s", err)) return err } - hclog.L().Debug("task succeeded") + m.logger.Debug("task succeeded") return nil } } diff --git a/server/pkg/tasks_manager/actions_test.go b/server/pkg/tasks_manager/actions_test.go index 7c6bf5f4..d2e98daf 100644 --- a/server/pkg/tasks_manager/actions_test.go +++ b/server/pkg/tasks_manager/actions_test.go @@ -5,6 +5,7 @@ import ( "fmt" "testing" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/vault/sdk/logical" "github.com/stretchr/testify/assert" @@ -222,7 +223,7 @@ func TestManager_WrapTaskFunc(t *testing.T) { func initManagerWithoutWorker() *Manager { taskChan := make(chan *worker.Task, taskChanSize) - m := &Manager{taskChan: taskChan} + m := &Manager{taskChan: taskChan, logger: hclog.L()} return m } diff --git a/server/pkg/tasks_manager/backend_test.go b/server/pkg/tasks_manager/backend_test.go index aa56a0e6..1e4e5293 100644 --- a/server/pkg/tasks_manager/backend_test.go +++ b/server/pkg/tasks_manager/backend_test.go @@ -6,6 +6,7 @@ import ( "testing" "time" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/vault/sdk/framework" "github.com/hashicorp/vault/sdk/logical" "github.com/stretchr/testify/assert" @@ -486,7 +487,7 @@ func assertAndAddCompletedTaskToStorage(t *testing.T, ctx context.Context, stora func pathTestSetup(t *testing.T) (context.Context, logical.Backend, *Manager, logical.Storage) { ctx := context.Background() - m := NewManager() // TODO: use worker interface + m := NewManager(hclog.L()) // TODO: use worker interface storage := &logical.InmemStorage{} config := logical.TestBackendConfig() diff --git a/server/pkg/tasks_manager/manager.go b/server/pkg/tasks_manager/manager.go index 3a0c14a7..f1b9570e 100644 --- a/server/pkg/tasks_manager/manager.go +++ b/server/pkg/tasks_manager/manager.go @@ -4,6 +4,7 @@ import ( "context" "sync" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/vault/sdk/logical" "github.com/werf/trdl/server/pkg/tasks_manager/worker" @@ -15,12 +16,13 @@ type Manager struct { Storage logical.Storage Worker worker.Interface + logger hclog.Logger taskChan chan *worker.Task mu sync.Mutex } -func NewManager() *Manager { - m := &Manager{taskChan: make(chan *worker.Task, taskChanSize)} +func NewManager(logger hclog.Logger) *Manager { + m := &Manager{taskChan: make(chan *worker.Task, taskChanSize), logger: logger} m.Worker = worker.NewWorker(context.Background(), m.taskChan, m) go m.Worker.Start()