From 4bf19f339fa1bfd8aed98dcd56b8ee9f2375a98d Mon Sep 17 00:00:00 2001 From: Przemek Pokrywka <12400578+dekiel@users.noreply.github.com> Date: Tue, 15 Oct 2024 09:29:04 +0200 Subject: [PATCH] Debug logging for generating tags (#12088) * Use config to provide a default tag for images build for pr or commit. Added validation tag field to provide validation regex together with a tag. Update kaniko-build-config.yaml to provide default tag for pr and commit images with validation regex. Validating tag when parsing it's value. Added TagOption to add PR number to the Tagger instance. Using pull request default tag together with user provided tags instead replacing all values with default tag. This allows users to provide their own tag to the images build on pr. * Pass logger instance. * First set of debug lof messages * More loggers. Write parsed tags to file. * More debug log statements. Added writing generated tags to the file. This let us write logs in to stdout because the generated tags can be read from file. * Pass logger instance. * First set of debug lof messages * More loggers. Write parsed tags to file. * More debug log statements. Added writing generated tags to the file. This let us write logs in to stdout because the generated tags can be read from file. * Adjusteed tests * More debug logs * Do not change kaniko build config. THis is done in separate pr. Use logger from options when building locally. * Added named method to better describe log message context Added logging in other packages used by image-builder * Fixed tests * write output file to the root of container * Fix expected flag * Do not use named logger interface * More context data --- cmd/image-builder/config.go | 5 +- cmd/image-builder/images/kaniko/Dockerfile | 2 +- cmd/image-builder/main.go | 196 ++++++++++++++++----- cmd/image-builder/main_test.go | 182 +++++++++++++------ pkg/tags/options.go | 7 + pkg/tags/tags.go | 46 ++++- pkg/tags/tags_test.go | 8 + 7 files changed, 333 insertions(+), 113 deletions(-) diff --git a/cmd/image-builder/config.go b/cmd/image-builder/config.go index bc96c9894552..98d85be5debf 100644 --- a/cmd/image-builder/config.go +++ b/cmd/image-builder/config.go @@ -33,9 +33,6 @@ type Config struct { DevRegistry Registry `yaml:"dev-registry" json:"dev-registry"` // Cache options that are directly related to kaniko flags Cache CacheConfig `yaml:"cache" json:"cache"` - // TagTemplate is used to generate default tag for push events for current image-builder version. - // This will be removed after migration. - TagTemplate tags.Tag `yaml:"tag-template" json:"tag-template"` // Default Tag template used for images build on commit. // The value can be a go-template string or literal tag value string. // See tags.Tag struct for more information and available fields @@ -346,4 +343,4 @@ func determineUsedCISystem(envGetter func(key string) string, envLookup func(key } return "", fmt.Errorf("cannot determine ci system: unknown system") -} +} \ No newline at end of file diff --git a/cmd/image-builder/images/kaniko/Dockerfile b/cmd/image-builder/images/kaniko/Dockerfile index 72bf6fd877ac..720b3bbf66cf 100644 --- a/cmd/image-builder/images/kaniko/Dockerfile +++ b/cmd/image-builder/images/kaniko/Dockerfile @@ -9,4 +9,4 @@ FROM gcr.io/kaniko-project/executor:v1.23.2 COPY --from=builder /app/image-builder /image-builder -ENTRYPOINT ["/image-builder"] +ENTRYPOINT ["/image-builder"] \ No newline at end of file diff --git a/cmd/image-builder/main.go b/cmd/image-builder/main.go index 936d3c1bf7ba..4eedcda21295 100644 --- a/cmd/image-builder/main.go +++ b/cmd/image-builder/main.go @@ -22,10 +22,12 @@ import ( adopipelines "github.com/kyma-project/test-infra/pkg/azuredevops/pipelines" "github.com/kyma-project/test-infra/pkg/extractimageurls" "github.com/kyma-project/test-infra/pkg/github/actions" + "github.com/kyma-project/test-infra/pkg/logging" "github.com/kyma-project/test-infra/pkg/sets" "github.com/kyma-project/test-infra/pkg/sign" "github.com/kyma-project/test-infra/pkg/tags" "github.com/microsoft/azure-devops-go-api/azuredevops/v7/pipelines" + "go.uber.org/zap" "golang.org/x/net/context" errutil "k8s.io/apimachinery/pkg/util/errors" ) @@ -39,6 +41,7 @@ type options struct { name string variant string logDir string + logger Logger orgRepo string silent bool isCI bool @@ -60,6 +63,12 @@ type options struct { gitState GitStateConfig debug bool dryRun bool + tagsOutputFile string +} + +type Logger interface { + logging.StructuredLoggerInterface + logging.WithLoggerInterface } // parseVariable returns a build-arg. @@ -422,13 +431,13 @@ func buildLocally(o options) error { // TODO(dekiel): validating if envFile or variants.yaml file exists should be done in validateOptions or in a separate function. // We should call this function before calling image building functions. - dockerfilePath, err := getDockerfileDirPath(o) + dockerfilePath, err := getDockerfileDirPath(o.logger, o) if err != nil { return fmt.Errorf("get dockerfile path failed, error: %w", err) } // Load environment variables from the envFile or variants.yaml file. if len(o.envFile) > 0 { - envs, err = loadEnv(os.DirFS(dockerfilePath), o.envFile) + envs, err = loadEnv(o.logger, os.DirFS(dockerfilePath), o.envFile) if err != nil { return fmt.Errorf("load env failed, error: %w", err) } @@ -468,13 +477,13 @@ func buildLocally(o options) error { return fmt.Errorf("'sha' could not be determined") } - defaultTag, err := getDefaultTag(o) + defaultTag, err := getDefaultTag(o.logger, o) if err != nil { return err } // Get the tags for the image. - parsedTags, err := getTags(pr, sha, append(o.tags, defaultTag)) + parsedTags, err := getTags(o.logger, pr, sha, append(o.tags, defaultTag)) if err != nil { return err } @@ -521,8 +530,9 @@ func appendMissing(target *map[string]string, source []tags.Tag) { // appendToTags appends key-value pairs from source map to target slice of tags.Tag // This allows creation of image tags from key value pairs. -func appendToTags(target *[]tags.Tag, source map[string]string) { +func appendToTags(logger Logger, target *[]tags.Tag, source map[string]string) { for key, value := range source { + logger.Debugw("appending key-value pair to tags", "key", key, "value", value) *target = append(*target, tags.Tag{Name: key, Value: value}) } } @@ -639,24 +649,34 @@ func (l *StrList) List() []string { return n } -func getTags(pr, sha string, templates []tags.Tag) ([]tags.Tag, error) { +func getTags(logger Logger, pr, sha string, templates []tags.Tag) ([]tags.Tag, error) { + logger.Debugw("started building tags", "pr_number", pr, "commit_sha", sha, "templates", templates) + + logger.Debugw("building tagger options") var taggerOptions []tags.TagOption if len(pr) > 0 { taggerOptions = append(taggerOptions, tags.PRNumber(pr)) + logger.Debugw("pr number is set, adding tagger option", "pr_number", pr) } if len(sha) > 0 { taggerOptions = append(taggerOptions, tags.CommitSHA(sha)) + logger.Debugw("commit sha is set, adding tagger option", "commit_sha", sha) } + taggerOptions = append(taggerOptions, tags.WithLogger(logger)) + logger.Debugw("added logger to tagger options") // build a tag from commit SHA - tagger, err := tags.NewTagger(templates, taggerOptions...) + tagger, err := tags.NewTagger(logger, templates, taggerOptions...) if err != nil { - return nil, fmt.Errorf("get tagger: %w", err) + return nil, fmt.Errorf("failed creating tagger instance: %w", err) } + logger.Debugw("created tagger instance with options, starting parsing tags") p, err := tagger.ParseTags() if err != nil { return nil, fmt.Errorf("build tag: %w", err) } + logger.Debugw("parsed tags successfully", "tags", p) + return p, nil } @@ -718,39 +738,55 @@ func validateOptions(o options) error { } // loadEnv creates environment variables in application runtime from a file with key=value data -func loadEnv(vfs fs.FS, envFile string) (map[string]string, error) { +func loadEnv(logger Logger, vfs fs.FS, envFile string) (map[string]string, error) { + logger.Debugw("loading env file", "envFile_path", envFile) if len(envFile) == 0 { + logger.Infow("provided env file path is empty, skipping loading env file") // file is empty - ignore return nil, nil } + logger.Debugw("Opening env file") file, err := vfs.Open(envFile) if err != nil { return nil, fmt.Errorf("open env file: %w", err) } + defer file.Close() + logger.Debugw("File opened") fileReader := bufio.NewScanner(file) vars := make(map[string]string) + logger.Debugw("Reading env file line by line") for fileReader.Scan() { line := fileReader.Text() + logger = logger.With("line", line) + logger.Debugw("Processing envFile line") + logger.Debugw("Splitting envFile line", "separator", "=") separatedValues := strings.SplitN(line, "=", 2) if len(separatedValues) > 2 { return nil, fmt.Errorf("env var split incorrectly, got more than two values, expected only two, values: %v", separatedValues) } // ignore empty lines, setup environment variable only if key and value are present if len(separatedValues) == 2 { + logger.Debugw("Separated values", "key", separatedValues[0], "value", separatedValues[1]) + logger = logger.With("key", separatedValues[0], "value", separatedValues[1]) key, val := separatedValues[0], separatedValues[1] + logger.Debugw("Checking if env file for a given key is already present in runtime") if _, ok := os.LookupEnv(key); ok { // do not override env variable if it's already present in the runtime // do not include in vars map since dev should not have access to it anyway + logger.Infow("Env file key already present in runtime, skipping setting it") continue } + logger.Debugw("Setting env file for a given key in runtime") err := os.Setenv(key, val) if err != nil { return nil, fmt.Errorf("setenv: %w", err) } + logger.Debugw("Adding env file key to vars, to be injected as build args") // add value to the vars that will be injected as build args vars[key] = val } } + logger.Debugw("Finished processing env file") return vars, nil } @@ -796,6 +832,7 @@ func (o *options) gatherOptions(flagSet *flag.FlagSet) *flag.FlagSet { flagSet.BoolVar(&o.parseTagsOnly, "parse-tags-only", false, "Only parse tags and print them to stdout") flagSet.StringVar(&o.oidcToken, "oidc-token", "", "Token used to authenticate against Azure DevOps backend service") flagSet.StringVar(&o.azureAccessToken, "azure-access-token", "", "Token used to authenticate against Azure DevOps API") + flagSet.StringVar(&o.tagsOutputFile, "tags-output-file", "/generated-tags.json", "Path to file where generated tags will be written as JSON") return flagSet } @@ -805,10 +842,23 @@ func main() { o := options{isCI: os.Getenv("CI") == "true"} o.gatherOptions(flagSet) if err := flagSet.Parse(os.Args[1:]); err != nil { - fmt.Println(err) - os.Exit(1) + log.Fatalf("Failed to parse flags: %s", err) } + var ( + zapLogger *zap.Logger + err error + ) + if o.debug { + zapLogger, err = zap.NewDevelopment() + } else { + zapLogger, err = zap.NewProduction() + } + if err != nil { + log.Fatalf("Failed to initialize logger: %s", err) + } + o.logger = zapLogger.Sugar() + // If running inside some CI system, determine which system is used if o.isCI { ciSystem, err := DetermineUsedCISystem() @@ -849,11 +899,14 @@ func main() { } if o.parseTagsOnly { - err = generateTags(o) + logger := o.logger.With("command", "parse-tags-only") + logger.Infow("Parsing tags") + err = generateTags(logger, o) if err != nil { - fmt.Printf("Parse tags failed with error: %s\n", err) + logger.Errorw("Parsing tags failed", "error", err) os.Exit(1) } + logger.Infow("Tags parsed successfully") os.Exit(0) } if o.buildInADO { @@ -873,87 +926,136 @@ func main() { fmt.Println("Job's done.") } -func generateTags(o options) error { +func generateTags(logger Logger, o options) error { + logger.Infow("starting tag generation") + logger.Debugw("getting the absolute path to the Dockerfile directory") // Get the absolute path to the dockerfile directory. - dockerfilePath, err := getDockerfileDirPath(o) + dockerfileDirPath, err := getDockerfileDirPath(logger, o) if err != nil { - return fmt.Errorf("failed to get dockerfile path: %s", err) + return fmt.Errorf("failed to get dockerfile path: %w", err) } + logger.Debugw("dockerfile directory path retrieved", "dockerfileDirPath", dockerfileDirPath) + logger.Debugw("getting environment variables from environment file", "envFile", o.envFile, "dockerfileDirPath", dockerfileDirPath) // Load environment variables from the envFile. - envs, err := getEnvs(o, dockerfilePath) + envs, err := loadEnv(logger, os.DirFS(dockerfileDirPath), o.envFile) if err != nil { - return err + return fmt.Errorf("failed to load environment variables from env file: %w", err) + } + // If envs is nil, alocate empty map. getEnvs returns nil if envFile path is empty. + if envs == nil { + envs = make(map[string]string) + logger.Infow("no environment file provided") + logger.Debugw("initialized empty envs map") + } else { + logger.Infow("environment variables successfully loaded from file") + logger.Debugw("environment variables", "envs", envs) } + logger.Debugw("parsing tags from options") // Parse tags from the provided options. - parsedTags, err := parseTags(o) + parsedTags, err := parseTags(logger, o) if err != nil { - return fmt.Errorf("failed to parse tags : %s", err) + return fmt.Errorf("failed to parse tags from options: %w", err) } + logger.Infow("tags parsed successfully", "parsedTags", parsedTags) + logger.Debugw("appending values from envFile to tags") // Append environment variables to tags. - appendToTags(&parsedTags, envs) + appendToTags(logger, &parsedTags, envs) // Print parsed tags to stdout as json. - jsonTags := tagsAsJSON(parsedTags) - fmt.Printf("%s\n", jsonTags) + logger.Debugw("environment variables appended to tags", "parsedTags", parsedTags) + logger.Debugw("converting parsed tags to JSON") + jsonTags, err := tagsAsJSON(parsedTags) + if err != nil { + return fmt.Errorf("failed generating tags json representation: %w", err) + } + logger.Debugw("successfully generated image tags in JSON format", "tags", jsonTags) + // Write tags to a file. + if o.tagsOutputFile != "" { + logger.Debugw("tags output file provided", "tagsOutputFile", o.tagsOutputFile) + err = writeOutputFile(logger, o.tagsOutputFile, jsonTags) + if err != nil { + return fmt.Errorf("failed to write tags to file: %w", err) + } + logger.Infow("tags successfully written to file", "tagsOutputFile", o.tagsOutputFile, "generatedTags", jsonTags) + } return nil } -func tagsAsJSON(parsedTags []tags.Tag) string { - jsonTags, err := json.Marshal(parsedTags) +// writeOutputFile writes the provided data to the file specified by the path. +func writeOutputFile(logger Logger, path string, data []byte) error { + logger.Debugw("writing generated tags to file", "tagsOutputFile", path) + err := os.WriteFile(path, data, 0644) if err != nil { - fmt.Printf("Failed to marshal tags to json: %s", err) - os.Exit(1) + return fmt.Errorf("failed to write tags to file: %s", err) } - return string(jsonTags) + logger.Debugw("tags written to file") + return nil } -func getEnvs(o options, dockerfilePath string) (map[string]string, error) { - if len(o.envFile) > 0 { - envs, err := loadEnv(os.DirFS(dockerfilePath), o.envFile) - if err != nil { - return nil, fmt.Errorf("failed to load env file: %s", err) - } - return envs, nil +func tagsAsJSON(parsedTags []tags.Tag) ([]byte, error) { + jsonTags, err := json.Marshal(parsedTags) + if err != nil { + return nil, fmt.Errorf("failed to marshal tags to json, got error: %w", err) } - return map[string]string{}, nil + return jsonTags, err } -func parseTags(o options) ([]tags.Tag, error) { +func parseTags(logger Logger, o options) ([]tags.Tag, error) { + logger.Debugw("starting to parse tags") var ( pr string sha string ) + + logger.Debugw("reading git state for event type") if !o.gitState.isPullRequest && o.gitState.BaseCommitSHA != "" { sha = o.gitState.BaseCommitSHA + logger.Debugw("running for push event, base commit SHA found", "sha", sha) } if o.gitState.isPullRequest && o.gitState.PullRequestNumber > 0 { pr = fmt.Sprint(o.gitState.PullRequestNumber) + logger.Debugw("Running for pull request event, PR number found", "pr-number", pr) } // TODO (dekiel): Tags provided as base64 encoded string should be parsed and added to the tags list when parsing flags. // This way all tags are available in the tags list from thr very beginning of execution and can be used in any process. + + logger.Debugw("checking if base64 encoded tags are provided") // read tags from base64 encoded string if provided if o.tagsBase64 != "" { + logger.Debugw("base64 encoded tags provided, starting to decode", "tagsBase64", o.tagsBase64) decoded, err := base64.StdEncoding.DecodeString(o.tagsBase64) if err != nil { - return nil, fmt.Errorf("failed to decode tags, error: %w", err) + return nil, fmt.Errorf("failed to decode base64 encoded tags, error: %w", err) } + logger.Debugw("tags successfully decoded", "decoded", string(decoded)) splitedTags := strings.Split(string(decoded), ",") + logger.Debugw("splitted decoded tags", "splitedTags", splitedTags) for _, tag := range splitedTags { + logger.Debugw("adding tag", "tag", tag) err = o.tags.Set(tag) if err != nil { return nil, fmt.Errorf("failed to set tag, tag: %s, error: %w", tag, err) } + logger.Debugw("tag set successfully") } + logger.Debugw("all base64 encoded tags successfully added", "tags", o.tags.String()) + } else { + logger.Debugw("no base64 encoded tags provided") } - defaultTag, err := getDefaultTag(o) + logger.Debugw("getting default tag") + defaultTag, err := getDefaultTag(logger, o) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to retrieve default tag, error: %w", err) } - parsedTags, err := getTags(pr, sha, append(o.tags, defaultTag)) + logger.Debugw("default tag retrieved", "defaultTag", defaultTag) + + logger.Debugw("parsing tags") + parsedTags, err := getTags(logger, pr, sha, append(o.tags, defaultTag)) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to parse tags: %w", err) } + logger.Debugw("tags parsed successfully", "parsedTags", parsedTags) return parsedTags, nil } @@ -961,24 +1063,30 @@ func parseTags(o options) ([]tags.Tag, error) { // getDefaultTag returns the default tag based on the read git state. // The function provid default tag for pull request or commit. // The default tag is read from the provided options struct. -func getDefaultTag(o options) (tags.Tag, error) { +func getDefaultTag(logger Logger, o options) (tags.Tag, error) { + logger.Debugw("reading gitstate data") if o.gitState.isPullRequest && o.gitState.PullRequestNumber > 0 { + logger.Debugw("pull request number provided, returning default pr tag") return o.DefaultPRTag, nil } if len(o.gitState.BaseCommitSHA) > 0 { + o.logger.Debugw("commit sha provided, returning default commit tag") return o.DefaultCommitTag, nil } return tags.Tag{}, fmt.Errorf("could not determine default tag, no pr number or commit sha provided") } -func getDockerfileDirPath(o options) (string, error) { +func getDockerfileDirPath(logger Logger, o options) (string, error) { + logger.Debugw("starting to get Dockerfile directory path", "dockerfile", o.dockerfile, "context", o.context) // Get the absolute path to the build context directory. context, err := filepath.Abs(o.context) if err != nil { return "", fmt.Errorf("could not get absolute path to build context directory: %w", err) } + logger.Debugw("successfully retrieved absolute path to context directory", "absolute_path", context) // Get the absolute path to the dockerfile. dockerfileDirPath := filepath.Join(context, filepath.Dir(o.dockerfile)) + logger.Debugw("dockerfile directory path constructed", "dockerfileDirPath", dockerfileDirPath) return dockerfileDirPath, err } diff --git a/cmd/image-builder/main_test.go b/cmd/image-builder/main_test.go index db4cdb49ea6a..b881e81eabf2 100644 --- a/cmd/image-builder/main_test.go +++ b/cmd/image-builder/main_test.go @@ -16,6 +16,7 @@ import ( "github.com/kyma-project/test-infra/pkg/sets" "github.com/kyma-project/test-infra/pkg/sign" "github.com/kyma-project/test-infra/pkg/tags" + "go.uber.org/zap" . "github.com/onsi/gomega" ) @@ -243,10 +244,11 @@ func TestFlags(t *testing.T) { { name: "unknown flag, fail", expectedOpts: options{ - context: ".", - configPath: "/config/image-builder-config.yaml", - dockerfile: "dockerfile", - logDir: "/logs/artifacts", + context: ".", + configPath: "/config/image-builder-config.yaml", + dockerfile: "dockerfile", + logDir: "/logs/artifacts", + tagsOutputFile: "/generated-tags.json", }, expectedErr: true, args: []string{ @@ -262,12 +264,13 @@ func TestFlags(t *testing.T) { {Name: "latest", Value: "latest"}, {Name: "cookie", Value: "cookie"}, }, - context: "prow/build", - configPath: "config.yaml", - dockerfile: "dockerfile", - logDir: "prow/logs", - orgRepo: "kyma-project/test-infra", - silent: true, + context: "prow/build", + configPath: "config.yaml", + dockerfile: "dockerfile", + logDir: "prow/logs", + orgRepo: "kyma-project/test-infra", + silent: true, + tagsOutputFile: "/generated-tags.json", }, args: []string{ "--config=config.yaml", @@ -284,11 +287,12 @@ func TestFlags(t *testing.T) { { name: "export tag, pass", expectedOpts: options{ - context: ".", - configPath: "/config/image-builder-config.yaml", - dockerfile: "dockerfile", - logDir: "/logs/artifacts", - exportTags: true, + context: ".", + configPath: "/config/image-builder-config.yaml", + dockerfile: "dockerfile", + logDir: "/logs/artifacts", + exportTags: true, + tagsOutputFile: "/generated-tags.json", }, args: []string{ "--export-tags", @@ -305,6 +309,7 @@ func TestFlags(t *testing.T) { tags.Tag{Name: "BIN", Value: "test"}, tags.Tag{Name: "BIN2", Value: "test2"}, }, + tagsOutputFile: "/generated-tags.json", }, args: []string{ "--build-arg=BIN=test", @@ -407,10 +412,15 @@ func Test_getTags(t *testing.T) { } for _, c := range tc { t.Run(c.name, func(t *testing.T) { + zapLogger, err := zap.NewProduction() + if err != nil { + t.Errorf("got error but didn't want to: %s", err) + } + logger := zapLogger.Sugar() for k, v := range c.env { t.Setenv(k, v) } - got, err := getTags(c.pr, c.sha, append(c.additionalTags, c.tagTemplate)) + got, err := getTags(logger, c.pr, c.sha, append(c.additionalTags, c.tagTemplate)) if err != nil && !c.expectErr { t.Errorf("got error but didn't want to: %s", err) } @@ -436,7 +446,12 @@ func Test_loadEnv(t *testing.T) { "key3": "static-value", "key4": "val4=asf", } - _, err := loadEnv(vfs, ".env") + zapLogger, err := zap.NewProduction() + if err != nil { + t.Errorf("got error but didn't want to: %s", err) + } + logger := zapLogger.Sugar() + _, err = loadEnv(logger, vfs, ".env") if err != nil { t.Errorf("%v", err) } @@ -628,6 +643,11 @@ func Test_appendMissing(t *testing.T) { func Test_parseTags(t *testing.T) { tagsFlag := sets.Tags{{Name: "base64testtag", Value: "testtag"}, {Name: "base64testtemplate", Value: "test-{{ .PRNumber }}"}} base64Tags := base64.StdEncoding.EncodeToString([]byte(tagsFlag.String())) + zapLogger, err := zap.NewProduction() + if err != nil { + t.Errorf("got error but didn't want to: %s", err) + } + logger := zapLogger.Sugar() tc := []struct { name string options options @@ -639,6 +659,7 @@ func Test_parseTags(t *testing.T) { options: options{ gitState: prGitState, Config: buildConfig, + logger: logger, }, expectedTags: []tags.Tag{expectedDefaultPRTag(prGitState.PullRequestNumber)}, }, @@ -647,6 +668,7 @@ func Test_parseTags(t *testing.T) { options: options{ gitState: commitGitState, Config: buildConfig, + logger: logger, }, expectedTags: []tags.Tag{expectedDefaultCommitTag(commitGitState.BaseCommitSHA)}, }, @@ -659,6 +681,7 @@ func Test_parseTags(t *testing.T) { {Name: "AnotherTest", Value: `Another-{{ .PRNumber }}`}, {Name: "Test", Value: "tag-value"}, }, + logger: logger, }, expectedTags: []tags.Tag{{Name: "AnotherTest", Value: "Another-" + strconv.Itoa(prGitState.PullRequestNumber)}, {Name: "Test", Value: "tag-value"}, expectedDefaultPRTag(prGitState.PullRequestNumber)}, }, @@ -671,6 +694,7 @@ func Test_parseTags(t *testing.T) { {Name: "AnotherTest", Value: `Another-{{ .CommitSHA }}`}, {Name: "Test", Value: "tag-value"}, }, + logger: logger, }, expectedTags: []tags.Tag{{Name: "AnotherTest", Value: "Another-" + commitGitState.BaseCommitSHA}, {Name: "Test", Value: "tag-value"}, expectedDefaultCommitTag(commitGitState.BaseCommitSHA)}, }, @@ -682,6 +706,7 @@ func Test_parseTags(t *testing.T) { tags: sets.Tags{ {Name: "BadTagTemplate", Value: `{{ .ASD }}`}, }, + logger: logger, }, expectErr: true, }, @@ -691,6 +716,7 @@ func Test_parseTags(t *testing.T) { gitState: prGitState, Config: buildConfig, tagsBase64: base64Tags, + logger: logger, }, expectedTags: []tags.Tag{ {Name: "base64testtag", Value: "testtag"}, @@ -701,7 +727,8 @@ func Test_parseTags(t *testing.T) { for _, c := range tc { t.Run(c.name, func(t *testing.T) { - tags, err := parseTags(c.options) + logger := c.options.logger + tags, err := parseTags(logger, c.options) if err != nil && !c.expectErr { t.Errorf("Got unexpected error: %s", err) } @@ -719,6 +746,11 @@ func Test_parseTags(t *testing.T) { func Test_getDefaultTag(t *testing.T) { g := NewGomegaWithT(t) + zapLogger, err := zap.NewProduction() + if err != nil { + t.Errorf("got error but didn't want to: %s", err) + } + logger := zapLogger.Sugar() tests := []struct { name string options options @@ -730,6 +762,7 @@ func Test_getDefaultTag(t *testing.T) { options: options{ gitState: prGitState, Config: buildConfig, + logger: logger, }, want: defaultPRTag, wantErr: false, @@ -739,6 +772,7 @@ func Test_getDefaultTag(t *testing.T) { options: options{ gitState: commitGitState, Config: buildConfig, + logger: logger, }, want: defaultCommitTag, wantErr: false, @@ -747,6 +781,7 @@ func Test_getDefaultTag(t *testing.T) { name: "Failure - No PR number or commit SHA", options: options{ gitState: GitStateConfig{}, + logger: logger, }, want: tags.Tag{}, wantErr: true, @@ -755,7 +790,8 @@ func Test_getDefaultTag(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - got, err := getDefaultTag(tt.options) + logger := tt.options.logger + got, err := getDefaultTag(logger, tt.options) if tt.wantErr { g.Expect(err).To(HaveOccurred()) } else { @@ -946,6 +982,11 @@ func (m *mockSigner) Sign([]string) error { } func Test_getDockerfileDirPath(t *testing.T) { + zapLogger, err := zap.NewProduction() + if err != nil { + t.Errorf("got error but didn't want to: %s", err) + } + logger := zapLogger.Sugar() type args struct { o options } @@ -961,6 +1002,7 @@ func Test_getDockerfileDirPath(t *testing.T) { o: options{ context: ".", dockerfile: "Dockerfile", + logger: logger, }, }, want: "/test-infra/cmd/image-builder", @@ -972,6 +1014,7 @@ func Test_getDockerfileDirPath(t *testing.T) { o: options{ context: "cmd/image-builder", dockerfile: "Dockerfile", + logger: logger, }, }, want: "/test-infra/cmd/image-builder", @@ -980,7 +1023,8 @@ func Test_getDockerfileDirPath(t *testing.T) { } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - got, err := getDockerfileDirPath(tt.args.o) + logger := tt.args.o.logger + got, err := getDockerfileDirPath(logger, tt.args.o) if (err != nil) != tt.wantErr { t.Errorf("getDockerfileDirPath() error = %v, wantErr %v", err, tt.wantErr) return @@ -992,36 +1036,48 @@ func Test_getDockerfileDirPath(t *testing.T) { } } -func Test_getEnvs(t *testing.T) { - type args struct { - o options - dockerfilePath string - } - tests := []struct { - name string - args args - want map[string]string - }{ - { - name: "Empty env file path", - args: args{ - o: options{ - context: ".", - dockerfile: "Dockerfile", - envFile: "", - }, - }, - want: map[string]string{}, - }, - } - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if got, _ := getEnvs(tt.args.o, tt.args.dockerfilePath); !reflect.DeepEqual(got, tt.want) { - t.Errorf("getEnvs() = %v, want %v", got, tt.want) - } - }) - } -} +// func Test_getEnvs(t *testing.T) { +// type args struct { +// o options +// dockerfilePath string +// } +// +// zapLogger, err := zap.NewProduction() +// if err != nil { +// t.Errorf("got error but didn't want to: %s", err) +// } +// logger := zapLogger.Sugar() +// +// tests := []struct { +// name string +// args args +// want map[string]string +// }{ +// { +// name: "Empty env file path", +// args: args{ +// o: options{ +// context: ".", +// dockerfile: "Dockerfile", +// envFile: "", +// logger: logger, +// }, +// }, +// want: map[string]string{}, +// }, +// } +// for _, tt := range tests { +// t.Run(tt.name, func(t *testing.T) { +// got, err := getEnvs(tt.args.o, tt.args.dockerfilePath) +// if err != nil { +// t.Errorf("getEnvs() error = %v", err) +// } +// if got != nil { +// t.Errorf("getEnvs() = %v, want %v", got, tt.want) +// } +// }) +// } +// } func Test_appendToTags(t *testing.T) { type args struct { @@ -1044,7 +1100,12 @@ func Test_appendToTags(t *testing.T) { } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - appendToTags(tt.args.target, tt.args.source) + zapLogger, err := zap.NewProduction() + if err != nil { + t.Errorf("got error but didn't want to: %s", err) + } + logger := zapLogger.Sugar() + appendToTags(logger, tt.args.target, tt.args.source) if !reflect.DeepEqual(tt.args.target, tt.want) { t.Errorf("appendToTags() got = %v, want %v", tt.args.target, tt.want) @@ -1058,29 +1119,36 @@ func Test_getParsedTagsAsJSON(t *testing.T) { parsedTags []tags.Tag } tests := []struct { - name string - args args - want string + name string + args args + want string + wantErr bool }{ { name: "Empty tags", args: args{ parsedTags: []tags.Tag{}, }, - want: "[]", + want: "[]", + wantErr: false, }, { name: "Multiple tags", args: args{ parsedTags: []tags.Tag{{Name: "key1", Value: "val1"}, {Name: "key2", Value: "val2"}}, }, - want: `[{"name":"key1","value":"val1"},{"name":"key2","value":"val2"}]`, + want: `[{"name":"key1","value":"val1"},{"name":"key2","value":"val2"}]`, + wantErr: false, }, } { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - if got := tagsAsJSON(tt.args.parsedTags); got != tt.want { + got, err := tagsAsJSON(tt.args.parsedTags) + if err != nil && !tt.wantErr { + t.Errorf("got error but didn't want to: %s", err) + } + if string(got) != tt.want { t.Errorf("tagsAsJSON() = %v, want %v", got, tt.want) } }) diff --git a/pkg/tags/options.go b/pkg/tags/options.go index 580440b9b184..66608666e6de 100644 --- a/pkg/tags/options.go +++ b/pkg/tags/options.go @@ -43,3 +43,10 @@ func PRNumber(pr string) TagOption { return nil } } + +func WithLogger(logger Logger) TagOption { + return func(t *Tagger) error { + t.logger = logger.With("component", "tagger") + return nil + } +} diff --git a/pkg/tags/tags.go b/pkg/tags/tags.go index 284663776d8b..d1adec189031 100644 --- a/pkg/tags/tags.go +++ b/pkg/tags/tags.go @@ -7,10 +7,19 @@ import ( "regexp" "text/template" "time" + + "github.com/kyma-project/test-infra/pkg/logging" + "go.uber.org/zap" ) +type Logger interface { + logging.StructuredLoggerInterface + logging.WithLoggerInterface +} + type Tagger struct { tags []Tag + logger Logger CommitSHA string ShortSHA string PRNumber string @@ -19,62 +28,85 @@ type Tagger struct { } func (tg *Tagger) Env(key string) string { + tg.logger.Debugw("reading environment variable", "variable_name", key, "variable_value", os.Getenv(key)) return os.Getenv(key) } func (tg *Tagger) ParseTags() ([]Tag, error) { + tg.logger.Debugw("started parsing tags") var parsed []Tag for _, tag := range tg.tags { if len(tag.Name) == 0 || len(tag.Value) == 0 { return nil, fmt.Errorf("tag name or value is empty, tag name: %s, tag value: %s", tag.Name, tag.Value) } + logger := tg.logger.With("tag", tag.Name, "value", tag.Value) + logger.Debugw("verified tag name and value are not empty") + logger.Debugw("parsing tag template") tmpl, err := template.New("tag").Parse(tag.Value) if err != nil { - return nil, err + return nil, fmt.Errorf("error parsing tag template: %w", err) } + logger.Debugw("parsed tag template") buf := bytes.Buffer{} err = tmpl.Execute(&buf, tg) if err != nil { - return nil, err + return nil, fmt.Errorf("error executing tag template: %w", err) } + logger.Debugw("successfully executed tag template", "computed_name", tag.Name, "computed_value", buf.String()) tag.Value = buf.String() err = tg.validateTag(tag) if err != nil { - return nil, err + return nil, fmt.Errorf("failed to validate tag: %w", err) } + logger.Debugw("tag validation passed") parsed = append(parsed, tag) + logger.Debugw("added tag to parsed tags") } + tg.logger.Debugw("all tags parsed", "parsed_tags", parsed) return parsed, nil } func (tg *Tagger) validateTag(tag Tag) error { + logger := tg.logger.With("tag", tag.Name, "value", tag.Value, "validation", tag.Validation) + logger.Debugw("started validating tag") + logger.Debugw("checking if validation regex is provided") if tag.Name == "default_tag" && len(tag.Validation) == 0 { - return fmt.Errorf("default_tag validation is empty, tag: %s", tag.Value) + return fmt.Errorf("default_tag required validation is empty, tag: %s", tag.Value) } if tag.Validation != "" { - // Verify PR default tag. Check if value starts with PR- and is followed by a number re := regexp.MustCompile(tag.Validation) + logger.Debugw("compiled regex", "regex", re.String()) match := re.FindAllString(tag.Value, -1) if match == nil { - return fmt.Errorf("tag validation failed, tag: %s, validation: %s", tag.Value, tag.Validation) + return fmt.Errorf("no regex match found, tag: %s, validation: %s", tag.Value, tag.Validation) } + logger.Debugw("regex matched successfully", "match", match) } return nil } -func NewTagger(tags []Tag, opts ...TagOption) (*Tagger, error) { +func NewTagger(logger Logger, tags []Tag, opts ...TagOption) (*Tagger, error) { + logger.Debugw("started creating new tagger", "tags", tags) now := time.Now() + logger.Debugw("read current time", "time", now) t := Tagger{ tags: tags, Time: now, Date: now.Format("20060102"), } + logger.Debugw("created new tagger, applying options") for _, o := range opts { err := o(&t) if err != nil { return nil, fmt.Errorf("error applying tag option: %w", err) } } + logger.Debugw("applied options to tagger") + if t.logger == nil { + t.logger = zap.NewNop().Sugar() + logger.Debugw("no logger provided for tagger, used nop logger") + } + logger.Debugw("finished creating new tagger") return &t, nil } diff --git a/pkg/tags/tags_test.go b/pkg/tags/tags_test.go index ff2d99bea7dd..8699315b481e 100644 --- a/pkg/tags/tags_test.go +++ b/pkg/tags/tags_test.go @@ -3,6 +3,8 @@ package tags import ( "testing" "time" + + "go.uber.org/zap" ) func TestTagger_ParseTags(t *testing.T) { @@ -37,6 +39,11 @@ func TestTagger_ParseTags(t *testing.T) { } for _, c := range tc { t.Run(c.name, func(t *testing.T) { + zapLogger, err := zap.NewDevelopment() + if err != nil { + t.Errorf("error creating zap logger: %v", err) + } + logger := zapLogger.Sugar() t.Setenv("test-var", "test") tag := Tagger{ tags: c.template, @@ -44,6 +51,7 @@ func TestTagger_ParseTags(t *testing.T) { CommitSHA: "f1c7ca0b532141898f56c1843ae60ebec3a75a85", Time: time.Now(), Date: time.Date(2022, 06, 02, 01, 01, 01, 1, time.Local).Format("20060102"), + logger: logger, } got, err := tag.ParseTags() if err != nil {