Skip to content

Commit

Permalink
fix: clean error message for negative tests
Browse files Browse the repository at this point in the history
  • Loading branch information
vsukhin committed Apr 10, 2024
1 parent 1224342 commit 598010a
Show file tree
Hide file tree
Showing 5 changed files with 46 additions and 73 deletions.
38 changes: 19 additions & 19 deletions pkg/executor/client/job.go
Original file line number Diff line number Diff line change
Expand Up @@ -362,7 +362,7 @@ func (c *JobExecutor) updateResultsFromPod(ctx context.Context, pod corev1.Pod,

// save stop time and final state
defer func() {
if err := c.stopExecution(ctx, l, execution, execution.ExecutionResult, isNegativeTest, err); err != nil {
if err := c.stopExecution(ctx, l, execution, execution.ExecutionResult, isNegativeTest); err != nil {
c.streamLog(ctx, execution.Id, events.NewErrorLog(err))
l.Errorw("error stopping execution after updating results from pod", "error", err)
}
Expand Down Expand Up @@ -397,21 +397,22 @@ func (c *JobExecutor) updateResultsFromPod(ctx context.Context, pod corev1.Pod,
}
}

var logs []byte
logs, err = executor.GetPodLogs(ctx, c.ClientSet, execution.TestNamespace, pod)
logs, err := executor.GetPodLogs(ctx, c.ClientSet, execution.TestNamespace, pod)
if err != nil {
l.Errorw("get pod logs error", "error", err)
c.streamLog(ctx, execution.Id, events.NewErrorLog(err))
}

// don't attach logs if logs v2 is enabled - they will be streamed through the logs service
attachLogs := !c.features.LogsV2
// parse job output log (JSON stream)
execution.ExecutionResult, err = output.ParseRunnerOutput(logs, attachLogs)
if err != nil {
l.Errorw("parse output error", "error", err)
c.streamLog(ctx, execution.Id, events.NewErrorLog(errors.Wrap(err, "can't get test execution job output")))
return execution.ExecutionResult, err
if len(logs) != 0 {
// parse job output log (JSON stream)
execution.ExecutionResult, err = output.ParseRunnerOutput(logs, attachLogs)
if err != nil {
l.Errorw("parse output error", "error", err)
c.streamLog(ctx, execution.Id, events.NewErrorLog(errors.Wrap(err, "can't get test execution job output")))
return execution.ExecutionResult, err
}
}

if execution.ExecutionResult.IsFailed() {
Expand All @@ -431,7 +432,7 @@ func (c *JobExecutor) updateResultsFromPod(ctx context.Context, pod corev1.Pod,
return execution.ExecutionResult, nil
}

func (c *JobExecutor) stopExecution(ctx context.Context, l *zap.SugaredLogger, execution *testkube.Execution, result *testkube.ExecutionResult, isNegativeTest bool, passedErr error) error {
func (c *JobExecutor) stopExecution(ctx context.Context, l *zap.SugaredLogger, execution *testkube.Execution, result *testkube.ExecutionResult, isNegativeTest bool) error {
savedExecution, err := c.Repository.Get(ctx, execution.Id)
if err != nil {
l.Errorw("get execution error", "error", err)
Expand All @@ -440,7 +441,7 @@ func (c *JobExecutor) stopExecution(ctx context.Context, l *zap.SugaredLogger, e

logEvent := events.NewLog().WithSource(events.SourceJobExecutor)

l.Debugw("stopping execution", "executionId", execution.Id, "status", result.Status, "executionStatus", execution.ExecutionResult.Status, "passedError", passedErr, "savedExecutionStatus", savedExecution.ExecutionResult.Status)
l.Debugw("stopping execution", "executionId", execution.Id, "status", result.Status, "executionStatus", execution.ExecutionResult.Status, "savedExecutionStatus", savedExecution.ExecutionResult.Status)

c.streamLog(ctx, execution.Id, logEvent.WithContent("stopping execution"))
defer c.streamLog(ctx, execution.Id, logEvent.WithContent("execution stopped"))
Expand All @@ -455,14 +456,17 @@ func (c *JobExecutor) stopExecution(ctx context.Context, l *zap.SugaredLogger, e
if result.IsFailed() {
l.Debugw("test run was expected to fail, and it failed as expected", "test", execution.TestName)
execution.ExecutionResult.Status = testkube.ExecutionStatusPassed
result.Status = testkube.ExecutionStatusPassed
execution.ExecutionResult.ErrorMessage = ""
result.Output = result.Output + "\nTest run was expected to fail, and it failed as expected"
} else {
l.Debugw("test run was expected to fail - the result will be reversed", "test", execution.TestName)
execution.ExecutionResult.Status = testkube.ExecutionStatusFailed
result.Status = testkube.ExecutionStatusFailed
execution.ExecutionResult.ErrorMessage = "negative test error"
result.Output = result.Output + "\nTest run was expected to fail, the result will be reversed"
}

result.Status = execution.ExecutionResult.Status
result.ErrorMessage = execution.ExecutionResult.ErrorMessage
}

err = c.Repository.EndExecution(ctx, *execution)
Expand All @@ -471,10 +475,6 @@ func (c *JobExecutor) stopExecution(ctx context.Context, l *zap.SugaredLogger, e
return err
}

if passedErr != nil {
result.Err(passedErr)
}

eventToSend := testkube.NewEventEndTestSuccess(execution)
if result.IsAborted() {
result.Output = result.Output + "\nTest run was aborted manually."
Expand Down Expand Up @@ -760,7 +760,7 @@ func (c *JobExecutor) Abort(ctx context.Context, execution *testkube.Execution)
l.Errorw("error aborting job", "execution", execution.Id, "error", err)
}
l.Debugw("job aborted", "execution", execution.Id, "result", result)
if err := c.stopExecution(ctx, l, execution, result, false, nil); err != nil {
if err := c.stopExecution(ctx, l, execution, result, false); err != nil {
l.Errorw("error stopping execution on job executor abort", "error", err)
}
return result, nil
Expand All @@ -780,7 +780,7 @@ func (c *JobExecutor) Timeout(ctx context.Context, jobName string) (result *test
result = &testkube.ExecutionResult{
Status: testkube.ExecutionStatusTimeout,
}
if err := c.stopExecution(ctx, l, &execution, result, false, nil); err != nil {
if err := c.stopExecution(ctx, l, &execution, result, false); err != nil {
l.Errorw("error stopping execution on job executor timeout", "error", err)
}

Expand Down
49 changes: 26 additions & 23 deletions pkg/executor/containerexecutor/containerexecutor.go
Original file line number Diff line number Diff line change
Expand Up @@ -348,13 +348,13 @@ func (c *ContainerExecutor) updateResultsFromPod(
jobOptions *JobOptions,
isNegativeTest bool,
) (*testkube.ExecutionResult, error) {
var err error

// save stop time and final state
defer c.stopExecution(ctx, execution, execution.ExecutionResult, isNegativeTest)

// wait for pod
l.Debug("poll immediate waiting for executor pod")

var err error
if err = wait.PollUntilContextTimeout(ctx, pollInterval, c.podStartTimeout, true, executor.IsPodLoggable(c.clientSet, executorPod.Name, execution.TestNamespace)); err != nil {
l.Errorw("waiting for executor pod started error", "error", err)
} else if err = wait.PollUntilContextTimeout(ctx, pollInterval, pollTimeout, true, executor.IsPodReady(c.clientSet, executorPod.Name, execution.TestNamespace)); err != nil {
Expand Down Expand Up @@ -388,7 +388,7 @@ func (c *ContainerExecutor) updateResultsFromPod(
return execution.ExecutionResult, err
}

scraperPodName := execution.Id + "-scraper"
scraperPodName := execution.Id + ScraperPodSuffix
scraperPods, err := executor.GetJobPods(ctx, podsClient, scraperPodName, 1, 10)
if err != nil {
return execution.ExecutionResult, err
Expand Down Expand Up @@ -449,28 +449,29 @@ func (c *ContainerExecutor) updateResultsFromPod(
}

executorLogs = append(executorLogs, scraperLogs...)

// parse container output log (mixed JSON and plain text stream)
executionResult, output, err := output.ParseContainerOutput(executorLogs)
if err != nil {
l.Errorw("parse output error", "error", err)
execution.ExecutionResult.Output = output
execution.ExecutionResult.Err(err)
err = c.repository.UpdateResult(ctx, execution.Id, *execution)
if len(executorLogs) != 0 {
// parse container output log (mixed JSON and plain text stream)
executionResult, output, err := output.ParseContainerOutput(executorLogs)
if err != nil {
l.Infow("Update result", "error", err)
l.Errorw("parse output error", "error", err)
execution.ExecutionResult.Output = output
execution.ExecutionResult.Err(err)
err = c.repository.UpdateResult(ctx, execution.Id, *execution)
if err != nil {
l.Infow("Update result", "error", err)
}
return execution.ExecutionResult, err
}
return execution.ExecutionResult, err
}

if executionResult != nil {
execution.ExecutionResult = executionResult
}
if executionResult != nil {
execution.ExecutionResult = executionResult
}

// don't attach logs if logs v2 is enabled - they will be streamed through the logs service
attachLogs := !c.features.LogsV2
if attachLogs {
execution.ExecutionResult.Output = output
// don't attach logs if logs v2 is enabled - they will be streamed through the logs service
attachLogs := !c.features.LogsV2
if attachLogs {
execution.ExecutionResult.Output = output
}
}

if execution.ExecutionResult.IsFailed() {
Expand Down Expand Up @@ -502,15 +503,17 @@ func (c *ContainerExecutor) stopExecution(ctx context.Context,
if result.IsFailed() {
c.log.Debugw("test run was expected to fail, and it failed as expected", "test", execution.TestName)
execution.ExecutionResult.Status = testkube.ExecutionStatusPassed
result.Status = testkube.ExecutionStatusPassed
execution.ExecutionResult.ErrorMessage = ""
result.Output = result.Output + "\nTest run was expected to fail, and it failed as expected"
} else {
c.log.Debugw("test run was expected to fail - the result will be reversed", "test", execution.TestName)
execution.ExecutionResult.Status = testkube.ExecutionStatusFailed
result.Status = testkube.ExecutionStatusFailed
execution.ExecutionResult.ErrorMessage = "negative test error"
result.Output = result.Output + "\nTest run was expected to fail, the result will be reversed"
}

result.Status = execution.ExecutionResult.Status
result.ErrorMessage = execution.ExecutionResult.ErrorMessage
err := c.repository.UpdateResult(ctx, execution.Id, *execution)
if err != nil {
c.log.Errorw("Update execution result error", "error", err)
Expand Down
11 changes: 0 additions & 11 deletions pkg/executor/output/parser.go
Original file line number Diff line number Diff line change
Expand Up @@ -38,13 +38,6 @@ func GetLogEntry(b []byte) (out Output, err error) {
// {"type": "result", "result": {"id": "2323", "output": "-----"}, "time": "..."}
func ParseRunnerOutput(b []byte, attachLogs bool) (*testkube.ExecutionResult, error) {
result := &testkube.ExecutionResult{}
if len(b) == 0 {
errMessage := "no logs found"
if attachLogs {
result.Output = errMessage
}
return result.Err(errors.New(errMessage)), nil
}
logs, err := parseLogs(b)
if err != nil {
err := fmt.Errorf("could not parse logs \"%s\": %v", b, err.Error())
Expand Down Expand Up @@ -85,10 +78,6 @@ func ParseRunnerOutput(b []byte, attachLogs bool) (*testkube.ExecutionResult, er
// {"type": "result", "result": {"id": "2323", "output": "-----"}, "time": "..."}
func ParseContainerOutput(b []byte) (*testkube.ExecutionResult, string, error) {
result := &testkube.ExecutionResult{}
if len(b) == 0 {
return nil, "", nil
}

logs, err := parseContainerLogs(b)
if err != nil {
err = fmt.Errorf("could not parse logs \"%s\": %v", b, err.Error())
Expand Down
20 changes: 0 additions & 20 deletions pkg/executor/output/parser_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -61,16 +61,6 @@ func TestGetLogEntry(t *testing.T) {
func TestParseRunnerOutput(t *testing.T) {
t.Parallel()

t.Run("Empty runner output", func(t *testing.T) {
t.Parallel()

result, err := ParseRunnerOutput([]byte{}, true)

assert.Equal(t, "no logs found", result.Output)
assert.NoError(t, err)
assert.Equal(t, testkube.ExecutionStatusFailed, result.Status)
})

t.Run("Invalid log", func(t *testing.T) {
t.Parallel()

Expand Down Expand Up @@ -405,16 +395,6 @@ running test [63ca8c8988564860327a16b5]
func TestParseContainerOutput(t *testing.T) {
t.Parallel()

t.Run("Empty runner output", func(t *testing.T) {
t.Parallel()

result, output, err := ParseContainerOutput([]byte{})

assert.Equal(t, "", output)
assert.NoError(t, err)
assert.Nil(t, result)
})

t.Run("Runner output with no timestamps", func(t *testing.T) {
t.Parallel()

Expand Down
1 change: 1 addition & 0 deletions pkg/triggers/watcher.go
Original file line number Diff line number Diff line change
Expand Up @@ -340,6 +340,7 @@ func (s *Service) checkExecutionPodStatus(ctx context.Context, executionID strin
if test.Spec.ExecutionRequest != nil && test.Spec.ExecutionRequest.NegativeTest {
s.logger.Debugw("test run was expected to fail, and it failed as expected", "test", execution.TestName)
execution.ExecutionResult.Status = testkube.ExecutionStatusPassed
execution.ExecutionResult.ErrorMessage = ""
}

err = s.resultRepository.UpdateResult(ctx, executionID, execution)
Expand Down

0 comments on commit 598010a

Please sign in to comment.