Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add status reason messaging #833

Merged
merged 31 commits into from Dec 9, 2022
Merged
Show file tree
Hide file tree
Changes from 14 commits
Commits
Show all changes
31 commits
Select commit Hold shift + click to select a range
94d364b
Added step status reason messaging
vshah23 Nov 30, 2022
e822fbc
Moved status reason to result model
vshah23 Nov 30, 2022
72ca723
Fixed formatting of status reason time interval
vshah23 Dec 1, 2022
633ea76
Added unit tests for the status reason messaging.
vshah23 Dec 1, 2022
74d7f0f
Fix linter errors
vshah23 Dec 1, 2022
e67b814
Fixed nil properties
vshah23 Dec 6, 2022
e561d66
Added and utilized short reason in footer and summary titles
vshah23 Dec 6, 2022
45f9389
Removed status reason from run output and added it to footer instead
vshah23 Dec 6, 2022
5df29c9
Updated unit tests
vshah23 Dec 6, 2022
c4c8447
Fix linter error
vshah23 Dec 6, 2022
96c7e25
Updated short reason and added unit test
vshah23 Dec 7, 2022
c73bdc1
Code style
vshah23 Dec 7, 2022
da051c4
Fixed unit test
vshah23 Dec 7, 2022
a5ba8bd
Update unit tests
vshah23 Dec 7, 2022
069dfff
Update unit tests
vshah23 Dec 7, 2022
4d53b36
StatusReason -> StatusName
vshah23 Dec 7, 2022
cff54e3
Matched output to step status doc
vshah23 Dec 8, 2022
036a5d0
Fix unit tests
vshah23 Dec 8, 2022
eca7af3
Update step finished statuses (#836)
godrei Dec 8, 2022
3254390
Updated StepRunStatus Names
vshah23 Dec 8, 2022
cd3ef07
Updated unit test
vshah23 Dec 8, 2022
a0208c2
Update unit tests
vshah23 Dec 8, 2022
05c45fb
Update unit tests
vshah23 Dec 9, 2022
eefee40
Attempt to fix flakey test
vshah23 Dec 9, 2022
d3e84c9
Update trimTitle method
godrei Dec 9, 2022
5900a0a
Update step finished console log
godrei Dec 9, 2022
7f4d85f
Fix event print tests
godrei Dec 9, 2022
735d934
Replace special quotation marks
godrei Dec 9, 2022
b58b743
Restore original value of StepRunStatuses
godrei Dec 9, 2022
4b88264
PR review updates
godrei Dec 9, 2022
8796da7
Restore earlier trimTitle
godrei Dec 9, 2022
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
4 changes: 2 additions & 2 deletions bitrise/print.go
Expand Up @@ -39,7 +39,7 @@ func trimTitle(title string, titleSuffix string, titleBoxWidth int) string {
return title
}

return fmt.Sprintf("%s %s", title, titleSuffix)
return strings.TrimSpace(fmt.Sprintf("%s %s", title, titleSuffix))
godrei marked this conversation as resolved.
Show resolved Hide resolved
}

func getTrimmedStepName(stepRunResult models.StepRunResultsModel) string {
Expand All @@ -59,7 +59,7 @@ func getTrimmedStepName(stepRunResult models.StepRunResultsModel) string {
}

suffix := ""
reason := stepRunResult.Status.Reason(stepRunResult.ExitCode)
reason := stepRunResult.ShortReason()
godrei marked this conversation as resolved.
Show resolved Hide resolved
if reason != "" {
suffix = fmt.Sprintf("(%s)", reason)
}
Expand Down
14 changes: 7 additions & 7 deletions bitrise/print_test.go
Expand Up @@ -35,7 +35,7 @@ func TestGetTrimmedStepName(t *testing.T) {
}

actual := getTrimmedStepName(result)
expected := "This is a very long string, this is a very long string, thi..."
expected := "This is a very long string, this is a very long s... (Success)"
require.Equal(t, expected, actual)
}

Expand All @@ -58,7 +58,7 @@ func TestGetTrimmedStepName(t *testing.T) {
}

actual := getTrimmedStepName(result)
expected := ""
expected := "(Success)"
require.Equal(t, expected, actual)
}
}
Expand Down Expand Up @@ -92,7 +92,7 @@ func Test_getRunningStepFooterMainSection(t *testing.T) {
ErrorStr: longStr,
ExitCode: 1,
},
expected: "| \x1b[31;1mx\x1b[0m | \x1b[31;1mThis is a very long string, this is a very l... (exit code: 1)\x1b[0m| 0.01 sec |",
expected: "| \x1b[31;1mx\x1b[0m | \x1b[31;1mThis is a very long string, this is a very long st... (Failed)\x1b[0m| 0.01 sec |",
},
{
name: "aborted step due to no output",
Expand All @@ -104,15 +104,15 @@ func Test_getRunningStepFooterMainSection(t *testing.T) {
ErrorStr: longStr,
ExitCode: 1,
},
expected: "| \x1b[31;1m/\x1b[0m | \x1b[31;1mThis is a very long string, th... (timed out due to no output)\x1b[0m| 0.01 sec |",
expected: "| \x1b[31;1m/\x1b[0m | \x1b[31;1mThis is a very long string, this is a very long st... (Failed)\x1b[0m| 0.01 sec |",
},
{
name: "successful step",
result: models.StepRunResultsModel{
StepInfo: noTitleInfo,
Status: models.StepRunStatusCodeSuccess,
},
expected: "| \x1b[32;1m✓\x1b[0m | \x1b[32;1m\x1b[0m | 0.00 sec |",
expected: "| \x1b[32;1m✓\x1b[0m | \x1b[32;1m(Success)\x1b[0m | 0.00 sec |",
},
{
name: "long runtime",
Expand All @@ -121,7 +121,7 @@ func Test_getRunningStepFooterMainSection(t *testing.T) {
Status: models.StepRunStatusCodeSuccess,
RunTime: 100 * 1000 * 1e9, // 100 * 1000 * 10^9 nanosec = 100 000 sec
},
expected: "| \x1b[32;1m✓\x1b[0m | \x1b[32;1m\x1b[0m | 28 hour |",
expected: "| \x1b[32;1m✓\x1b[0m | \x1b[32;1m(Success)\x1b[0m | 28 hour |",
},
{
name: "very long runtime",
Expand All @@ -130,7 +130,7 @@ func Test_getRunningStepFooterMainSection(t *testing.T) {
Status: models.StepRunStatusCodeSuccess,
RunTime: time.Duration(1000) * time.Hour,
},
expected: "| \x1b[32;1m✓\x1b[0m | \x1b[32;1m\x1b[0m | 999+ hour|",
expected: "| \x1b[32;1m✓\x1b[0m | \x1b[32;1m(Success)\x1b[0m | 999+ hour|",
},
}
for _, tt := range tests {
Expand Down
19 changes: 2 additions & 17 deletions cli/build_run_result_collector.go
Expand Up @@ -10,7 +10,6 @@ import (
"github.com/bitrise-io/bitrise/models"
"github.com/bitrise-io/bitrise/tools/timeoutcmd"
"github.com/bitrise-io/bitrise/utils"
"github.com/bitrise-io/go-utils/colorstring"
"github.com/bitrise-io/go-utils/errorutil"
"github.com/bitrise-io/go-utils/pointers"
coreanalytics "github.com/bitrise-io/go-utils/v2/analytics"
Expand Down Expand Up @@ -121,31 +120,16 @@ func (r buildRunResultCollector) registerStepRunResults(
case models.StepRunStatusCodePreparationFailed:
buildRunResults.FailedSteps = append(buildRunResults.FailedSteps, stepResults)
case models.StepRunStatusCodeFailed:
if !isExitStatusError {
log.Errorf("Step (%s) failed: %s", pointers.StringWithDefault(stepInfoCopy.Step.Title, "missing title"), err)
}
buildRunResults.FailedSteps = append(buildRunResults.FailedSteps, stepResults)
case models.StepRunStatusCodeFailedSkippable:
if !isExitStatusError {
log.Warnf("Step (%s) failed, but was marked as skippable: %s", pointers.StringWithDefault(stepInfoCopy.Step.Title, "missing title"), err)
} else {
log.Warnf("Step (%s) failed, but was marked as skippable", pointers.StringWithDefault(stepInfoCopy.Step.Title, "missing title"))
}
buildRunResults.FailedSkippableSteps = append(buildRunResults.FailedSkippableSteps, stepResults)
case models.StepRunStatusAbortedWithCustomTimeout, models.StepRunStatusAbortedWithNoOutputTimeout:
log.Errorf("Step (%s) aborted: %s", pointers.StringWithDefault(stepInfoCopy.Step.Title, "missing title"), err)
buildRunResults.FailedSteps = append(buildRunResults.FailedSteps, stepResults)
case models.StepRunStatusCodeSkipped:
log.Warnf("A previous step failed, and this step (%s) was not marked as IsAlwaysRun, skipped", pointers.StringWithDefault(stepInfoCopy.Step.Title, "missing title"))
buildRunResults.SkippedSteps = append(buildRunResults.SkippedSteps, stepResults)
case models.StepRunStatusCodeSkippedWithRunIf:
log.Warn("The step's (" + pointers.StringWithDefault(stepInfoCopy.Step.Title, "missing title") + ") Run-If expression evaluated to false - skipping")
if runIf != "" {
log.Info("The Run-If expression was: ", colorstring.Blue(runIf))
}
buildRunResults.SkippedSteps = append(buildRunResults.SkippedSteps, stepResults)
default:
log.Error("Unknown result code")
return
}

Expand Down Expand Up @@ -204,7 +188,8 @@ func stepFinishedParamsFromResults(results models.StepRunResultsModel, stepExecu
ExecutionId: stepExecutionId,
InternalStatus: int(results.Status),
Status: results.Status.HumanReadableStatus(),
StatusReason: results.Status.Reason(results.ExitCode),
StatusReason: results.StatusReason(),
ShortReason: results.ShortReason(),
Title: title,
RunTime: results.RunTime.Milliseconds(),
SupportURL: supportURL,
Expand Down
12 changes: 12 additions & 0 deletions cli/run_util.go
Expand Up @@ -707,6 +707,18 @@ func activateAndRunSteps(
stepInfoPtr.Step.SourceCodeURL = pointers.NewStringPtr(*mergedStep.SourceCodeURL)
}

if mergedStep.RunIf != nil {
stepInfoPtr.Step.RunIf = pointers.NewStringPtr(*mergedStep.RunIf)
}

if mergedStep.Timeout != nil {
stepInfoPtr.Step.Timeout = pointers.NewIntPtr(*mergedStep.Timeout)
}

if mergedStep.NoOutputTimeout != nil {
stepInfoPtr.Step.NoOutputTimeout = pointers.NewIntPtr(*mergedStep.NoOutputTimeout)
}
Comment on lines +711 to +721
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These are needed because they were not set on the stepInfoPtr previously? I was trying to see where we are reading these from the stepInfoPtr but could not see it. Is this a change to just make the code technically correct?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These are needed because they were not set on the stepInfoPtr previously?

Yes, if you search for stepInfoPtr.Step. in the activateAndRunSteps func, you can see that we only set the step properties that are later used for presentation (step boxes).

stepInfoPtr is passed to the buildRunResultCollector.registerStepRunResults, which uses it for creating the stepResults:

Then the added fields are used for creating the status reason: https://github.com/bitrise-io/bitrise/blob/CI-318/cli/build_run_result_collector.go#L184


// At this point we have a filled up step info model and also have a step model which is contains the merged step
// data from the bitrise.yml and the steps step.yml.
// If the step title contains the step id or the step library as a prefix then we will take the original steps
Expand Down
5 changes: 4 additions & 1 deletion log/event_print.go
Expand Up @@ -91,9 +91,12 @@ func generateStepFinishedFooterLines(params StepFinishedParams) []string {
}

var lines []string
if params.StatusReason != "" {
lines = append(lines, params.StatusReason)
}
lines = append(lines, sectionSeparator)
lines = append(lines, mainSeparator)
lines = append(lines, getSummaryFooterRow(params.InternalStatus, params.Title, params.StatusReason, params.RunTime, deprecated))
lines = append(lines, getSummaryFooterRow(params.InternalStatus, params.Title, params.ShortReason, params.RunTime, deprecated))
lines = append(lines, mainSeparator)

hasPreviousSection := false
Expand Down
64 changes: 47 additions & 17 deletions log/event_print_test.go
Expand Up @@ -113,6 +113,8 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusCodeSuccess,
Status: "success",
StatusReason: "",
ShortReason: "",
Title: "Normal step name",
RunTime: 1234567,
LastStep: true,
Expand All @@ -130,14 +132,16 @@ func TestStepFooterPrinting(t *testing.T) {
InternalStatus: models.StepRunStatusCodeFailed,
Status: "failed",
StatusReason: "exit code: 1",
ShortReason: "exit code: 1",
Title: "Loooooooooooooooooooooooooooooooooong step name",
RunTime: 9999,
LastStep: true,
},
expectedOutput: []string{
"exit code: 1",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1mx\u001B[0m | \u001B[31;1mLoooooooooooooooooooooooooooooooooong step ... (exit code: 1)\u001B[0m | 10.00 sec |",
"| \x1b[31;1mx\x1b[0m | \x1b[31;1mLoooooooooooooooooooooooooooooooooong step ... (exit code: 1)\x1b[0m | 10.00 sec |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -146,15 +150,17 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusCodeFailedSkippable,
Status: "failed_skippable",
StatusReason: "exit code: 2",
StatusReason: "This Step failed, but it was marked as “is_skippable”, so the build continued.",
ShortReason: "exit code: 1",
Title: "Simple Git",
RunTime: 3333,
LastStep: true,
},
expectedOutput: []string{
"This Step failed, but it was marked as “is_skippable”, so the build continued.",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[33;1m!\u001B[0m | \u001B[33;1mSimple Git (exit code: 2) \u001B[0m | 3.33 sec |",
"| \x1b[33;1m!\x1b[0m | \x1b[33;1mSimple Git (exit code: 1) \x1b[0m | 3.33 sec |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -163,14 +169,17 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusCodeSkipped,
Status: "skipped",
StatusReason: "This Step was skipped, because a previous Step failed, and this Step was not marked “is_always_run”.",
ShortReason: "skipped",
Title: "Step",
RunTime: 654321,
LastStep: true,
},
expectedOutput: []string{
"This Step was skipped, because a previous Step failed, and this Step was not marked “is_always_run”.",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[34;1m-\u001B[0m | \u001B[34;1mStep \u001B[0m | 10.9 min |",
"| \x1b[34;1m-\x1b[0m | \x1b[34;1mStep (skipped) \x1b[0m | 10.9 min |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -179,14 +188,21 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusCodeSkippedWithRunIf,
Status: "skipped_with_run_if",
Title: "Step",
RunTime: 42424242,
LastStep: true,
StatusReason: `
This Step was skipped, because its “run_if” expression evaluated to false.

The “run_if” expression was: false
`,
ShortReason: "skipped due to run_if",
Title: "Step",
RunTime: 42424242,
LastStep: true,
},
expectedOutput: []string{
"\nThis Step was skipped, because its “run_if” expression evaluated to false.\n\nThe “run_if” expression was: false\n",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[34;1m-\u001B[0m | \u001B[34;1mStep \u001B[0m | 12 hour |",
"| \x1b[34;1m-\x1b[0m | \x1b[34;1mStep (skipped due to run_if) \x1b[0m | 12 hour |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -196,14 +212,16 @@ func TestStepFooterPrinting(t *testing.T) {
InternalStatus: models.StepRunStatusCodePreparationFailed,
Status: "preparation_failed",
StatusReason: "exit code: 3",
ShortReason: "exit code: 3",
Title: "Step",
RunTime: 11111,
LastStep: true,
},
expectedOutput: []string{
"exit code: 3",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1mx\u001B[0m | \u001B[31;1mStep (exit code: 3) \u001B[0m | 11.11 sec |",
"| \x1b[31;1mx\x1b[0m | \x1b[31;1mStep (exit code: 3) \x1b[0m | 11.11 sec |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -212,15 +230,17 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusAbortedWithCustomTimeout,
Status: "aborted_with_custom_timeout",
StatusReason: "timed out",
StatusReason: "This Step timed out after 5m.",
ShortReason: "timed out",
Title: "Step",
RunTime: 99099,
LastStep: true,
},
expectedOutput: []string{
"This Step timed out after 5m.",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1m/\u001B[0m | \u001B[31;1mStep (timed out) \u001B[0m | 1.7 min |",
"| \x1b[31;1m/\x1b[0m | \x1b[31;1mStep (timed out) \x1b[0m | 1.7 min |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -229,15 +249,17 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusAbortedWithNoOutputTimeout,
Status: "aborted_with_no_output",
StatusReason: "timed out due to no output",
StatusReason: "This Step failed, because it has not sent any output for 4m.",
ShortReason: "timed out due to no output",
Title: "Step",
RunTime: 101,
LastStep: true,
},
expectedOutput: []string{
"This Step failed, because it has not sent any output for 4m.",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1m/\u001B[0m | \u001B[31;1mStep (timed out due to no output) \u001B[0m | 0.10 sec |",
"| \x1b[31;1m/\x1b[0m | \x1b[31;1mStep (timed out due to no output) \x1b[0m | 0.10 sec |",
"+---+---------------------------------------------------------------+----------+",
},
},
Expand All @@ -247,6 +269,7 @@ func TestStepFooterPrinting(t *testing.T) {
InternalStatus: models.StepRunStatusCodeFailed,
Status: "failed",
StatusReason: "exit code: 11",
ShortReason: "exit code: 11",
Title: "Failed step",
RunTime: 88888,
SupportURL: "https://issue-url-issue-url-issue-url-issue-url-issue-url-issue-url-issue-url-issue-url",
Expand All @@ -257,9 +280,10 @@ func TestStepFooterPrinting(t *testing.T) {
LastStep: true,
},
expectedOutput: []string{
"exit code: 11",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1mx\u001B[0m | \u001B[31;1mFailed step (exit code: 11) \u001B[0m | 1.5 min |",
"| \x1b[31;1mx\x1b[0m | \x1b[31;1mFailed step (exit code: 11) \x1b[0m | 1.5 min |",
"+---+---------------------------------------------------------------+----------+",
"| Issue tracker: https://issue-url-issue-url-issue-url-issue-url-issue-url-... |",
"| Source: https://source-code-url |",
Expand All @@ -271,6 +295,8 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusCodeSuccess,
Status: "success",
StatusReason: "",
ShortReason: "",
Title: "Step",
RunTime: 65748,
Update: &StepUpdate{
Expand Down Expand Up @@ -298,6 +324,7 @@ func TestStepFooterPrinting(t *testing.T) {
InternalStatus: models.StepRunStatusCodeFailed,
Status: "failed",
StatusReason: "exit code: 42",
ShortReason: "exit code: 42",
Title: "Loooooooooong step naaaaaaaaaaaaaaaaaaaaaaaaaaaaaaame",
RunTime: 223,
Deprecation: &StepDeprecation{
Expand All @@ -307,12 +334,13 @@ func TestStepFooterPrinting(t *testing.T) {
LastStep: true,
},
expectedOutput: []string{
"exit code: 42",
"| |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1mx\u001B[0m | \u001B[31;1m[Deprecated]\u001B[0m \u001B[31;1mLoooooooooong step naaaaaaaaa... (exit code: 42)\u001B[0m | 0.22 sec |",
"| \x1b[31;1mx\x1b[0m | \x1b[31;1m[Deprecated]\x1b[0m \x1b[31;1mLoooooooooong step naaaaaaaaa... (exit code: 42)\x1b[0m | 0.22 sec |",
"+---+---------------------------------------------------------------+----------+",
"| \u001B[31;1mRemoval date:\u001B[0m 2022-10-26 |",
"| \u001B[31;1mRemoval notes:\u001B[0m Lorem ipsum dolor sit amet, consectetur adipiscing elit. In |",
"| \x1b[31;1mRemoval date:\x1b[0m 2022-10-26 |",
"| \x1b[31;1mRemoval notes:\x1b[0m Lorem ipsum dolor sit amet, consectetur adipiscing elit. In |",
"| at ipsum nec orci convallis efficitur. Nulla ultrices eros non nisi tempus |",
"| feugiat. Donec ac sapien in odio ultrices ullamcorper vel id erat. Interdum |",
"| et malesuada fames ac ante ipsum primis in faucibus. Sed sed placerat |",
Expand All @@ -325,6 +353,8 @@ func TestStepFooterPrinting(t *testing.T) {
params: StepFinishedParams{
InternalStatus: models.StepRunStatusCodeSuccess,
Status: "success",
StatusReason: "",
ShortReason: "",
Title: "Regular step",
RunTime: 111111111111,
Errors: []StepError{
Expand Down
1 change: 1 addition & 0 deletions log/models.go
Expand Up @@ -39,6 +39,7 @@ type StepFinishedParams struct {
InternalStatus int `json:"-"`
Status string `json:"status"`
StatusReason string `json:"status_reason,omitempty"`
ShortReason string `json:"status_reason_short,omitempty"`
godrei marked this conversation as resolved.
Show resolved Hide resolved
Title string `json:"title"`
RunTime int64 `json:"run_time_in_ms"`
SupportURL string `json:"support_url"`
Expand Down