From 9287ec55dfcc6b1b3e02b399f858f2fc2bfc084f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Bj=C3=B6rn=20Brauer?= Date: Tue, 17 May 2022 13:48:43 +0000 Subject: [PATCH] feat: add step/job id and results to json logs Co-authored-by: Markus Wolf --- pkg/runner/command_test.go | 2 +- pkg/runner/job_executor.go | 11 ++++++++--- pkg/runner/logger.go | 15 +++++++++++---- pkg/runner/runner.go | 2 +- pkg/runner/step.go | 8 ++++---- 5 files changed, 25 insertions(+), 13 deletions(-) diff --git a/pkg/runner/command_test.go b/pkg/runner/command_test.go index 1c72768eef4..0f3d32b0d6d 100644 --- a/pkg/runner/command_test.go +++ b/pkg/runner/command_test.go @@ -164,7 +164,7 @@ func TestAddmaskUsemask(t *testing.T) { re := captureOutput(t, func() { ctx := context.Background() - ctx = WithJobLogger(ctx, "testjob", config, &rc.Masks) + ctx = WithJobLogger(ctx, "0", "testjob", config, &rc.Masks) handler := rc.commandHandler(ctx) handler("::add-mask::secret\n") diff --git a/pkg/runner/job_executor.go b/pkg/runner/job_executor.go index 632d48439f0..23ded3d9c58 100644 --- a/pkg/runner/job_executor.go +++ b/pkg/runner/job_executor.go @@ -40,6 +40,7 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo preSteps = append(preSteps, info.startContainer()) for i, stepModel := range infoSteps { + stepModel := stepModel if stepModel == nil { return func(ctx context.Context) error { return fmt.Errorf("invalid Step %v: missing run or uses key", i) @@ -55,11 +56,12 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo return common.NewErrorExecutor(err) } - preSteps = append(preSteps, step.pre()) + preSteps = append(preSteps, func(ctx context.Context) error { + return step.pre()(withStepLogger(ctx, stepModel.ID, stepModel.String())) + }) stepExec := step.main() steps = append(steps, func(ctx context.Context) error { - stepName := stepModel.String() return (func(ctx context.Context) error { logger := common.Logger(ctx) err := stepExec(ctx) @@ -71,7 +73,7 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo common.SetJobError(ctx, ctx.Err()) } return nil - })(withStepLogger(ctx, stepName)) + })(withStepLogger(ctx, stepModel.ID, stepModel.String())) }) // run the post exector in reverse order @@ -83,15 +85,18 @@ func newJobExecutor(info jobInfo, sf stepFactory, rc *RunContext) common.Executo } postExecutor = postExecutor.Finally(func(ctx context.Context) error { + logger := common.Logger(ctx) jobError := common.JobError(ctx) if jobError != nil { info.result("failure") + logger.WithField("jobResult", "failure").Infof("\U0001F3C1 Job failed") } else { err := info.stopContainer()(ctx) if err != nil { return err } info.result("success") + logger.WithField("jobResult", "success").Infof("\U0001F3C1 Job succeeded") } return nil diff --git a/pkg/runner/logger.go b/pkg/runner/logger.go index f4217a1f616..7d221e03e73 100644 --- a/pkg/runner/logger.go +++ b/pkg/runner/logger.go @@ -58,7 +58,7 @@ func WithMasks(ctx context.Context, masks *[]string) context.Context { } // WithJobLogger attaches a new logger to context that is aware of steps -func WithJobLogger(ctx context.Context, jobName string, config *Config, masks *[]string) context.Context { +func WithJobLogger(ctx context.Context, jobID string, jobName string, config *Config, masks *[]string) context.Context { mux.Lock() defer mux.Unlock() @@ -82,7 +82,11 @@ func WithJobLogger(ctx context.Context, jobName string, config *Config, masks *[ logger.SetFormatter(formatter) logger.SetOutput(os.Stdout) logger.SetLevel(logrus.GetLevel()) - rtn := logger.WithFields(logrus.Fields{"job": jobName, "dryrun": common.Dryrun(ctx)}).WithContext(ctx) + rtn := logger.WithFields(logrus.Fields{ + "job": jobName, + "jobID": jobID, + "dryrun": common.Dryrun(ctx), + }).WithContext(ctx) return common.WithLogger(ctx, rtn) } @@ -92,8 +96,11 @@ func WithCompositeLogger(ctx context.Context, masks *[]string) context.Context { return common.WithLogger(ctx, common.Logger(ctx).WithFields(logrus.Fields{}).WithContext(ctx)) } -func withStepLogger(ctx context.Context, stepName string) context.Context { - rtn := common.Logger(ctx).WithFields(logrus.Fields{"step": stepName}) +func withStepLogger(ctx context.Context, stepID string, stepName string) context.Context { + rtn := common.Logger(ctx).WithFields(logrus.Fields{ + "step": stepName, + "stepID": stepID, + }) return common.WithLogger(ctx, rtn) } diff --git a/pkg/runner/runner.go b/pkg/runner/runner.go index 427cda9b3b6..18f8d1de69f 100644 --- a/pkg/runner/runner.go +++ b/pkg/runner/runner.go @@ -178,7 +178,7 @@ func (runner *runnerImpl) NewPlanExecutor(plan *model.Plan) common.Executor { } return nil - })(common.WithJobErrorContainer(WithJobLogger(ctx, jobName, rc.Config, &rc.Masks))) + })(common.WithJobErrorContainer(WithJobLogger(ctx, rc.Run.JobID, jobName, rc.Config, &rc.Masks))) }) } pipeline = append(pipeline, common.NewParallelExecutor(maxParallel, stageExecutor...)) diff --git a/pkg/runner/step.go b/pkg/runner/step.go index 4fbfcd00af3..87da9f43996 100644 --- a/pkg/runner/step.go +++ b/pkg/runner/step.go @@ -81,9 +81,9 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo } if !runStep { - logger.Debugf("Skipping step '%s' due to '%s'", stepModel, ifExpression) rc.StepResults[rc.CurrentStep].Conclusion = model.StepStatusSkipped rc.StepResults[rc.CurrentStep].Outcome = model.StepStatusSkipped + logger.Debugf("Skipping step '%s' due to '%s'", stepModel, ifExpression) return nil } @@ -96,10 +96,8 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo err = executor(ctx) if err == nil { - logger.Infof(" \u2705 Success - %s %s", stage, stepString) + logger.WithField("stepResult", rc.StepResults[rc.CurrentStep].Outcome).Infof(" \u2705 Success - %s %s", stage, stepString) } else { - logger.Errorf(" \u274C Failure - %s %s", stage, stepString) - rc.StepResults[rc.CurrentStep].Outcome = model.StepStatusFailure if stepModel.ContinueOnError { logger.Infof("Failed but continue next step") @@ -108,6 +106,8 @@ func runStepExecutor(step step, stage stepStage, executor common.Executor) commo } else { rc.StepResults[rc.CurrentStep].Conclusion = model.StepStatusFailure } + + logger.WithField("stepResult", rc.StepResults[rc.CurrentStep].Outcome).Errorf(" \u274C Failure - %s %s", stage, stepString) } return err }