feat: add step/job id and results to json logs

Co-authored-by: Markus Wolf <markus.wolf@new-work.se>
xing · May 18, 2022 · 9287ec5 · 9287ec5
1 parent 6a2197f
commit 9287ec5
Show file tree

Hide file tree

Showing 5 changed files with 25 additions and 13 deletions.
diff --git 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
@@ -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
@@ -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
@@ -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
@@ -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
 	}