From 92bff8c14aac9b9e0cdba4c463bace3d9188521f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Kriszti=C3=A1n=20G=C3=B6drei?= Date: Wed, 12 Oct 2022 11:47:56 +0200 Subject: [PATCH] Structured logging (#818) * Update dependency * Use new logger * Add temp version number * Update go-utils/advancedlog * Update go-utils/advancedlog * Code cleanup * Migrate remaining go-utils/log usages to advancedlog * Migrate remaining fmt usages to advancedlog * Code cleanup * Update version.go * Test json and console log compatibility * Update log_format_test_bitrise.yml * Update dependency * Use new logger * Update go-utils/advancedlog * Update go-utils/advancedlog * Code cleanup * Migrate remaining fmt usages to advancedlog * Code cleanup * Rebase fixes * Pull latest go-utils/v2 * Fix rebase * Fix rebase * Fix rebase * Move advancedlog package to bitrise * Rename advancedlog package to log * Update paths.go * Hangdetector log with timestamp * Add producer id to step logs * Code cleanup * Console logger tests * PR fixes * Constructor for utilsLogAdapter * Introduce new LoggerOpts * Update run_test.go * Remove configs.LoggerType * PR fixes Co-authored-by: Szabolcs Toth --- _tests/integration/log_format_test.go | 115 ++++++++++++ .../integration/log_format_test_bitrise.yml | 36 ++++ analytics/legacy.go | 69 +++++++ analytics/logger.go | 47 +++++ analytics/tracker.go | 12 +- bitrise.yml | 16 +- bitrise/dependencies.go | 10 +- bitrise/print.go | 64 +++---- bitrise/setup.go | 12 +- bitrise/updates.go | 2 +- bitrise/util.go | 9 +- cli/build_run_result_collector.go | 4 +- cli/cli.go | 137 ++++++++------ cli/export.go | 19 +- cli/flags.go | 10 - cli/help.go | 8 +- cli/init.go | 13 +- cli/json_output.go | 58 ++++++ cli/normalize.go | 12 +- cli/plugin.go | 2 +- cli/plugin_delete.go | 2 +- cli/plugin_info.go | 8 +- cli/plugin_install.go | 8 +- cli/plugin_list.go | 8 +- cli/plugin_update.go | 8 +- cli/run.go | 75 ++++---- cli/run_config.go | 2 +- cli/run_test.go | 37 ++-- cli/run_util.go | 27 ++- cli/setup.go | 13 +- cli/share.go | 4 +- cli/share_audit.go | 4 +- cli/share_create.go | 7 +- cli/share_finish.go | 4 +- cli/share_start.go | 5 +- cli/step_activator.go | 4 +- cli/step_info.go | 46 ++--- cli/step_list.go | 7 +- cli/tools.go | 5 +- cli/trigger.go | 24 +-- cli/trigger_check.go | 12 +- cli/update.go | 10 +- cli/validate.go | 11 +- cli/version.go | 9 +- cli/workflow_list.go | 8 +- configs/paths.go | 2 +- go.mod | 3 +- go.sum | 8 +- log/corelog/console_logger.go | 76 ++++++++ log/corelog/console_logger_test.go | 107 +++++++++++ log/corelog/json_logger.go | 64 +++++++ log/corelog/json_logger_test.go | 137 ++++++++++++++ log/corelog/logger.go | 62 +++++++ log/corelog/logger_test.go | 27 +++ log/log.go | 171 ++++++++++++++++++ log/log_functions.go | 99 ++++++++++ log/logger.go | 22 +++ log/logger_test.go | 43 +++++ log/logwriter/color_converter.go | 70 +++++++ log/logwriter/color_converter_test.go | 87 +++++++++ log/logwriter/writer.go | 23 +++ log/logwriter/writer_test.go | 85 +++++++++ output/output.go | 6 +- plugins/install.go | 2 +- plugins/paths.go | 3 +- plugins/run.go | 33 +++- toolkits/command_runner.go | 2 +- toolkits/golang.go | 6 +- tools/filterwriter/filterwriter.go | 2 +- tools/hangdetector/hang_detector.go | 8 +- tools/timeoutcmd/timeoutcmd.go | 2 +- tools/tools.go | 51 +++--- .../go-utils/v2/analytics/client.go | 4 +- .../v2/log/colorstring/colorstring.go | 111 ++++++++++++ .../bitrise-io/go-utils/v2/log/severity.go | 2 +- .../go-utils/v2/retryhttp/retryhttp.go | 25 +++ .../hashicorp/go-retryablehttp/README.md | 19 ++ .../hashicorp/go-retryablehttp/client.go | 85 ++++++--- vendor/modules.txt | 7 +- 79 files changed, 2029 insertions(+), 428 deletions(-) create mode 100644 _tests/integration/log_format_test.go create mode 100644 _tests/integration/log_format_test_bitrise.yml create mode 100644 analytics/legacy.go create mode 100644 analytics/logger.go create mode 100644 cli/json_output.go create mode 100644 log/corelog/console_logger.go create mode 100644 log/corelog/console_logger_test.go create mode 100644 log/corelog/json_logger.go create mode 100644 log/corelog/json_logger_test.go create mode 100644 log/corelog/logger.go create mode 100644 log/corelog/logger_test.go create mode 100644 log/log.go create mode 100644 log/log_functions.go create mode 100644 log/logger.go create mode 100644 log/logger_test.go create mode 100644 log/logwriter/color_converter.go create mode 100644 log/logwriter/color_converter_test.go create mode 100644 log/logwriter/writer.go create mode 100644 log/logwriter/writer_test.go create mode 100644 vendor/github.com/bitrise-io/go-utils/v2/log/colorstring/colorstring.go create mode 100644 vendor/github.com/bitrise-io/go-utils/v2/retryhttp/retryhttp.go diff --git a/_tests/integration/log_format_test.go b/_tests/integration/log_format_test.go new file mode 100644 index 000000000..4feb370a9 --- /dev/null +++ b/_tests/integration/log_format_test.go @@ -0,0 +1,115 @@ +package integration + +import ( + "bytes" + "encoding/json" + "os/exec" + "regexp" + "testing" + + "github.com/stretchr/testify/require" +) + +func TestConsoleLogCanBeRestoredFromJSONLog(t *testing.T) { + consoleLog := createConsoleLog(t) + jsonLog := createJSONleLog(t) + convertedConsoleLog := restoreConsoleLog(t, jsonLog) + require.Equal(t, replaceVariableParts(consoleLog), replaceVariableParts(convertedConsoleLog)) +} + +func createConsoleLog(t *testing.T) string { + execCmd := exec.Command(binPath(), "setup") + outBytes, err := execCmd.CombinedOutput() + require.NoError(t, err, string(outBytes)) + + cmd := exec.Command(binPath(), "run", "fail_test", "--config", "log_format_test_bitrise.yml") + out, err := cmd.CombinedOutput() + require.EqualError(t, err, "exit status 1") + return string(out) +} + +func createJSONleLog(t *testing.T) []byte { + execCmd := exec.Command(binPath(), "setup") + outBytes, err := execCmd.CombinedOutput() + require.NoError(t, err, string(outBytes)) + + cmd := exec.Command(binPath(), "run", "fail_test", "--config", "log_format_test_bitrise.yml", "--output-format", "json") + out, err := cmd.CombinedOutput() + require.EqualError(t, err, "exit status 1") + return out +} + +func restoreConsoleLog(t *testing.T, log []byte) string { + type Log struct { + Message string `json:"message"` + Level string `json:"level"` + } + + var consoleLog string + lines := bytes.Split(log, []byte("\n")) + for _, line := range lines { + if string(line) == "" { + continue + } + var log Log + err := json.Unmarshal(line, &log) + require.NoError(t, err, string(line)) + consoleLog += createLogMsg(log.Level, log.Message) + } + return consoleLog +} + +var levelToANSIColorCode = map[level]ansiColorCode{ + errorLevel: redCode, + warnLevel: yellowCode, + infoLevel: blueCode, + doneLevel: greenCode, + debugLevel: magentaCode, +} + +func createLogMsg(lvl string, message string) string { + color := levelToANSIColorCode[level(lvl)] + if color != "" { + return addColor(color, message) + } + return message +} + +func addColor(color ansiColorCode, msg string) string { + return string(color) + msg + string(resetCode) +} + +type level string + +const ( + errorLevel level = "error" + warnLevel level = "warn" + infoLevel level = "info" + doneLevel level = "done" + normalLevel level = "normal" + debugLevel level = "debug" +) + +type ansiColorCode string + +const ( + redCode ansiColorCode = "\x1b[31;1m" + yellowCode ansiColorCode = "\x1b[33;1m" + blueCode ansiColorCode = "\x1b[34;1m" + greenCode ansiColorCode = "\x1b[32;1m" + magentaCode ansiColorCode = "\x1b[35;1m" + resetCode ansiColorCode = "\x1b[0m" +) + +func replaceVariableParts(line string) string { + timeRegexp := regexp.MustCompile(`(\| time: .+\|)`) + line = timeRegexp.ReplaceAllString(line, "[REPLACED]") + + runTimeRegexp := regexp.MustCompile(`(\| .+ sec \|)`) + line = runTimeRegexp.ReplaceAllString(line, "[REPLACED]") + + totalRunTimeRegexp := regexp.MustCompile(`(\| Total runtime: .+ \|)`) + line = totalRunTimeRegexp.ReplaceAllString(line, "[REPLACED]") + + return line +} diff --git a/_tests/integration/log_format_test_bitrise.yml b/_tests/integration/log_format_test_bitrise.yml new file mode 100644 index 000000000..ec8fd0809 --- /dev/null +++ b/_tests/integration/log_format_test_bitrise.yml @@ -0,0 +1,36 @@ +format_version: "11" +default_step_lib_source: https://github.com/bitrise-io/bitrise-steplib.git +project_type: other + +workflows: + fail_test: + title: Fails + description: Workflow will fail + steps: + - script: + title: Success + inputs: + - content: |- + set -ex + exit 0 + - script@1.1: + title: Fail wit exit code 2 + inputs: + - content: |- + set -ex + exit 2 + - git::https://github.com/bitrise-steplib/steps-script.git@master: + title: Skippable fail with exit code 2 + is_always_run: true + is_skippable: true + inputs: + - content: |- + set -ex + exit 2 + - script: + title: Skipping success + is_always_run: false + inputs: + - content: |- + set -ex + exit 0 diff --git a/analytics/legacy.go b/analytics/legacy.go new file mode 100644 index 000000000..920fa6507 --- /dev/null +++ b/analytics/legacy.go @@ -0,0 +1,69 @@ +package analytics + +import ( + "bytes" + "context" + "encoding/json" + "fmt" + "net/http" + "time" + + "github.com/bitrise-io/bitrise/log" +) + +var ( + analyticsServerURL = "https://bitrise-step-analytics.herokuapp.com" + httpClient = http.Client{ + Timeout: time.Second * 5, + } +) + +// LogMessage sends the log message to the configured analytics server +func LogMessage(logLevel string, stepID string, tag string, data map[string]interface{}, format string, v ...interface{}) { + // Entry represents a line in a log + e := struct { + LogLevel string `json:"log_level"` + Message string `json:"message"` + Data map[string]interface{} `json:"data"` + }{ + Message: fmt.Sprintf(format, v...), + LogLevel: logLevel, + } + + e.Data = make(map[string]interface{}) + for k, v := range data { + e.Data[k] = v + } + + if v, ok := e.Data["step_id"]; ok { + log.Printf("internal logger: data.step_id (%s) will be overriden with (%s) ", v, stepID) + } + if v, ok := e.Data["tag"]; ok { + log.Printf("internal logger: data.tag (%s) will be overriden with (%s) ", v, tag) + } + + e.Data["step_id"] = stepID + e.Data["tag"] = tag + + var b bytes.Buffer + if err := json.NewEncoder(&b).Encode(e); err != nil { + return + } + + ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second) + defer cancel() + + req, err := http.NewRequest(http.MethodPost, analyticsServerURL+"/logs", &b) + if err != nil { + // deliberately not writing into users log + return + } + req = req.WithContext(ctx) + req.Header.Add("Content-Type", "application/json") + + if _, err := httpClient.Do(req); err != nil { + // deliberately not writing into users log + return + } + +} diff --git a/analytics/logger.go b/analytics/logger.go new file mode 100644 index 000000000..6b75ea466 --- /dev/null +++ b/analytics/logger.go @@ -0,0 +1,47 @@ +package analytics + +import ( + "github.com/bitrise-io/bitrise/log" +) + +// utilsLogAdapter extends the bitrise/log.Logger to meet the go-utils/v2/log.Logger interface. +type utilsLogAdapter struct { + debug bool + log.Logger +} + +func newUtilsLogAdapter() utilsLogAdapter { + opts := log.GetGlobalLoggerOpts() + return utilsLogAdapter{ + Logger: log.NewLogger(opts), + debug: opts.DebugLogEnabled, + } +} + +func (l *utilsLogAdapter) TInfof(format string, v ...interface{}) { + log.Infof(format, v...) +} +func (l *utilsLogAdapter) TWarnf(format string, v ...interface{}) { + log.Warnf(format, v...) +} +func (l *utilsLogAdapter) TPrintf(format string, v ...interface{}) { + log.Printf(format, v...) +} +func (l *utilsLogAdapter) TDonef(format string, v ...interface{}) { + log.Donef(format, v...) +} +func (l *utilsLogAdapter) TDebugf(format string, v ...interface{}) { + if !l.debug { + return + } + log.Debugf(format, v...) +} +func (l *utilsLogAdapter) TErrorf(format string, v ...interface{}) { + log.Errorf(format, v...) +} +func (l *utilsLogAdapter) Println() { + log.Print() +} +func (l *utilsLogAdapter) EnableDebugLog(enable bool) { + l.debug = enable +} diff --git a/analytics/tracker.go b/analytics/tracker.go index a840ea08b..b87ccbc9d 100644 --- a/analytics/tracker.go +++ b/analytics/tracker.go @@ -6,14 +6,11 @@ import ( "os" "time" - "github.com/sirupsen/logrus" - "github.com/bitrise-io/bitrise/configs" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/version" "github.com/bitrise-io/go-utils/v2/analytics" "github.com/bitrise-io/go-utils/v2/env" - "github.com/bitrise-io/go-utils/v2/log" ) const ( @@ -122,13 +119,10 @@ func NewDefaultTracker() Tracker { envRepository := env.NewRepository() stateChecker := NewStateChecker(envRepository) - // Adapter between logrus and go-utils log package - logger := log.NewLogger() - logger.EnableDebugLog(logrus.GetLevel() == logrus.DebugLevel) - - tracker := analytics.NewDefaultSyncTracker(logger) + logger := newUtilsLogAdapter() + tracker := analytics.NewDefaultSyncTracker(&logger) if stateChecker.UseAsync() { - tracker = analytics.NewDefaultTracker(logger) + tracker = analytics.NewDefaultTracker(&logger) } return NewTracker(tracker, envRepository, stateChecker) diff --git a/bitrise.yml b/bitrise.yml index bca96914c..e8163f261 100644 --- a/bitrise.yml +++ b/bitrise.yml @@ -89,19 +89,27 @@ workflows: - script: title: Success inputs: - - content: exit 0 + - content: |- + set -ex + exit 0 - script: title: Fail wit exit code 2 inputs: - - content: exit 2 + - content: |- + set -ex + exit 2 - script: title: Skippable fail with exit code 2 is_always_run: true is_skippable: true inputs: - - content: exit 2 + - content: |- + set -ex + exit 2 - script: title: Skipping success is_always_run: false inputs: - - content: exit 0 + - content: |- + set -ex + exit 0 diff --git a/bitrise/dependencies.go b/bitrise/dependencies.go index 0b20da154..a34972704 100644 --- a/bitrise/dependencies.go +++ b/bitrise/dependencies.go @@ -7,12 +7,12 @@ import ( "strings" "time" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" "github.com/bitrise-io/bitrise/tools" "github.com/bitrise-io/bitrise/utils" "github.com/bitrise-io/go-utils/colorstring" "github.com/bitrise-io/go-utils/command" - "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/progress" "github.com/bitrise-io/go-utils/retry" "github.com/bitrise-io/go-utils/versions" @@ -88,7 +88,7 @@ func CheckIsPluginInstalled(name string, dependency PluginDependency) error { } if len(plugin.Description) > 0 { - fmt.Println(removeEmptyNewLines(plugin.Description)) + log.Print(removeEmptyNewLines(plugin.Description)) } } @@ -106,12 +106,12 @@ func CheckIsHomebrewInstalled(isFullSetupMode bool) error { progInstallPth, err := utils.CheckProgramInstalledPath("brew") if err != nil { - fmt.Println() + log.Print() log.Warnf("It seems that Homebrew is not installed on your system.") log.Infof("Homebrew (short: brew) is required in order to be able to auto-install all the bitrise dependencies.") log.Infof("You should be able to install brew by copying this command and running it in your Terminal:") log.Infof(brewRubyInstallCmdString) - log.Infof("You can find more information about Homebrew on its official site at:", officialSiteURL) + log.Infof("You can find more information about Homebrew on its official site at: %s", officialSiteURL) log.Warnf("Once the installation of brew is finished you should call the bitrise setup again.") return err } @@ -129,7 +129,7 @@ func CheckIsHomebrewInstalled(isFullSetupMode bool) error { doctorOutput, err = command.RunCommandAndReturnCombinedStdoutAndStderr("brew", "doctor") }) if err != nil { - fmt.Println("") + log.Print() log.Warnf("brew doctor returned an error:") log.Warnf("%s", doctorOutput) return errors.New("command failed: brew doctor") diff --git a/bitrise/print.go b/bitrise/print.go index be46147e4..2819ce86d 100644 --- a/bitrise/print.go +++ b/bitrise/print.go @@ -6,10 +6,10 @@ import ( "time" "unicode/utf8" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/toolkits" "github.com/bitrise-io/go-utils/colorstring" - "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/stringutil" stepmanModels "github.com/bitrise-io/stepman/models" ) @@ -541,12 +541,12 @@ func getRunningStepFooterSubSection(stepRunResult models.StepRunResultsModel) st func PrintRunningStepHeader(stepInfo stepmanModels.StepInfoModel, step stepmanModels.StepModel, idx int) { sep := fmt.Sprintf("+%s+", strings.Repeat("-", stepRunSummaryBoxWidthInChars-2)) - fmt.Println(sep) - fmt.Println(getRunningStepHeaderMainSection(stepInfo, idx)) - fmt.Println(sep) - fmt.Println(getRunningStepHeaderSubSection(step, stepInfo)) - fmt.Println(sep) - fmt.Println("|" + strings.Repeat(" ", stepRunSummaryBoxWidthInChars-2) + "|") + log.Print(sep) + log.Print(getRunningStepHeaderMainSection(stepInfo, idx)) + log.Print(sep) + log.Print(getRunningStepHeaderSubSection(step, stepInfo)) + log.Print(sep) + log.Print("|" + strings.Repeat(" ", stepRunSummaryBoxWidthInChars-2) + "|") } // PrintRunningStepFooter .. @@ -556,31 +556,31 @@ func PrintRunningStepFooter(stepRunResult models.StepRunResultsModel, isLastStep titleBoxWidth := stepRunSummaryBoxWidthInChars - 4 - iconBoxWidth - timeBoxWidth sep := fmt.Sprintf("+%s+%s+%s+", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) - fmt.Println("|" + strings.Repeat(" ", stepRunSummaryBoxWidthInChars-2) + "|") + log.Print("|" + strings.Repeat(" ", stepRunSummaryBoxWidthInChars-2) + "|") - fmt.Println(sep) - fmt.Println(getRunningStepFooterMainSection(stepRunResult)) - fmt.Println(sep) + log.Print(sep) + log.Print(getRunningStepFooterMainSection(stepRunResult)) + log.Print(sep) if stepRunResult.ErrorStr != "" || stepRunResult.StepInfo.GroupInfo.RemovalDate != "" || isUpdateAvailable(stepRunResult.StepInfo) { footerSubSection := getRunningStepFooterSubSection(stepRunResult) if footerSubSection != "" { - fmt.Println(footerSubSection) - fmt.Println(sep) + log.Print(footerSubSection) + log.Print(sep) } } if !isLastStepInWorkflow { - fmt.Println() - fmt.Println(strings.Repeat(" ", 42) + "▼") - fmt.Println() + log.Print() + log.Print(strings.Repeat(" ", 42) + "▼") + log.Print() } } // PrintRunningWorkflow ... func PrintRunningWorkflow(title string) { - fmt.Println() + log.Print() log.Printf("%s %s", colorstring.Blue("Switching to workflow:"), title) - fmt.Println() + log.Print() } // PrintSummary ... @@ -589,28 +589,28 @@ func PrintSummary(buildRunResults models.BuildRunResultsModel) { timeBoxWidth := len(" time (s) ") titleBoxWidth := stepRunSummaryBoxWidthInChars - 4 - iconBoxWidth - timeBoxWidth - fmt.Println() - fmt.Println() - fmt.Printf("+%s+\n", strings.Repeat("-", stepRunSummaryBoxWidthInChars-2)) + log.Print() + log.Print() + log.Printf("+%s+", strings.Repeat("-", stepRunSummaryBoxWidthInChars-2)) whitespaceWidth := (stepRunSummaryBoxWidthInChars - 2 - len("bitrise summary ")) / 2 - fmt.Printf("|%sbitrise summary %s|\n", strings.Repeat(" ", whitespaceWidth), strings.Repeat(" ", whitespaceWidth)) - fmt.Printf("+%s+%s+%s+\n", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) + log.Printf("|%sbitrise summary %s|", strings.Repeat(" ", whitespaceWidth), strings.Repeat(" ", whitespaceWidth)) + log.Printf("+%s+%s+%s+", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) whitespaceWidth = stepRunSummaryBoxWidthInChars - len("| | title") - len("| time (s) |") - fmt.Printf("| | title%s| time (s) |\n", strings.Repeat(" ", whitespaceWidth)) - fmt.Printf("+%s+%s+%s+\n", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) + log.Printf("| | title%s| time (s) |", strings.Repeat(" ", whitespaceWidth)) + log.Printf("+%s+%s+%s+", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) orderedResults := buildRunResults.OrderedResults() tmpTime := time.Time{} for _, stepRunResult := range orderedResults { tmpTime = tmpTime.Add(stepRunResult.RunTime) - fmt.Println(getRunningStepFooterMainSection(stepRunResult)) - fmt.Printf("+%s+%s+%s+\n", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) + log.Print(getRunningStepFooterMainSection(stepRunResult)) + log.Printf("+%s+%s+%s+", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) if stepRunResult.ErrorStr != "" || stepRunResult.StepInfo.GroupInfo.RemovalDate != "" || isUpdateAvailable(stepRunResult.StepInfo) { footerSubSection := getRunningStepFooterSubSection(stepRunResult) if footerSubSection != "" { - fmt.Println(footerSubSection) - fmt.Printf("+%s+%s+%s+\n", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) + log.Print(footerSubSection) + log.Printf("+%s+%s+%s+", strings.Repeat("-", iconBoxWidth), strings.Repeat("-", titleBoxWidth), strings.Repeat("-", timeBoxWidth)) } } } @@ -628,8 +628,8 @@ func PrintSummary(buildRunResults models.BuildRunResultsModel) { whitespaceWidth = 0 } - fmt.Printf("| Total runtime: %s%s|\n", runTimeStr, strings.Repeat(" ", whitespaceWidth)) - fmt.Printf("+%s+\n", strings.Repeat("-", stepRunSummaryBoxWidthInChars-2)) + log.Printf("| Total runtime: %s%s|", runTimeStr, strings.Repeat(" ", whitespaceWidth)) + log.Printf("+%s+", strings.Repeat("-", stepRunSummaryBoxWidthInChars-2)) - fmt.Println() + log.Print() } diff --git a/bitrise/setup.go b/bitrise/setup.go index e56e2b2ae..66cdca77c 100644 --- a/bitrise/setup.go +++ b/bitrise/setup.go @@ -6,11 +6,11 @@ import ( "runtime" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" "github.com/bitrise-io/bitrise/toolkits" "github.com/bitrise-io/bitrise/version" "github.com/bitrise-io/go-utils/colorstring" - "github.com/bitrise-io/go-utils/log" ) const ( @@ -96,7 +96,7 @@ func RunSetup(appVersion string, isFullSetupMode bool, isCleanSetupMode bool) er return fmt.Errorf("Failed to do Toolkits setup, error: %s", err) } - fmt.Println() + log.Print() log.Donef("All the required tools are installed! We're ready to rock!!") if err := configs.SaveSetupSuccessForVersion(appVersion); err != nil { @@ -107,7 +107,7 @@ func RunSetup(appVersion string, isFullSetupMode bool, isCleanSetupMode bool) er } func doSetupToolkits() error { - fmt.Println() + log.Print() log.Infof("Checking Bitrise Toolkits...") coreToolkits := toolkits.AllSupportedToolkits() @@ -141,7 +141,7 @@ func doSetupToolkits() error { } func doSetupPlugins() error { - fmt.Println() + log.Print() log.Infof("Checking Bitrise Plugins...") for pluginName, pluginDependency := range PluginDependencyMap { @@ -154,7 +154,7 @@ func doSetupPlugins() error { } func doSetupBitriseCoreTools() error { - fmt.Println() + log.Print() log.Infof("Checking Bitrise Core tools...") if err := CheckIsEnvmanInstalled(minEnvmanVersion); err != nil { @@ -169,7 +169,7 @@ func doSetupBitriseCoreTools() error { } func doSetupOnOSX(isMinimalSetupMode bool) error { - fmt.Println() + log.Print() log.Infof("Doing OS X specific setup") log.Printf("Checking required tools...") diff --git a/bitrise/updates.go b/bitrise/updates.go index ad07ce929..3ab5f5b4c 100644 --- a/bitrise/updates.go +++ b/bitrise/updates.go @@ -4,7 +4,7 @@ import ( "regexp" "strings" - "github.com/bitrise-io/go-utils/log" + "github.com/bitrise-io/bitrise/log" stepmanModels "github.com/bitrise-io/stepman/models" ver "github.com/hashicorp/go-version" ) diff --git a/bitrise/util.go b/bitrise/util.go index 0ebd34e1d..6efb919ca 100644 --- a/bitrise/util.go +++ b/bitrise/util.go @@ -9,9 +9,8 @@ import ( "strings" "time" - "gopkg.in/yaml.v2" - "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/tools" envmanModels "github.com/bitrise-io/envman/models" @@ -21,7 +20,7 @@ import ( "github.com/bitrise-io/go-utils/pathutil" "github.com/bitrise-io/go-utils/pointers" stepmanModels "github.com/bitrise-io/stepman/models" - log "github.com/sirupsen/logrus" + "gopkg.in/yaml.v2" ) // InventoryModelFromYAMLBytes ... @@ -316,11 +315,11 @@ func ReadBitriseConfig(pth string) (models.BitriseDataModel, []string, error) { } if strings.HasSuffix(pth, ".json") { - log.Debugln("=> Using JSON parser for: ", pth) + log.Debug("=> Using JSON parser for: ", pth) return ConfigModelFromJSONBytes(bytes) } - log.Debugln("=> Using YAML parser for: ", pth) + log.Debug("=> Using YAML parser for: ", pth) return ConfigModelFromYAMLBytes(bytes) } diff --git a/cli/build_run_result_collector.go b/cli/build_run_result_collector.go index e4e04dd5d..52d1dfe40 100644 --- a/cli/build_run_result_collector.go +++ b/cli/build_run_result_collector.go @@ -2,19 +2,19 @@ package cli import ( "errors" - "github.com/bitrise-io/go-utils/errorutil" "time" "github.com/bitrise-io/bitrise/analytics" "github.com/bitrise-io/bitrise/bitrise" "github.com/bitrise-io/bitrise/exitcode" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/tools/timeoutcmd" "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" stepmanModels "github.com/bitrise-io/stepman/models" - log "github.com/sirupsen/logrus" ) type buildRunResultCollector struct { diff --git a/cli/cli.go b/cli/cli.go index 0f699dfe6..fd303f4b0 100644 --- a/cli/cli.go +++ b/cli/cli.go @@ -5,21 +5,21 @@ import ( "fmt" "os" "path" + "strconv" + "strings" + "time" "github.com/bitrise-io/bitrise/bitrise" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" "github.com/bitrise-io/bitrise/version" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) -func initLogFormatter() { - log.SetFormatter(&log.TextFormatter{ - FullTimestamp: true, - ForceColors: true, - TimestampFormat: "15:04:05", - }) +func failf(format string, args ...interface{}) { + log.Errorf(format, args...) + os.Exit(1) } func before(c *cli.Context) error { @@ -28,54 +28,20 @@ func before(c *cli.Context) error { use log.Fatal to avoid print help. */ - initLogFormatter() initHelpAndVersionFlags() - // Debug mode? - if c.Bool(DebugModeKey) { - // set for other tools, as an ENV - if err := os.Setenv(configs.DebugModeEnvKey, "true"); err != nil { - log.Fatalf("Failed to set DEBUG env, error: %s", err) - } - configs.IsDebugMode = true - log.Warn("=> Started in DEBUG mode") - } - - // Log level - // If log level defined - use it - logLevelStr := c.String(LogLevelKey) - if logLevelStr == "" && configs.IsDebugMode { - // if no Log Level defined and we're in Debug Mode - set loglevel to debug - logLevelStr = "debug" - log.Warn("=> LogLevel set to debug") - } - if logLevelStr == "" { - // if still empty: set the default - logLevelStr = "info" - } - - level, err := log.ParseLevel(logLevelStr) - if err != nil { - log.Fatalf("Failed parse log level, error: %s", err) - } - - if err := os.Setenv(configs.LogLevelEnvKey, level.String()); err != nil { - log.Fatalf("Failed to set LOGLEVEL env, error: %s", err) - } - log.SetLevel(level) - // CI Mode check if c.Bool(CIKey) { // if CI mode indicated make sure we set the related env // so all other tools we use will also get it if err := os.Setenv(configs.CIModeEnvKey, "true"); err != nil { - log.Fatalf("Failed to set CI env, error: %s", err) + failf("Failed to set CI env, error: %s", err) } configs.IsCIMode = true } if err := configs.InitPaths(); err != nil { - log.Fatalf("Failed to initialize required paths, error: %s", err) + failf("Failed to initialize required paths, error: %s", err) } // Pull Request Mode check @@ -83,7 +49,7 @@ func before(c *cli.Context) error { // if PR mode indicated make sure we set the related env // so all other tools we use will also get it if err := os.Setenv(configs.PRModeEnvKey, "true"); err != nil { - log.Fatalf("Failed to set PR env, error: %s", err) + failf("Failed to set PR env, error: %s", err) } configs.IsPullRequestMode = true } @@ -102,19 +68,88 @@ func before(c *cli.Context) error { } func printVersion(c *cli.Context) { - fmt.Println(c.App.Version) + log.Print(c.App.Version) +} + +func loggerParameters(arguments []string) (bool, string, bool) { + isRunCommand := false + outputFormat := "" + isDebug := false + + for i, argument := range arguments { + if argument == "run" { + isRunCommand = true + } + + if argument == "--"+OutputFormatKey { + if i+1 <= len(arguments) { + value := arguments[i+1] + + if !strings.HasPrefix(value, "--") { + outputFormat = value + } + } + } + + if argument == "--"+DebugModeKey { + if i+1 <= len(arguments) { + value := arguments[i+1] + + if strings.HasPrefix(value, "--") { + isDebug = true + } else { + value, err := strconv.ParseBool(value) + if err == nil { + isDebug = value + } + } + } + } + } + + return isRunCommand, outputFormat, isDebug } // Run ... func Run() { - if err := plugins.InitPaths(); err != nil { - log.Fatalf("Failed to initialize plugin path, error: %s", err) + isRunCommand, format, isDebug := loggerParameters(os.Args[1:]) + if !isDebug { + isDebug = os.Getenv(configs.DebugModeEnvKey) == "true" + } + + loggerType := log.ConsoleLogger + if isRunCommand && format == "json" { + loggerType = log.JSONLogger + } + + // Global logger needs to be initialised before using any log function + opts := log.LoggerOpts{ + LoggerType: loggerType, + Producer: log.BitriseCLI, + DebugLogEnabled: isDebug, + Writer: os.Stdout, + TimeProvider: time.Now, + } + log.InitGlobalLogger(opts) + + // Debug mode? + if isDebug { + // set for other tools, as an ENV + if err := os.Setenv(configs.DebugModeEnvKey, "true"); err != nil { + failf("Failed to set DEBUG env, error: %s", err) + + } + + configs.IsDebugMode = true + log.Warn("=> Started in DEBUG mode") } - initAppHelpTemplate() + if err := plugins.InitPaths(); err != nil { + failf("Failed to initialize plugin path, error: %s", err) + } - // Parse cl cli.VersionPrinter = printVersion + cli.AppHelpTemplate = fmt.Sprintf(helpTemplate, getPluginsList()) app := cli.NewApp() app.Name = path.Base(os.Args[0]) @@ -141,7 +176,7 @@ func Run() { } if err := bitrise.RunSetupIfNeeded(version.VERSION, false); err != nil { - log.Fatalf("Setup failed, error: %s", err) + failf("Setup failed, error: %s", err) } if err := plugins.RunPluginByCommand(plugin, pluginArgs); err != nil { @@ -158,6 +193,6 @@ func Run() { } if err := app.Run(os.Args); err != nil { - log.Fatal(err) + failf(err.Error()) } } diff --git a/cli/export.go b/cli/export.go index 2814fd520..13c79c5db 100644 --- a/cli/export.go +++ b/cli/export.go @@ -3,12 +3,11 @@ package cli import ( "encoding/json" - "gopkg.in/yaml.v2" - + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/go-utils/fileutil" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" + "gopkg.in/yaml.v2" ) func export(c *cli.Context) error { @@ -29,12 +28,12 @@ func export(c *cli.Context) error { if outfilePth == "" { showSubcommandHelp(c) - log.Fatal("No output file path specified!") + failf("No output file path specified!") } if outFormat == "" { showSubcommandHelp(c) - log.Fatal("No output format format specified!") + failf("No output format format specified!") } // Config validation @@ -44,7 +43,7 @@ func export(c *cli.Context) error { } if err != nil { showSubcommandHelp(c) - log.Fatalf("Failed to create bitrise config, error: %s", err) + failf("Failed to create bitrise config, error: %s", err) } // serialize @@ -56,20 +55,20 @@ func export(c *cli.Context) error { configBytes, err = json.Marshal(bitriseConfig) } if err != nil { - log.Fatalf("Failed to generate config JSON, error: %s", err) + failf("Failed to generate config JSON, error: %s", err) } } else if outFormat == output.FormatYML { configBytes, err = yaml.Marshal(bitriseConfig) if err != nil { - log.Fatalf("Failed to generate config YML, error: %s", err) + failf("Failed to generate config YML, error: %s", err) } } else { - log.Fatalf("Invalid output format: %s", outFormat) + failf("Invalid output format: %s", outFormat) } // write to file if err := fileutil.WriteBytesToFile(outfilePth, configBytes); err != nil { - log.Fatalf("Failed to write file (%s), error: %s", outfilePth, err) + failf("Failed to write file (%s), error: %s", outfilePth, err) } log.Infof("Done, saved to path: %s", outfilePth) diff --git a/cli/flags.go b/cli/flags.go index 3df8a5808..c6d0693f6 100644 --- a/cli/flags.go +++ b/cli/flags.go @@ -15,10 +15,6 @@ const ( // DebugModeKey ... DebugModeKey = "debug" - // LogLevelKey ... - LogLevelKey = "loglevel" - logLevelKeyShort = "l" - // VersionKey ... VersionKey = "version" versionKeyShort = "v" @@ -78,11 +74,6 @@ const ( var ( // App flags - flLogLevel = cli.StringFlag{ - Name: LogLevelKey + ", " + logLevelKeyShort, - Usage: "Log level (options: debug, info, warn, error, fatal, panic).", - EnvVar: configs.LogLevelEnvKey, - } flDebugMode = cli.BoolFlag{ Name: DebugModeKey, Usage: "If true it enabled DEBUG mode. If no separate Log Level is specified this will also set the loglevel to debug.", @@ -98,7 +89,6 @@ var ( Usage: "If true bitrise runs in pull request mode.", } flags = []cli.Flag{ - flLogLevel, flDebugMode, flTool, flPRMode, diff --git a/cli/help.go b/cli/help.go index e0d1dc1fc..acb0c1562 100644 --- a/cli/help.go +++ b/cli/help.go @@ -1,13 +1,11 @@ package cli import ( - "log" "strings" "fmt" "github.com/bitrise-io/bitrise/plugins" - "github.com/urfave/cli" ) const ( @@ -39,7 +37,7 @@ func getPluginsList() string { pluginList, err := plugins.InstalledPluginList() if err != nil { - log.Fatalf("Failed to list plugins, error: %s", err) + failf("Failed to list plugins, error: %s", err) } if len(pluginList) > 0 { @@ -53,7 +51,3 @@ func getPluginsList() string { return pluginListString } - -func initAppHelpTemplate() { - cli.AppHelpTemplate = fmt.Sprintf(helpTemplate, getPluginsList()) -} diff --git a/cli/init.go b/cli/init.go index e80e1e979..da1146f92 100644 --- a/cli/init.go +++ b/cli/init.go @@ -4,10 +4,9 @@ import ( "fmt" "github.com/bitrise-io/bitrise/bitrise" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" "github.com/bitrise-io/bitrise/version" - "github.com/bitrise-io/go-utils/log" - "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -21,19 +20,19 @@ var initCmd = cli.Command{ // If the plugin is not installed yet run the bitrise setup first and try it again perr, ok := err.(plugins.NotInstalledError) if ok { - log.Warnf(perr.Error()) - log.Printf("Runing setup to install the default plugins") - fmt.Println() + log.Warn(perr) + log.Print("Running setup to install the default plugins") + log.Print() if err := bitrise.RunSetup(version.VERSION, false, false); err != nil { return fmt.Errorf("Setup failed, error: %s", err) } if err := initConfig(c); err != nil { - logrus.Fatal(err) + failf(err.Error()) } } else { - logrus.Fatal(err) + failf(err.Error()) } } return nil diff --git a/cli/json_output.go b/cli/json_output.go new file mode 100644 index 000000000..03bfa94db --- /dev/null +++ b/cli/json_output.go @@ -0,0 +1,58 @@ +package cli + +import ( + "fmt" + "io" + "os" + + "github.com/bitrise-io/bitrise/log" +) + +// Logger ... +type Logger interface { + Print(f Formatable) +} + +// Formatable ... +type Formatable interface { + String() string + JSON() string +} + +// RawLogger ... +type RawLogger struct { + writer io.Writer +} + +// NewDefaultRawLogger ... +func NewDefaultRawLogger() RawLogger { + return RawLogger{ + writer: os.Stdout, + } +} + +// Print ... +func (l RawLogger) Print(f Formatable) { + if _, err := fmt.Fprintln(l.writer, f.String()); err != nil { + log.Printf("failed to print message: %s, error: %s\n", f.String(), err) + } +} + +// JSONLoger ... +type JSONLoger struct { + writer io.Writer +} + +// NewDefaultJSONLoger ... +func NewDefaultJSONLoger() JSONLoger { + return JSONLoger{ + writer: os.Stdout, + } +} + +// Print ... +func (l JSONLoger) Print(f Formatable) { + if _, err := fmt.Fprint(l.writer, f.JSON()); err != nil { + log.Printf("failed to print message: %s, error: %s\n", f.JSON(), err) + } +} diff --git a/cli/normalize.go b/cli/normalize.go index d8a6b685a..ad3a4b722 100644 --- a/cli/normalize.go +++ b/cli/normalize.go @@ -2,7 +2,7 @@ package cli import ( "github.com/bitrise-io/bitrise/bitrise" - log "github.com/sirupsen/logrus" + "github.com/bitrise-io/bitrise/log" "github.com/urfave/cli" ) @@ -21,10 +21,10 @@ func normalize(c *cli.Context) error { // Input validation bitriseConfigPath, err := GetBitriseConfigFilePath(bitriseConfigPath) if err != nil { - log.Fatalf("Failed to get bitrise config path, error: %s", err) + failf("Failed to get bitrise config path, error: %s", err) } if bitriseConfigPath == "" { - log.Fatal("No bitrise config path defined!") + failf("No bitrise config path defined!") } // Config validation @@ -33,15 +33,15 @@ func normalize(c *cli.Context) error { log.Warnf("warning: %s", warning) } if err != nil { - log.Fatalf("Failed to create bitrise config, error: %s", err) + failf("Failed to create bitrise config, error: %s", err) } // Normalize if err := bitrise.RemoveConfigRedundantFieldsAndFillStepOutputs(&bitriseConfig); err != nil { - log.Fatalf("Failed to remove redundant fields, error: %s", err) + failf("Failed to remove redundant fields, error: %s", err) } if err := bitrise.SaveConfigToFile(bitriseConfigPath, bitriseConfig); err != nil { - log.Fatalf("Failed to save config to file, error: %s", err) + failf("Failed to save config to file, error: %s", err) } log.Info("Redundant fields removed") diff --git a/cli/plugin.go b/cli/plugin.go index d09b28316..75972d11f 100644 --- a/cli/plugin.go +++ b/cli/plugin.go @@ -1,7 +1,7 @@ package cli import ( - "github.com/bitrise-io/go-utils/log" + "github.com/bitrise-io/bitrise/log" "github.com/urfave/cli" ) diff --git a/cli/plugin_delete.go b/cli/plugin_delete.go index 93f42e244..576168dbe 100644 --- a/cli/plugin_delete.go +++ b/cli/plugin_delete.go @@ -5,8 +5,8 @@ import ( "fmt" "os" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" - "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) diff --git a/cli/plugin_info.go b/cli/plugin_info.go index 2c94559af..b01d1705c 100644 --- a/cli/plugin_info.go +++ b/cli/plugin_info.go @@ -5,9 +5,9 @@ import ( "fmt" "os" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/bitrise/plugins" - "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) @@ -86,10 +86,10 @@ func pluginInfo(c *cli.Context) error { return fmt.Errorf("invalid format: %s", format) } - var logger log.Logger - logger = log.NewDefaultRawLogger() + var logger Logger + logger = NewDefaultRawLogger() if format == output.FormatJSON { - logger = log.NewDefaultJSONLoger() + logger = NewDefaultJSONLoger() } // --- diff --git a/cli/plugin_install.go b/cli/plugin_install.go index 90431be0a..95808c4a8 100644 --- a/cli/plugin_install.go +++ b/cli/plugin_install.go @@ -4,8 +4,8 @@ import ( "fmt" "os" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" - "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) @@ -58,12 +58,12 @@ func pluginInstall(c *cli.Context) error { } if len(plugin.Description) > 0 { - fmt.Println() + log.Print() log.Infof("Description:") - fmt.Println(plugin.Description) + log.Print(plugin.Description) } - fmt.Println() + log.Print() if version == "" { log.Donef("Local plugin (%s) installed ", plugin.Name) } else { diff --git a/cli/plugin_list.go b/cli/plugin_list.go index 2450c6622..c29257bae 100644 --- a/cli/plugin_list.go +++ b/cli/plugin_list.go @@ -4,9 +4,9 @@ import ( "fmt" "os" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/bitrise/plugins" - "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) @@ -40,10 +40,10 @@ func pluginList(c *cli.Context) error { return fmt.Errorf("invalid format: %s", format) } - var logger log.Logger - logger = log.NewDefaultRawLogger() + var logger Logger + logger = NewDefaultRawLogger() if format == output.FormatJSON { - logger = log.NewDefaultJSONLoger() + logger = NewDefaultJSONLoger() } // --- diff --git a/cli/plugin_update.go b/cli/plugin_update.go index bd49e7fc4..ad2db4201 100644 --- a/cli/plugin_update.go +++ b/cli/plugin_update.go @@ -5,8 +5,8 @@ import ( "fmt" "os" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" - "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) @@ -83,12 +83,12 @@ func pluginUpdate(c *cli.Context) error { } if len(plugin.Description) > 0 { - fmt.Println() + log.Print() log.Infof("Description:") - fmt.Println(plugin.Description) + log.Print(plugin.Description) } - fmt.Println() + log.Print() log.Donef("Plugin (%s) with version (%s) installed ", plugin.Name, version) } else { log.Donef("No new version available") diff --git a/cli/run.go b/cli/run.go index 50fed6ed1..96075d117 100644 --- a/cli/run.go +++ b/cli/run.go @@ -10,13 +10,12 @@ import ( "github.com/bitrise-io/bitrise/analytics" "github.com/bitrise-io/bitrise/bitrise" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/version" envmanModels "github.com/bitrise-io/envman/models" "github.com/bitrise-io/go-utils/colorstring" - utilsLog "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/pointers" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -25,6 +24,7 @@ const ( DefaultBitriseConfigFileName = "bitrise.yml" // DefaultSecretsFileName ... DefaultSecretsFileName = ".bitrise.secrets.yml" + OutputFormatKey = "output-format" depManagerBrew = "brew" depManagerTryCheck = "_" @@ -46,6 +46,7 @@ var runCommand = cli.Command{ // cli params used in CI mode cli.StringFlag{Name: JSONParamsKey, Usage: "Specify command flags with json string-string hash."}, cli.StringFlag{Name: JSONParamsBase64Key, Usage: "Specify command flags with base64 encoded json string-string hash."}, + cli.StringFlag{Name: OutputFormatKey, Usage: "Log format. Available values: json, console"}, // deprecated flPath, @@ -57,10 +58,10 @@ var runCommand = cli.Command{ } func printAboutUtilityWorkflowsText() { - fmt.Println("Note about utility workflows:") - fmt.Println(" Utility workflow names start with '_' (example: _my_utility_workflow).") - fmt.Println(" These workflows can't be triggered directly, but can be used by other workflows") - fmt.Println(" in the before_run and after_run lists.") + log.Print("Note about utility workflows:") + log.Print(" Utility workflow names start with '_' (example: _my_utility_workflow).") + log.Print(" These workflows can't be triggered directly, but can be used by other workflows") + log.Print(" in the before_run and after_run lists.") } func printAvailableWorkflows(config models.BitriseDataModel) { @@ -78,39 +79,39 @@ func printAvailableWorkflows(config models.BitriseDataModel) { sort.Strings(utilityWorkflowNames) if len(workflowNames) > 0 { - fmt.Println("The following workflows are available:") + log.Print("The following workflows are available:") for _, wfName := range workflowNames { - fmt.Println(" * " + wfName) + log.Print(" * " + wfName) } - fmt.Println() - fmt.Println("You can run a selected workflow with:") - fmt.Println("$ bitrise run WORKFLOW-ID") - fmt.Println() + log.Print() + log.Print("You can run a selected workflow with:") + log.Print("$ bitrise run WORKFLOW-ID") + log.Print() } else { - fmt.Println("No workflows are available!") + log.Print("No workflows are available!") } if len(utilityWorkflowNames) > 0 { - fmt.Println() - fmt.Println("The following utility workflows are defined:") + log.Print() + log.Print("The following utility workflows are defined:") for _, wfName := range utilityWorkflowNames { - fmt.Println(" * " + wfName) + log.Print(" * " + wfName) } - fmt.Println() + log.Print() printAboutUtilityWorkflowsText() - fmt.Println() + log.Print() } } func runAndExit(bitriseConfig models.BitriseDataModel, inventoryEnvironments []envmanModels.EnvironmentItemModel, workflowToRunID string, tracker analytics.Tracker) { if workflowToRunID == "" { - log.Fatal("No workflow id specified") + failf("No workflow id specified") } if err := bitrise.RunSetupIfNeeded(version.VERSION, false); err != nil { - log.Fatalf("Setup failed, error: %s", err) + failf("Setup failed, error: %s", err) } startTime := time.Now() @@ -119,7 +120,7 @@ func runAndExit(bitriseConfig models.BitriseDataModel, inventoryEnvironments []e if buildRunResults, err := runWorkflowWithConfiguration(startTime, workflowToRunID, bitriseConfig, inventoryEnvironments, tracker); err != nil { tracker.Wait() logExit(1) - log.Fatalf("Failed to run workflow, error: %s", err) + failf("Failed to run workflow, error: %s", err) } else if buildRunResults.IsBuildFailed() { tracker.Wait() exitCode := buildRunResults.ExitCode() @@ -145,10 +146,10 @@ func logExit(exitCode int) { message = fmt.Sprintf("Bitrise build failed (exit code: %d)", exitCode) colorMessage = colorstring.Red(message) } - utilsLog.RInfof("bitrise-cli", "exit", map[string]interface{}{"build_slug": os.Getenv("BITRISE_BUILD_SLUG")}, message) - fmt.Println() - fmt.Print(colorMessage) - fmt.Println() + analytics.LogMessage("info", "bitrise-cli", "exit", map[string]interface{}{"build_slug": os.Getenv("BITRISE_BUILD_SLUG")}, message) + log.Print() + log.Print(colorMessage) + log.Print() } func printRunningWorkflow(bitriseConfig models.BitriseDataModel, targetWorkflowToRunID string) { @@ -242,7 +243,7 @@ func run(c *cli.Context) error { // Inventory validation inventoryEnvironments, err := CreateInventoryFromCLIParams(runParams.InventoryBase64Data, runParams.InventoryPath) if err != nil { - log.Fatalf("Failed to create inventory, error: %s", err) + failf("Failed to create inventory, error: %s", err) } // Config validation @@ -251,7 +252,7 @@ func run(c *cli.Context) error { log.Warnf("warning: %s", warning) } if err != nil { - log.Fatalf("Failed to create bitrise config, error: %s", err) + failf("Failed to create bitrise config, error: %s", err) } // Workflow id validation @@ -259,7 +260,7 @@ func run(c *cli.Context) error { // no workflow specified // list all the available ones and then exit log.Error("No workflow specified!") - fmt.Println() + log.Print() printAvailableWorkflows(bitriseConfig) os.Exit(1) } @@ -267,7 +268,7 @@ func run(c *cli.Context) error { // util workflow specified // print about util workflows and then exit log.Error("Utility workflows can't be triggered directly") - fmt.Println() + log.Print() printAboutUtilityWorkflowsText() os.Exit(1) } @@ -277,38 +278,38 @@ func run(c *cli.Context) error { // Main enabledFiltering, err := isSecretFiltering(secretFiltering, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check Secret Filtering mode, error: %s", err) + failf("Failed to check Secret Filtering mode, error: %s", err) } if err := registerSecretFiltering(enabledFiltering); err != nil { - log.Fatalf("Failed to register Secret Filtering mode, error: %s", err) + failf("Failed to register Secret Filtering mode, error: %s", err) } enabledEnvsFiltering, err := isSecretEnvsFiltering(secretEnvsFiltering, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check Secret Envs Filtering mode, error: %s", err) + failf("Failed to check Secret Envs Filtering mode, error: %s", err) } if err := registerSecretEnvsFiltering(enabledEnvsFiltering); err != nil { - log.Fatalf("Failed to register Secret Envs Filtering mode, error: %s", err) + failf("Failed to register Secret Envs Filtering mode, error: %s", err) } isPRMode, err := isPRMode(prGlobalFlagPtr, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check PR mode, error: %s", err) + failf("Failed to check PR mode, error: %s", err) } if err := registerPrMode(isPRMode); err != nil { - log.Fatalf("Failed to register PR mode, error: %s", err) + failf("Failed to register PR mode, error: %s", err) } isCIMode, err := isCIMode(ciGlobalFlagPtr, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check CI mode, error: %s", err) + failf("Failed to check CI mode, error: %s", err) } if err := registerCIMode(isCIMode); err != nil { - log.Fatalf("Failed to register CI mode, error: %s", err) + failf("Failed to register CI mode, error: %s", err) } noOutputTimeout := readNoOutputTimoutConfiguration(inventoryEnvironments) diff --git a/cli/run_config.go b/cli/run_config.go index 82e204f45..9d7d52170 100644 --- a/cli/run_config.go +++ b/cli/run_config.go @@ -7,9 +7,9 @@ import ( "time" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" envmanModels "github.com/bitrise-io/envman/models" "github.com/bitrise-io/go-utils/colorstring" - log "github.com/sirupsen/logrus" ) func getNoOutputTimoutValue(inventoryEnvironments []envmanModels.EnvironmentItemModel) (string, error) { diff --git a/cli/run_test.go b/cli/run_test.go index d4565f47c..5a76a3642 100644 --- a/cli/run_test.go +++ b/cli/run_test.go @@ -1,8 +1,9 @@ package cli import ( + "bytes" "fmt" - "io/ioutil" + "io" "os" "path/filepath" "strings" @@ -12,6 +13,7 @@ import ( cliAnalytics "github.com/bitrise-io/bitrise/analytics" "github.com/bitrise-io/bitrise/bitrise" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/plugins" envmanModels "github.com/bitrise-io/envman/models" @@ -1601,15 +1603,20 @@ route_map: givenPluginInstalled(t, pluginYML, "testplugin", pluginSpec) // When - var err error - output := captureOutput(t, func() { - _, err = runWorkflowWithConfiguration(time.Now(), "test", config, []envmanModels.EnvironmentItemModel{}, noOpTracker{}) - }) + var origWiter io.Writer + var buf bytes.Buffer + opts := log.GetGlobalLoggerOpts() + origWiter = opts.Writer + opts.Writer = &buf + log.InitGlobalLogger(opts) + _, err := runWorkflowWithConfiguration(time.Now(), "test", config, []envmanModels.EnvironmentItemModel{}, noOpTracker{}) + opts.Writer = origWiter // Then require.NoError(t, err) for _, expectedEvent := range test.expectedTriggeredEvents { - assert.True(t, strings.Contains(output, expectedEvent)) + output := buf.String() + assert.True(t, strings.Contains(output, expectedEvent), output) } } } @@ -1663,24 +1670,6 @@ func givenPlugin(t *testing.T, pluginContent, pluginName, pluginSpec string) str return bitriseDir } -func captureOutput(t *testing.T, function func()) string { - old := os.Stdout // keep backup of the real stdout - r, w, err := os.Pipe() - require.NoError(t, err) - - os.Stdout = w - - function() - - err = w.Close() - require.NoError(t, err) - out, err := ioutil.ReadAll(r) - require.NoError(t, err) - os.Stdout = old - - return string(out) -} - func write(t *testing.T, content, toPth string) { toDir := filepath.Dir(toPth) exist, err := pathutil.IsDirExists(toDir) diff --git a/cli/run_util.go b/cli/run_util.go index df0d7dab0..dd1959f5d 100644 --- a/cli/run_util.go +++ b/cli/run_util.go @@ -15,6 +15,8 @@ import ( "github.com/bitrise-io/bitrise/analytics" "github.com/bitrise-io/bitrise/bitrise" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" + "github.com/bitrise-io/bitrise/log/logwriter" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/plugins" "github.com/bitrise-io/bitrise/toolkits" @@ -30,7 +32,6 @@ import ( "github.com/bitrise-io/go-utils/versions" stepmanModels "github.com/bitrise-io/stepman/models" "github.com/gofrs/uuid" - log "github.com/sirupsen/logrus" ) func isPRMode(prGlobalFlagPtr *bool, inventoryEnvironments []envmanModels.EnvironmentItemModel) (bool, error) { @@ -266,7 +267,7 @@ func GetInventoryFromBase64Data(inventoryBase64Str string) ([]envmanModels.Envir // GetInventoryFilePath ... func GetInventoryFilePath(inventoryPath string) (string, error) { if inventoryPath == "" { - log.Debugln("[BITRISE_CLI] - Inventory path not defined, searching for " + DefaultSecretsFileName + " in current folder...") + log.Debug("[BITRISE_CLI] - Inventory path not defined, searching for " + DefaultSecretsFileName + " in current folder...") inventoryPath = filepath.Join(configs.CurrentDir, DefaultSecretsFileName) if exist, err := pathutil.IsPathExists(inventoryPath); err != nil { @@ -423,7 +424,21 @@ func executeStep( noOutputTimeout = time.Duration(*step.NoOutputTimeout) * time.Second } - return tools.EnvmanRun(configs.InputEnvstorePath, bitriseSourceDir, cmd, timeout, noOutputTimeout, secrets, nil) + opts := log.GetGlobalLoggerOpts() + opts.Producer = log.Step + opts.ProducerID = uuid.Must(uuid.NewV4()).String() + logWriter := logwriter.NewLogWriter(log.NewLogger(opts)) + + return tools.EnvmanRun( + configs.InputEnvstorePath, + bitriseSourceDir, + cmd, + timeout, + noOutputTimeout, + secrets, + nil, + &logWriter, + &logWriter) } func runStep( @@ -438,7 +453,7 @@ func runStep( // with a Toolkit+Deps if err := retry.Times(2).Try(func(attempt uint) error { if attempt > 0 { - fmt.Println() + log.Print() log.Warn("Installing Step dependency failed, retrying ...") } @@ -584,7 +599,7 @@ func activateAndRunSteps( isLastWorkflow bool, tracker analytics.Tracker, workflowIDProperties coreanalytics.Properties) models.BuildRunResultsModel { - log.Debugln("[BITRISE_CLI] - Activating and running steps") + log.Debug("[BITRISE_CLI] - Activating and running steps") // ------------------------------------------ // In function global variables - These are global for easy use in local register step run result methods. @@ -671,7 +686,7 @@ func activateAndRunSteps( mergedStep := workflowStep if stepYMLPth != "" { specStep, err := bitrise.ReadSpecStep(stepYMLPth) - log.Debugf("Spec read from YML: %#v\n", specStep) + log.Debugf("Spec read from YML: %#v", specStep) if err != nil { ymlPth := stepYMLPth if origStepYMLPth != "" { diff --git a/cli/setup.go b/cli/setup.go index 92c0e0ac4..dc2e7ed6e 100644 --- a/cli/setup.go +++ b/cli/setup.go @@ -1,11 +1,10 @@ package cli import ( - "fmt" "os" "github.com/bitrise-io/bitrise/bitrise" - "github.com/bitrise-io/go-utils/log" + "github.com/bitrise-io/bitrise/log" "github.com/urfave/cli" ) @@ -34,16 +33,16 @@ var setupCommand = cli.Command{ // PrintBitriseHeaderASCIIArt ... func PrintBitriseHeaderASCIIArt(appVersion string) { // generated here: http://patorjk.com/software/taag/#p=display&f=ANSI%20Shadow&t=Bitrise - fmt.Println(` + log.Print(` ██████╗ ██╗████████╗██████╗ ██╗███████╗███████╗ ██╔══██╗██║╚══██╔══╝██╔══██╗██║██╔════╝██╔════╝ ██████╔╝██║ ██║ ██████╔╝██║███████╗█████╗ ██╔══██╗██║ ██║ ██╔══██╗██║╚════██║██╔══╝ ██████╔╝██║ ██║ ██║ ██║██║███████║███████╗ ╚═════╝ ╚═╝ ╚═╝ ╚═╝ ╚═╝╚═╝╚══════╝╚══════╝`) - fmt.Println() + log.Print() log.Donef(" version: %s", appVersion) - fmt.Println() + log.Print() } func setup(c *cli.Context) error { @@ -56,12 +55,12 @@ func setup(c *cli.Context) error { return err } - fmt.Println() + log.Print() log.Infof("To start using bitrise:") log.Printf("* cd into your project's directory (if you're not there already)") log.Printf("* call: bitrise init") log.Printf("* follow the guide") - fmt.Println() + log.Print() log.Donef("That's all :)") return nil diff --git a/cli/share.go b/cli/share.go index c6db1428e..12638e2f5 100644 --- a/cli/share.go +++ b/cli/share.go @@ -1,15 +1,13 @@ package cli import ( - "log" - "github.com/bitrise-io/bitrise/tools" "github.com/urfave/cli" ) func share(c *cli.Context) error { if err := tools.StepmanShare(); err != nil { - log.Fatalf("Bitrise share failed, error: %s", err) + failf("Bitrise share failed, error: %s", err) } return nil diff --git a/cli/share_audit.go b/cli/share_audit.go index bb9f90659..2c28836e4 100644 --- a/cli/share_audit.go +++ b/cli/share_audit.go @@ -1,15 +1,13 @@ package cli import ( - "log" - "github.com/bitrise-io/bitrise/tools" "github.com/urfave/cli" ) func shareAudit(c *cli.Context) error { if err := tools.StepmanShareAudit(); err != nil { - log.Fatalf("Bitrise share audit failed, error: %s", err) + failf("Bitrise share audit failed, error: %s", err) } return nil diff --git a/cli/share_create.go b/cli/share_create.go index c85ba58f7..c968a9a92 100644 --- a/cli/share_create.go +++ b/cli/share_create.go @@ -2,7 +2,6 @@ package cli import ( "github.com/bitrise-io/bitrise/tools" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -10,18 +9,18 @@ func create(c *cli.Context) error { // Input validation tag := c.String(TagKey) if tag == "" { - log.Fatal("No step tag specified") + failf("No step tag specified") } gitURI := c.String(GitKey) if gitURI == "" { - log.Fatal("No step url specified") + failf("No step url specified") } stepID := c.String(StepIDKey) if err := tools.StepmanShareCreate(tag, gitURI, stepID); err != nil { - log.Fatalf("Bitrise share create failed, error: %s", err) + failf("Bitrise share create failed, error: %s", err) } return nil diff --git a/cli/share_finish.go b/cli/share_finish.go index c61a19c68..650516f7e 100644 --- a/cli/share_finish.go +++ b/cli/share_finish.go @@ -1,15 +1,13 @@ package cli import ( - "log" - "github.com/bitrise-io/bitrise/tools" "github.com/urfave/cli" ) func finish(c *cli.Context) error { if err := tools.StepmanShareFinish(); err != nil { - log.Fatalf("Bitrise share finish failed, error: %s", err) + failf("Bitrise share finish failed, error: %s", err) } return nil diff --git a/cli/share_start.go b/cli/share_start.go index ac7c283da..d581abf77 100644 --- a/cli/share_start.go +++ b/cli/share_start.go @@ -2,7 +2,6 @@ package cli import ( "github.com/bitrise-io/bitrise/tools" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -10,11 +9,11 @@ func start(c *cli.Context) error { // Input validation collectionURI := c.String(CollectionKey) if collectionURI == "" { - log.Fatal("No step collection specified") + failf("No step collection specified") } if err := tools.StepmanShareStart(collectionURI); err != nil { - log.Fatalf("Bitrise share start failed, error: %s", err) + failf("Bitrise share start failed, error: %s", err) } return nil diff --git a/cli/step_activator.go b/cli/step_activator.go index 27a473b07..72694d483 100644 --- a/cli/step_activator.go +++ b/cli/step_activator.go @@ -7,13 +7,13 @@ import ( "path/filepath" "strings" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/go-utils/command" "github.com/bitrise-io/go-utils/command/git" "github.com/bitrise-io/go-utils/pathutil" "github.com/bitrise-io/go-utils/pointers" stepmanModels "github.com/bitrise-io/stepman/models" - log "github.com/sirupsen/logrus" ) type stepActivator struct { @@ -40,7 +40,7 @@ func (a stepActivator) activateStep( return "", "", err } - log.Debugln("stepAbsLocalPth:", stepAbsLocalPth, "|stepDir:", stepDir) + log.Debug("stepAbsLocalPth:", stepAbsLocalPth, "|stepDir:", stepDir) origStepYMLPth = filepath.Join(stepAbsLocalPth, "step.yml") if err := command.CopyFile(origStepYMLPth, stepYMLPth); err != nil { diff --git a/cli/step_info.go b/cli/step_info.go index f10a4fe72..4dfe1f920 100644 --- a/cli/step_info.go +++ b/cli/step_info.go @@ -3,12 +3,13 @@ package cli import ( "fmt" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/bitrise/tools" "github.com/urfave/cli" ) -func printStepLibStep(collectionURI, id, version, format string) error { +func printStep(collectionURI, id, version, format string) error { stepInfo, err := tools.StepmanStepInfo(collectionURI, id, version) switch format { @@ -16,34 +17,13 @@ func printStepLibStep(collectionURI, id, version, format string) error { if err != nil { return err } - fmt.Println("Step info:") - fmt.Println(stepInfo.String()) + log.Print("Step info:") + log.Print(stepInfo.String()) case output.FormatJSON: if err != nil { return fmt.Errorf("StepmanJSONStepLibStepInfo failed, err: %s", err) } - fmt.Println(stepInfo.JSON()) - default: - return fmt.Errorf("Invalid format: %s", format) - } - return nil -} - -func printLocalStepInfo(pth, format string) error { - stepInfo, err := tools.StepmanStepInfo("path", pth, "") - - switch format { - case output.FormatRaw: - if err != nil { - return err - } - fmt.Println("Step info:") - fmt.Println(stepInfo.String()) - case output.FormatJSON: - if err != nil { - return fmt.Errorf("StepmanJSONLocalStepInfo failed, err: %s", err) - } - fmt.Println(stepInfo.JSON()) + log.Print(stepInfo.JSON()) default: return fmt.Errorf("Invalid format: %s", format) } @@ -85,14 +65,10 @@ func stepInfo(c *cli.Context) error { } if YMLPath != "" { - // - // Local step info - if err := printLocalStepInfo(YMLPath, format); err != nil { - registerFatal(fmt.Sprintf("Failed to print step info (yml path: %s), err: %s", YMLPath, err), warnings, format) - } + collectionURI = "path" + id = YMLPath + version = "" } else { - - // // Steplib step info if collectionURI == "" { bitriseConfig, warns, err := CreateBitriseConfigFromCLIParams(bitriseConfigBase64Data, bitriseConfigPath) @@ -107,10 +83,10 @@ func stepInfo(c *cli.Context) error { collectionURI = bitriseConfig.DefaultStepLibSource } + } - if err := printStepLibStep(collectionURI, id, version, format); err != nil { - registerFatal(fmt.Sprintf("Failed to print step info, err: %s", err), warnings, format) - } + if err := printStep(collectionURI, id, version, format); err != nil { + registerFatal(fmt.Sprintf("Failed to print step info, err: %s", err), warnings, format) } return nil diff --git a/cli/step_list.go b/cli/step_list.go index c18c7ce95..dc5d24dec 100644 --- a/cli/step_list.go +++ b/cli/step_list.go @@ -3,6 +3,7 @@ package cli import ( "fmt" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/bitrise/tools" "github.com/urfave/cli" @@ -51,8 +52,8 @@ func stepList(c *cli.Context) error { case output.FormatRaw: out, err := tools.StepmanRawStepList(collectionURI) if out != "" { - fmt.Println("Step list:") - fmt.Printf("%s", out) + log.Print("Step list:") + log.Printf("%s", out) } if err != nil { registerFatal(fmt.Sprintf("Failed to print step info, err: %s", err), warnings, format) @@ -62,7 +63,7 @@ func stepList(c *cli.Context) error { if err != nil { registerFatal(fmt.Sprintf("Failed to print step info, err: %s", err), warnings, format) } - fmt.Println(outStr) + log.Print(outStr) default: registerFatal(fmt.Sprintf("Invalid format: %s", format), warnings, output.FormatJSON) } diff --git a/cli/tools.go b/cli/tools.go index 234ca28d3..08c50c63b 100644 --- a/cli/tools.go +++ b/cli/tools.go @@ -4,7 +4,6 @@ import ( "os" "github.com/bitrise-io/go-utils/command" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -14,7 +13,7 @@ var stepmanCommand = cli.Command{ SkipFlagParsing: true, Action: func(c *cli.Context) error { if err := runCommandWith("stepman", c); err != nil { - log.Fatalf("Command failed, error: %s", err) + failf("Command failed, error: %s", err) } return nil }, @@ -26,7 +25,7 @@ var envmanCommand = cli.Command{ SkipFlagParsing: true, Action: func(c *cli.Context) error { if err := runCommandWith("envman", c); err != nil { - log.Fatalf("Command failed, error: %s", err) + failf("Command failed, error: %s", err) } return nil }, diff --git a/cli/trigger.go b/cli/trigger.go index 488a24898..066107ef2 100644 --- a/cli/trigger.go +++ b/cli/trigger.go @@ -7,10 +7,10 @@ import ( "github.com/bitrise-io/bitrise/analytics" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/version" "github.com/bitrise-io/go-utils/pointers" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -45,7 +45,7 @@ var triggerCommand = cli.Command{ } func printAvailableTriggerFilters(triggerMap []models.TriggerMapItemModel) { - log.Infoln("The following trigger filters are available:") + log.Info("The following trigger filters are available:") for _, triggerItem := range triggerMap { if triggerItem.Pattern != "" { @@ -136,7 +136,7 @@ func trigger(c *cli.Context) error { // Inventory validation inventoryEnvironments, err := CreateInventoryFromCLIParams(triggerParams.InventoryBase64Data, triggerParams.InventoryPath) if err != nil { - log.Fatalf("Failed to create inventory, error: %s", err) + failf("Failed to create inventory, error: %s", err) } // Config validation @@ -145,7 +145,7 @@ func trigger(c *cli.Context) error { log.Warnf("warning: %s", warning) } if err != nil { - log.Fatalf("Failed to create bitrise config, error: %s", err) + failf("Failed to create bitrise config, error: %s", err) } // Trigger filter validation @@ -160,38 +160,38 @@ func trigger(c *cli.Context) error { // Main enabledFiltering, err := isSecretFiltering(secretFiltering, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check Secret Filtering mode, error: %s", err) + failf("Failed to check Secret Filtering mode, error: %s", err) } if err := registerSecretFiltering(enabledFiltering); err != nil { - log.Fatalf("Failed to register Secret Filtering mode, error: %s", err) + failf("Failed to register Secret Filtering mode, error: %s", err) } enabledEnvsFiltering, err := isSecretEnvsFiltering(secretEnvsFiltering, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check Secret Envs Filtering mode, error: %s", err) + failf("Failed to check Secret Envs Filtering mode, error: %s", err) } if err := registerSecretEnvsFiltering(enabledEnvsFiltering); err != nil { - log.Fatalf("Failed to register Secret Envs Filtering mode, error: %s", err) + failf("Failed to register Secret Envs Filtering mode, error: %s", err) } isPRMode, err := isPRMode(prGlobalFlagPtr, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check PR mode, error: %s", err) + failf("Failed to check PR mode, error: %s", err) } if err := registerPrMode(isPRMode); err != nil { - log.Fatalf("Failed to register PR mode, error: %s", err) + failf("Failed to register PR mode, error: %s", err) } isCIMode, err := isCIMode(ciGlobalFlagPtr, inventoryEnvironments) if err != nil { - log.Fatalf("Failed to check CI mode, error: %s", err) + failf("Failed to check CI mode, error: %s", err) } if err := registerCIMode(isCIMode); err != nil { - log.Fatalf("Failed to register CI mode, error: %s", err) + failf("Failed to register CI mode, error: %s", err) } _, workflowToRunID, err := getPipelineAndWorkflowIDByParamsInCompatibleMode(bitriseConfig.TriggerMap, triggerParams, isPRMode) diff --git a/cli/trigger_check.go b/cli/trigger_check.go index f64a106b5..cc4e4bded 100644 --- a/cli/trigger_check.go +++ b/cli/trigger_check.go @@ -5,11 +5,11 @@ import ( "fmt" "os" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/go-utils/colorstring" "github.com/bitrise-io/go-utils/pointers" - log "github.com/sirupsen/logrus" "github.com/urfave/cli" ) @@ -28,14 +28,14 @@ func registerFatal(errorMsg string, warnings []string, format string) { for _, warning := range message.Warnings { log.Warnf("warning: %s", warning) } - log.Fatal(message.Error) + failf(message.Error) } else { bytes, err := json.Marshal(message) if err != nil { - log.Fatalf("Failed to parse error model, error: %s", err) + failf("Failed to parse error model, error: %s", err) } - fmt.Println(string(bytes)) + log.Print(string(bytes)) os.Exit(1) } } @@ -208,7 +208,7 @@ func triggerCheck(c *cli.Context) error { msg = fmt.Sprintf("%s: %s ", key, value) + msg } } - fmt.Println(msg) + log.Print(msg) break case output.FormatJSON: bytes, err := json.Marshal(triggerModel) @@ -216,7 +216,7 @@ func triggerCheck(c *cli.Context) error { registerFatal(fmt.Sprintf("Failed to parse trigger model, err: %s", err), warnings, triggerParams.Format) } - fmt.Println(string(bytes)) + log.Print(string(bytes)) break default: registerFatal(fmt.Sprintf("Invalid format: %s", triggerParams.Format), warnings, output.FormatJSON) diff --git a/cli/update.go b/cli/update.go index b37fb1fd6..9a234e138 100644 --- a/cli/update.go +++ b/cli/update.go @@ -15,10 +15,10 @@ import ( "github.com/bitrise-io/bitrise/bitrise" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/plugins" "github.com/bitrise-io/bitrise/version" "github.com/bitrise-io/go-utils/command" - "github.com/bitrise-io/go-utils/log" ver "github.com/hashicorp/go-version" "github.com/urfave/cli" ) @@ -88,7 +88,7 @@ func checkUpdate() error { func printCLIUpdateInfos(newVersion string) { log.Warnf("\nNew version (%s) of the Bitrise CLI available", newVersion) - log.Printf("Run command to update the Bitrise CLI:\n") + log.Printf("Run command to update the Bitrise CLI:") log.Donef("$ bitrise update") } @@ -219,7 +219,7 @@ func update(c *cli.Context) error { log.Infof("Updating Bitrise CLI...") versionFlag := c.String("version") - fmt.Printf("Current version: %s\n", version.VERSION) + log.Printf("Current version: %s", version.VERSION) withBrew, err := installedWithBrew() if err != nil { @@ -271,9 +271,9 @@ func update(c *cli.Context) error { return nil } - fmt.Printf("Updating to version: %s\n", versionFlag) + log.Printf("Updating to version: %s", versionFlag) - fmt.Println("Downloading Bitrise CLI...") + log.Print("Downloading Bitrise CLI...") if err := download(versionFlag); err != nil { return err } diff --git a/cli/validate.go b/cli/validate.go index 9662849c4..7c7a9be44 100644 --- a/cli/validate.go +++ b/cli/validate.go @@ -3,14 +3,11 @@ package cli import ( "encoding/json" "fmt" - "os" - "strings" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/go-utils/colorstring" - flog "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) @@ -239,12 +236,12 @@ func validate(c *cli.Context) error { format = output.FormatRaw } - var log flog.Logger - log = flog.NewDefaultRawLogger() + var log Logger + log = NewDefaultRawLogger() if format == output.FormatRaw { - log = flog.NewDefaultRawLogger() + log = NewDefaultRawLogger() } else if format == output.FormatJSON { - log = flog.NewDefaultJSONLoger() + log = NewDefaultJSONLoger() } else { log.Print(NewValidationError(fmt.Sprintf("Invalid format: %s", format))) os.Exit(1) diff --git a/cli/version.go b/cli/version.go index ccdc0e56e..253023671 100644 --- a/cli/version.go +++ b/cli/version.go @@ -2,10 +2,9 @@ package cli import ( "fmt" - "log" - "runtime" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/bitrise/version" @@ -26,7 +25,7 @@ func printVersionCmd(c *cli.Context) error { fullVersion := c.Bool("full") if err := output.ConfigureOutputFormat(c); err != nil { - log.Fatalf("Failed to configure output format, error: %s", err) + failf("Failed to configure output format, error: %s", err) } versionOutput := VersionOutputModel{ @@ -50,10 +49,10 @@ go: %s build number: %s commit: %s `, versionOutput.Version, versionOutput.FormatVersion, versionOutput.OS, versionOutput.GO, versionOutput.BuildNumber, versionOutput.Commit) - fmt.Println(versionStr) + log.Print(versionStr) } else { versionStr := fmt.Sprintf("%s", versionOutput.Version) - fmt.Println(versionStr) + log.Print(versionStr) } } else { output.Print(versionOutput, output.Format) diff --git a/cli/workflow_list.go b/cli/workflow_list.go index af16c2e97..758eac4ec 100644 --- a/cli/workflow_list.go +++ b/cli/workflow_list.go @@ -7,9 +7,9 @@ import ( "sort" "strings" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/output" "github.com/bitrise-io/go-utils/colorstring" - "github.com/bitrise-io/go-utils/log" "github.com/urfave/cli" ) @@ -189,10 +189,10 @@ func workflowList(c *cli.Context) error { return fmt.Errorf("invalid format: %s", format) } - var logger log.Logger - logger = log.NewDefaultRawLogger() + var logger Logger + logger = NewDefaultRawLogger() if format == output.FormatJSON { - logger = log.NewDefaultJSONLoger() + logger = NewDefaultJSONLoger() } if minimal && idOnly { diff --git a/configs/paths.go b/configs/paths.go index 1d91af047..a55dc6423 100644 --- a/configs/paths.go +++ b/configs/paths.go @@ -6,8 +6,8 @@ import ( "path/filepath" "strings" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/go-utils/pathutil" - log "github.com/sirupsen/logrus" ) var ( diff --git a/go.mod b/go.mod index ef2ba96d9..0d69f359d 100644 --- a/go.mod +++ b/go.mod @@ -5,14 +5,13 @@ go 1.16 require ( github.com/bitrise-io/envman v0.0.0-20221010094751-a03ce30a5316 github.com/bitrise-io/go-utils v1.0.3 - github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.10 + github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.12.0.20221010132402-33be72261ded github.com/bitrise-io/goinp v0.0.0-20211005113137-305e91b481f4 github.com/bitrise-io/gows v0.0.0-20211005113107-14f65e686b88 github.com/bitrise-io/stepman v0.0.0-20221010110437-a88e9a915b58 github.com/gofrs/uuid v4.2.0+incompatible github.com/hashicorp/go-version v1.4.0 github.com/ryanuber/go-glob v1.0.0 - github.com/sirupsen/logrus v1.8.1 github.com/stretchr/testify v1.7.1 github.com/urfave/cli v1.22.5 golang.org/x/crypto v0.0.0-20220315160706-3147a52a75dd // indirect diff --git a/go.sum b/go.sum index c46c8c5df..213b634f2 100644 --- a/go.sum +++ b/go.sum @@ -5,11 +5,10 @@ github.com/bitrise-io/envman v0.0.0-20221010094751-a03ce30a5316 h1:gRQReCvmNxUVv github.com/bitrise-io/envman v0.0.0-20221010094751-a03ce30a5316/go.mod h1:L4WQyg88d87Z4dxNwrYEa0Cwd9/W0gSfXsibw30r8Vw= github.com/bitrise-io/go-utils v0.0.0-20200224122728-e212188d99b4/go.mod h1:tTEsKvbz1LbzuN/KpVFHXnLtcAPdEgIdM41s0lL407s= github.com/bitrise-io/go-utils v0.0.0-20210505121718-07411d72e36e/go.mod h1:nhdaDQFvaMny1CugVV6KjK92/q97ENo0RuKSW5I4fbA= -github.com/bitrise-io/go-utils v1.0.1/go.mod h1:ZY1DI+fEpZuFpO9szgDeICM4QbqoWVt0RSY3tRI1heY= github.com/bitrise-io/go-utils v1.0.3 h1:xKy0WyiJtRPqeKl/HrwQJ0QdjNOOUhiVHs81RMDwD94= github.com/bitrise-io/go-utils v1.0.3/go.mod h1:ZY1DI+fEpZuFpO9szgDeICM4QbqoWVt0RSY3tRI1heY= -github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.10 h1:b3sG8BNhsktfYd8YXraVQsKunFKMs0bRELXdx/zhTKA= -github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.10/go.mod h1:Ta/ards3Ih/3Q6X8tBtcj6zTHcNf1hRSXv1E8lPgIYk= +github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.12.0.20221010132402-33be72261ded h1:KOnT1jCD1hMMFsEd4Ll0Njd/PU7HcdAX2I+jNxypFqU= +github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.12.0.20221010132402-33be72261ded/go.mod h1:gZWtM7PLn1VOroa4gN1La/24aRVc0jg5R701jTsPaO8= github.com/bitrise-io/goinp v0.0.0-20210504152833-8559b0680ab1/go.mod h1:iRbd8zAXLeNy+0gic0eqNCxXvDGe8ZEY/uYX2CCeAoo= github.com/bitrise-io/goinp v0.0.0-20211005113137-305e91b481f4 h1:ytUxnO7iSGHlNpbdjhDUefEM5WRy1kD2ElGfBA7r1PE= github.com/bitrise-io/goinp v0.0.0-20211005113137-305e91b481f4/go.mod h1:iRbd8zAXLeNy+0gic0eqNCxXvDGe8ZEY/uYX2CCeAoo= @@ -32,8 +31,9 @@ github.com/hashicorp/go-cleanhttp v0.5.2 h1:035FKYIWjmULyFRBKPs8TBQoi0x6d9G4xc9n github.com/hashicorp/go-cleanhttp v0.5.2/go.mod h1:kO/YDlP8L1346E6Sodw+PrpBSV4/SoxCXGY6BqNFT48= github.com/hashicorp/go-hclog v0.9.2 h1:CG6TE5H9/JXsFWJCfoIVpKFIkFe6ysEuHirp4DxCsHI= github.com/hashicorp/go-hclog v0.9.2/go.mod h1:5CU+agLiy3J7N7QjHK5d05KxGsuXiQLrjA0H7acj2lQ= -github.com/hashicorp/go-retryablehttp v0.7.0 h1:eu1EI/mbirUgP5C8hVsTNaGZreBDlYiwC1FZWkvQPQ4= github.com/hashicorp/go-retryablehttp v0.7.0/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY= +github.com/hashicorp/go-retryablehttp v0.7.1 h1:sUiuQAnLlbvmExtFQs72iFW/HXeUn8Z1aJLQ4LJJbTQ= +github.com/hashicorp/go-retryablehttp v0.7.1/go.mod h1:vAew36LZh98gCBJNLH42IQ1ER/9wtLZZ8meHqQvEYWY= github.com/hashicorp/go-version v1.4.0 h1:aAQzgqIrRKRa7w75CKpbBxYsmUoPjzVm1W59ca1L0J4= github.com/hashicorp/go-version v1.4.0/go.mod h1:fltr4n8CU8Ke44wwGCBoEymUuxUHl09ZGVZPK5anwXA= github.com/inconshreveable/mousetrap v1.0.0/go.mod h1:PxqpIevigyE2G7u3NXJIT2ANytuPF1OarO4DADm73n8= diff --git a/log/corelog/console_logger.go b/log/corelog/console_logger.go new file mode 100644 index 000000000..c32b7e8ac --- /dev/null +++ b/log/corelog/console_logger.go @@ -0,0 +1,76 @@ +package corelog + +import ( + "fmt" + "io" + "strings" +) + +var levelToANSIColorCode = map[Level]ANSIColorCode{ + ErrorLevel: RedCode, + WarnLevel: YellowCode, + InfoLevel: BlueCode, + DoneLevel: GreenCode, + DebugLevel: MagentaCode, +} + +type ANSIColorCode string + +const ( + RedCode ANSIColorCode = "\x1b[31;1m" + YellowCode ANSIColorCode = "\x1b[33;1m" + BlueCode ANSIColorCode = "\x1b[34;1m" + GreenCode ANSIColorCode = "\x1b[32;1m" + MagentaCode ANSIColorCode = "\x1b[35;1m" + ResetCode ANSIColorCode = "\x1b[0m" +) + +type consoleLogger struct { + output io.Writer +} + +func newConsoleLogger(output io.Writer) *consoleLogger { + return &consoleLogger{ + output: output, + } + +} + +// LogMessage ... +func (l *consoleLogger) LogMessage(message string, fields MessageFields) { + message = addColor(fields.Level, message) + + var prefixes []string + if fields.Timestamp != "" { + prefixes = append(prefixes, fmt.Sprintf("[%s]", fields.Timestamp)) + } + if fields.Producer != "" { + prefixes = append(prefixes, string(fields.Producer)) + } + if fields.ProducerID != "" { + prefixes = append(prefixes, fields.ProducerID) + } + prefix := strings.Join(prefixes, " ") + if prefix != "" && message != "" { + prefix += " " + } + + message = prefix + message + if _, err := fmt.Fprint(l.output, message); err != nil { + // Encountered an error during writing the message to the output. Manually construct a message for + // the error and print it to the stdout. + fmt.Printf("writing log message failed: %s", err) + } +} + +func addColor(level Level, message string) string { + if message == "" { + return message + } + + color := levelToANSIColorCode[level] + if color != "" { + return string(color) + message + string(ResetCode) + } + return message +} diff --git a/log/corelog/console_logger_test.go b/log/corelog/console_logger_test.go new file mode 100644 index 000000000..dbbe592d5 --- /dev/null +++ b/log/corelog/console_logger_test.go @@ -0,0 +1,107 @@ +package corelog + +import ( + "bytes" + "testing" + + "github.com/stretchr/testify/require" +) + +func Test_GivenConsoleLogger_WhenLogMessageInvoked_ThenLogsItCorrectly(t *testing.T) { + tests := []struct { + name string + messageFields MessageFields + message string + expectedMessage string + }{ + { + name: "Info message with fields", + messageFields: MessageFields{ + Timestamp: "2022.01.01", + Producer: "step", + ProducerID: "step--unique-id", + Level: InfoLevel, + }, + message: "Info message", + expectedMessage: "[2022.01.01] step step--unique-id \u001B[34;1mInfo message\u001B[0m", + }, + { + name: "Empty message with fields", + messageFields: MessageFields{ + Timestamp: "2022.01.01", + Producer: "step", + ProducerID: "step--unique-id", + Level: InfoLevel, + }, + message: "", + expectedMessage: "[2022.01.01] step step--unique-id", + }, + { + name: "Error log", + messageFields: MessageFields{ + Level: ErrorLevel, + }, + message: "Error", + expectedMessage: "\u001B[31;1mError\u001B[0m", + }, + { + name: "Warning log", + messageFields: MessageFields{ + Level: WarnLevel, + }, + message: "Warning", + expectedMessage: "\u001B[33;1mWarning\u001B[0m", + }, + { + name: "Info log", + messageFields: MessageFields{ + Level: InfoLevel, + }, + message: "Info", + expectedMessage: "\u001B[34;1mInfo\u001B[0m", + }, + { + name: "Done log", + messageFields: MessageFields{ + Level: DoneLevel, + }, + message: "Done", + expectedMessage: "\u001B[32;1mDone\u001B[0m", + }, + { + name: "Normal log", + messageFields: MessageFields{ + Level: NormalLevel, + }, + message: "Normal", + expectedMessage: "Normal", + }, + { + name: "Debug log", + messageFields: MessageFields{ + Level: DebugLevel, + }, + message: "Debug", + expectedMessage: "\u001B[35;1mDebug\u001B[0m", + }, + { + name: "Empty message is logged", + messageFields: MessageFields{ + Level: InfoLevel, + }, + message: "", + expectedMessage: "", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var buff bytes.Buffer + + logger := newConsoleLogger(&buff) + logger.LogMessage(tt.message, tt.messageFields) + + require.Equal(t, tt.expectedMessage, buff.String()) + }) + } +} diff --git a/log/corelog/json_logger.go b/log/corelog/json_logger.go new file mode 100644 index 000000000..15eed3736 --- /dev/null +++ b/log/corelog/json_logger.go @@ -0,0 +1,64 @@ +package corelog + +import ( + "encoding/json" + "fmt" + "io" +) + +type messageType string + +const ( + logMessageType messageType = "log" +) + +type logMessage struct { + Timestamp string `json:"timestamp"` + MessageType messageType `json:"type"` + Producer Producer `json:"producer"` + ProducerID string `json:"producer_id,omitempty"` + Level Level `json:"level"` + Message string `json:"message"` +} + +type jsonLogger struct { + encoder *json.Encoder +} + +func newJSONLogger(output io.Writer) *jsonLogger { + logger := jsonLogger{ + encoder: json.NewEncoder(output), + } + + return &logger +} + +// LogMessage ... +func (l *jsonLogger) LogMessage(message string, fields MessageFields) { + msg := logMessage{ + MessageType: logMessageType, + Message: message, + Timestamp: fields.Timestamp, + Producer: fields.Producer, + ProducerID: fields.ProducerID, + Level: fields.Level, + } + err := l.encoder.Encode(msg) + if err != nil { + // Encountered an error during writing the json message to the output. Manually construct a json message for + // the error and print it to the output + fmt.Println(l.logMessageForError(err, fields.Timestamp, fmt.Sprintf("%#v", msg))) + } +} + +func (l *jsonLogger) logMessageForError(err error, timestamps, msg string) string { + message := "{" + message += fmt.Sprintf(`"timestamp":"%s",`, timestamps) + message += fmt.Sprintf(`"type":"%s",`, string(logMessageType)) + message += fmt.Sprintf(`"producer":"%s",`, BitriseCLI) + message += fmt.Sprintf(`"level":"%s",`, string(ErrorLevel)) + message += fmt.Sprintf(`"message":"log message (%s) serialization failed: %s"`, msg, err) + message += "}" + + return message +} diff --git a/log/corelog/json_logger_test.go b/log/corelog/json_logger_test.go new file mode 100644 index 000000000..f49671c89 --- /dev/null +++ b/log/corelog/json_logger_test.go @@ -0,0 +1,137 @@ +package corelog + +import ( + "bytes" + "encoding/json" + "fmt" + "os" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +const rfc3339MicroTimeLayout = "2006-01-02T15:04:05.999999Z07:00" + +type testJSONLogMessage struct { + Timestamp string `json:"timestamp"` + MessageType string `json:"type"` + Producer string `json:"producer"` + Level string `json:"level"` + Message string `json:"message"` +} + +type testLogParameters struct { + producer Producer + level Level + message string +} + +func Test_GivenJsonLogger_WhenLogMessageInvoked_ThenGeneratesCorrectMessageFormat(t *testing.T) { + currentTime := time.Now() + currentTimeString := currentTime.Format(rfc3339MicroTimeLayout) + + tests := []struct { + name string + hasOutput bool + parameters testLogParameters + expectedMessage testJSONLogMessage + }{ + { + name: "CLI log", + hasOutput: true, + parameters: testLogParameters{ + producer: BitriseCLI, + level: InfoLevel, + message: "This is a cli log", + }, + expectedMessage: testJSONLogMessage{ + Timestamp: currentTimeString, + MessageType: "log", + Producer: "bitrise_cli", + Level: "info", + Message: "This is a cli log", + }, + }, + { + name: "Step log", + hasOutput: true, + parameters: testLogParameters{ + producer: Step, + level: NormalLevel, + message: "This is a step log", + }, + expectedMessage: testJSONLogMessage{ + Timestamp: currentTimeString, + MessageType: "log", + Producer: "step", + Level: "normal", + Message: "This is a step log", + }, + }, + { + name: "Debug log", + hasOutput: true, + parameters: testLogParameters{ + producer: Step, + level: DebugLevel, + message: "A useful debug log", + }, + expectedMessage: testJSONLogMessage{ + Timestamp: currentTimeString, + MessageType: "log", + Producer: "step", + Level: "debug", + Message: "A useful debug log", + }, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var buf bytes.Buffer + + logger := newJSONLogger(&buf) + logger.LogMessage(tt.parameters.message, MessageFields{ + Timestamp: currentTimeString, + Level: tt.parameters.level, + Producer: tt.parameters.producer, + }) + + if tt.hasOutput { + b, err := json.Marshal(tt.expectedMessage) + assert.NoError(t, err) + + expected := string(b) + "\n" + assert.Equal(t, expected, buf.String()) + } else { + assert.Equal(t, 0, buf.Len()) + } + }) + } +} + +func Test_GivenJsonLogger_WhenManualErrorMessageCreation_ThenMatchesTheLogMessageFormat(t *testing.T) { + err := fmt.Errorf("this is an error") + currentTime := time.Now() + currentTimeString := currentTime.Format(rfc3339MicroTimeLayout) + + logger := jsonLogger{ + encoder: json.NewEncoder(os.Stdout), + } + + message := logMessage{ + MessageType: "log", + Message: fmt.Sprintf("log message (invalid message) serialization failed: %s", err), + Timestamp: currentTimeString, + Producer: BitriseCLI, + ProducerID: "", + Level: ErrorLevel, + } + expected, jsonErr := json.Marshal(message) + assert.NoError(t, jsonErr) + + received := logger.logMessageForError(err, message.Timestamp, "invalid message") + + assert.Equal(t, string(expected), received) +} diff --git a/log/corelog/logger.go b/log/corelog/logger.go new file mode 100644 index 000000000..b25500e8d --- /dev/null +++ b/log/corelog/logger.go @@ -0,0 +1,62 @@ +package corelog + +import ( + "io" +) + +type LoggerType string + +const ( + JSONLogger LoggerType = "json" + ConsoleLogger LoggerType = "console" +) + +// Producer ... +type Producer string + +const ( + // BitriseCLI ... + BitriseCLI Producer = "bitrise_cli" + // Step ... + Step Producer = "step" +) + +// Level ... +type Level string + +const ( + // ErrorLevel ... + ErrorLevel Level = "error" + // WarnLevel ... + WarnLevel Level = "warn" + // InfoLevel ... + InfoLevel Level = "info" + // DoneLevel ... + DoneLevel Level = "done" + // NormalLevel ... + NormalLevel Level = "normal" + // DebugLevel ... + DebugLevel Level = "debug" +) + +// MessageFields ... +type MessageFields struct { + Timestamp string `json:"timestamp"` + Producer Producer `json:"producer"` + ProducerID string `json:"producer_id,omitempty"` + Level Level `json:"level"` +} + +// Logger ... +type Logger interface { + LogMessage(message string, fields MessageFields) +} + +func NewLogger(t LoggerType, output io.Writer) Logger { + switch t { + case JSONLogger: + return newJSONLogger(output) + default: + return newConsoleLogger(output) + } +} diff --git a/log/corelog/logger_test.go b/log/corelog/logger_test.go new file mode 100644 index 000000000..31e4401e0 --- /dev/null +++ b/log/corelog/logger_test.go @@ -0,0 +1,27 @@ +package corelog_test + +import ( + "os" + + "github.com/bitrise-io/bitrise/log/corelog" +) + +func ExampleLogger() { + var logger corelog.Logger + + fields := corelog.MessageFields{ + Timestamp: "2022-01-01T01:01:01Z", + Producer: corelog.BitriseCLI, + Level: corelog.InfoLevel, + } + message := "Info message" + + logger = corelog.NewLogger(corelog.JSONLogger, os.Stdout) + logger.LogMessage(message, fields) + + logger = corelog.NewLogger(corelog.ConsoleLogger, os.Stdout) + logger.LogMessage(message, fields) + + // Output: {"timestamp":"2022-01-01T01:01:01Z","type":"log","producer":"bitrise_cli","level":"info","message":"Info message"} + // [2022-01-01T01:01:01Z] bitrise_cli Info message +} diff --git a/log/log.go b/log/log.go new file mode 100644 index 000000000..32be87e61 --- /dev/null +++ b/log/log.go @@ -0,0 +1,171 @@ +package log + +import ( + "fmt" + "io" + "time" + + "github.com/bitrise-io/bitrise/log/corelog" +) + +const rfc3339MicroTimeLayout = "2006-01-02T15:04:05.999999Z07:00" + +const consoleTimeLayout = "15:04:05" + +type LoggerType corelog.LoggerType + +const ( + JSONLogger = LoggerType(corelog.JSONLogger) + ConsoleLogger = LoggerType(corelog.ConsoleLogger) +) + +type Producer corelog.Producer + +const ( + BitriseCLI = Producer(corelog.BitriseCLI) + Step = Producer(corelog.Step) +) + +// defaultLogger ... +type defaultLogger struct { + opts LoggerOpts + logger corelog.Logger +} + +type ConsoleLoggerOpts struct { + Timestamp bool +} + +type LoggerOpts struct { + LoggerType LoggerType + Producer Producer + ProducerID string + ConsoleLoggerOpts ConsoleLoggerOpts + DebugLogEnabled bool + Writer io.Writer + TimeProvider func() time.Time +} + +// NewLogger ... +func NewLogger(opts LoggerOpts) Logger { + return newLogger(opts) +} + +func newLogger(opts LoggerOpts) *defaultLogger { + logger := corelog.NewLogger(corelog.LoggerType(opts.LoggerType), opts.Writer) + return &defaultLogger{ + opts: opts, + logger: logger, + } +} + +// Error ... +func (m *defaultLogger) Error(args ...interface{}) { + m.logMessage(fmt.Sprint(args...)+"\n", corelog.ErrorLevel) +} + +// Errorf ... +func (m *defaultLogger) Errorf(format string, args ...interface{}) { + m.logMessage(fmt.Sprintf(format, args...)+"\n", corelog.ErrorLevel) +} + +// Warn ... +func (m *defaultLogger) Warn(args ...interface{}) { + m.logMessage(fmt.Sprint(args...)+"\n", corelog.WarnLevel) +} + +// Warnf ... +func (m *defaultLogger) Warnf(format string, args ...interface{}) { + m.logMessage(fmt.Sprintf(format, args...)+"\n", corelog.WarnLevel) +} + +// Info ... +func (m *defaultLogger) Info(args ...interface{}) { + m.logMessage(fmt.Sprint(args...)+"\n", corelog.InfoLevel) +} + +// Infof ... +func (m *defaultLogger) Infof(format string, args ...interface{}) { + m.logMessage(fmt.Sprintf(format, args...)+"\n", corelog.InfoLevel) +} + +// Done ... +func (m *defaultLogger) Done(args ...interface{}) { + m.logMessage(fmt.Sprint(args...)+"\n", corelog.DoneLevel) +} + +// Donef ... +func (m *defaultLogger) Donef(format string, args ...interface{}) { + m.logMessage(fmt.Sprintf(format, args...)+"\n", corelog.DoneLevel) +} + +// Print ... +func (m *defaultLogger) Print(args ...interface{}) { + m.logMessage(fmt.Sprint(args...)+"\n", corelog.NormalLevel) +} + +// Printf ... +func (m *defaultLogger) Printf(format string, args ...interface{}) { + m.logMessage(fmt.Sprintf(format, args...)+"\n", corelog.NormalLevel) +} + +// Debug ... +func (m *defaultLogger) Debug(args ...interface{}) { + if !m.opts.DebugLogEnabled { + return + } + m.logMessage(fmt.Sprint(args...)+"\n", corelog.DebugLevel) +} + +// Debugf ... +func (m *defaultLogger) Debugf(format string, args ...interface{}) { + if !m.opts.DebugLogEnabled { + return + } + m.logMessage(fmt.Sprintf(format, args...)+"\n", corelog.DebugLevel) +} + +// LogMessage ... +func (m *defaultLogger) LogMessage(message string, level corelog.Level) { + if level == corelog.DebugLevel && !m.opts.DebugLogEnabled { + return + } + + m.logMessage(message, level) +} + +func (m *defaultLogger) logMessage(message string, level corelog.Level) { + fields := m.createMessageFields(level) + m.logger.LogMessage(message, corelog.MessageFields(fields)) +} + +func (m *defaultLogger) createMessageFields(level corelog.Level) MessageFields { + if m.opts.LoggerType == JSONLogger { + return createJSONLogMessageFields(m.opts.Producer, m.opts.ProducerID, level, m.opts.TimeProvider) + } + + var tProvider func() time.Time + if m.opts.ConsoleLoggerOpts.Timestamp { + tProvider = m.opts.TimeProvider + } + return createConsoleLogMessageFields(level, tProvider) +} + +func createJSONLogMessageFields(producer Producer, producerID string, level corelog.Level, timeProvider func() time.Time) MessageFields { + return MessageFields{ + Timestamp: timeProvider().Format(rfc3339MicroTimeLayout), + Producer: corelog.Producer(producer), + ProducerID: producerID, + Level: level, + } +} + +func createConsoleLogMessageFields(level corelog.Level, timeProvider func() time.Time) MessageFields { + fields := MessageFields{ + Level: level, + } + if timeProvider != nil { + fields.Timestamp = timeProvider().Format(consoleTimeLayout) + } + return fields +} diff --git a/log/log_functions.go b/log/log_functions.go new file mode 100644 index 000000000..792d13651 --- /dev/null +++ b/log/log_functions.go @@ -0,0 +1,99 @@ +package log + +import ( + "os" + "time" + + "github.com/bitrise-io/bitrise/log/corelog" +) + +var globalLogger *defaultLogger + +func getGlobalLogger() Logger { + if globalLogger == nil { + opts := LoggerOpts{ + LoggerType: ConsoleLogger, + Producer: BitriseCLI, + Writer: os.Stdout, + TimeProvider: time.Now, + } + globalLogger = newLogger(opts) + } + return globalLogger +} + +// GetGlobalLoggerOpts ... +func GetGlobalLoggerOpts() LoggerOpts { + getGlobalLogger() + return globalLogger.opts +} + +// InitGlobalLogger ... +func InitGlobalLogger(opts LoggerOpts) { + globalLogger = newLogger(opts) +} + +// Error ... +func Error(args ...interface{}) { + getGlobalLogger().Error(args...) +} + +// Errorf ... +func Errorf(format string, args ...interface{}) { + getGlobalLogger().Errorf(format, args...) +} + +// Warn ... +func Warn(args ...interface{}) { + getGlobalLogger().Warn(args...) +} + +// Warnf ... +func Warnf(format string, args ...interface{}) { + getGlobalLogger().Warnf(format, args...) +} + +// Info ... +func Info(args ...interface{}) { + getGlobalLogger().Info(args...) +} + +// Infof ... +func Infof(format string, args ...interface{}) { + getGlobalLogger().Infof(format, args...) +} + +// Done ... +func Done(args ...interface{}) { + getGlobalLogger().Done(args...) +} + +// Donef ... +func Donef(format string, args ...interface{}) { + getGlobalLogger().Donef(format, args...) +} + +// Print ... +func Print(args ...interface{}) { + getGlobalLogger().Print(args...) +} + +// Printf ... +func Printf(format string, args ...interface{}) { + getGlobalLogger().Printf(format, args...) +} + +// Debug ... +func Debug(args ...interface{}) { + getGlobalLogger().Debug(args...) +} + +// Debugf ... +func Debugf(format string, args ...interface{}) { + getGlobalLogger().Debugf(format, args...) +} + +// LogMessage ... +func LogMessage(message string, level corelog.Level) { + getGlobalLogger().LogMessage(message, level) +} diff --git a/log/logger.go b/log/logger.go new file mode 100644 index 000000000..b125b003f --- /dev/null +++ b/log/logger.go @@ -0,0 +1,22 @@ +package log + +import "github.com/bitrise-io/bitrise/log/corelog" + +type MessageFields corelog.MessageFields + +// Logger ... +type Logger interface { + Error(args ...interface{}) + Errorf(format string, args ...interface{}) + Warn(args ...interface{}) + Warnf(format string, args ...interface{}) + Info(args ...interface{}) + Infof(format string, args ...interface{}) + Done(args ...interface{}) + Donef(format string, args ...interface{}) + Print(args ...interface{}) + Printf(format string, args ...interface{}) + Debug(args ...interface{}) + Debugf(format string, args ...interface{}) + LogMessage(message string, level corelog.Level) +} diff --git a/log/logger_test.go b/log/logger_test.go new file mode 100644 index 000000000..30159217b --- /dev/null +++ b/log/logger_test.go @@ -0,0 +1,43 @@ +package log_test + +import ( + "os" + "time" + + "github.com/bitrise-io/bitrise/log" +) + +func referenceTime() time.Time { + return time.Date(2022, 1, 1, 1, 1, 1, 0, time.UTC) +} + +func ExampleLogger() { + var logger log.Logger + + logger = log.NewLogger(log.LoggerOpts{ + LoggerType: log.ConsoleLogger, + Producer: log.BitriseCLI, + DebugLogEnabled: true, + Writer: os.Stdout, + TimeProvider: referenceTime, + }) + logger.Errorf("This is an %s", "error") + + logger = log.NewLogger(log.LoggerOpts{ + LoggerType: log.JSONLogger, + Producer: log.BitriseCLI, + DebugLogEnabled: true, + Writer: os.Stdout, + TimeProvider: referenceTime, + }) + logger.Debug("This is a debug message") + + log.InitGlobalLogger(log.LoggerOpts{ + LoggerType: log.JSONLogger, + Producer: log.BitriseCLI, + DebugLogEnabled: true, + Writer: os.Stdout, + TimeProvider: referenceTime, + }) + log.Info("This is an info message") +} diff --git a/log/logwriter/color_converter.go b/log/logwriter/color_converter.go new file mode 100644 index 000000000..11e51002e --- /dev/null +++ b/log/logwriter/color_converter.go @@ -0,0 +1,70 @@ +package logwriter + +import ( + "regexp" + "strconv" + "strings" + "unicode" + + "github.com/bitrise-io/bitrise/log/corelog" +) + +var ansiEscapeCodeToLevel = map[corelog.ANSIColorCode]corelog.Level{ + corelog.RedCode: corelog.ErrorLevel, + corelog.YellowCode: corelog.WarnLevel, + corelog.BlueCode: corelog.InfoLevel, + corelog.GreenCode: corelog.DoneLevel, + corelog.MagentaCode: corelog.DebugLevel, +} + +// convertColoredString determines the log level of the given message and removes related ANSI escape codes from it. +// Messages without a log level are returned untouched. +// A message is considered a message with a log level if: +// - starts with a color code +// - the first trailing non-whitespace characters have to be part of the reset-color code +// - contains exactly one color and reset code pair. +func convertColoredString(message string) (corelog.Level, string) { + // We need to remove all the possible noise from the end as we need remove the reset ansi code from the end + trimmedMessage := strings.TrimRightFunc(message, unicode.IsSpace) + + // If the message has more than one color then let the website do the coloring and do not modify the message + if hasMoreThanOneColor(trimmedMessage) { + return corelog.NormalLevel, message + } + + // Some messages have the starting color but do not have the reset code at the end. Ignore these. + if !strings.HasSuffix(trimmedMessage, string(corelog.ResetCode)) { + return corelog.NormalLevel, message + } + + for code, level := range ansiEscapeCodeToLevel { + if strings.HasPrefix(message, string(code)) { + message = strings.TrimPrefix(message, string(code)) + message = strings.Replace(message, string(corelog.ResetCode), "", 1) + return level, message + } + } + + return corelog.NormalLevel, message +} + +func hasMoreThanOneColor(message string) bool { + r, err := regexp.Compile(`(\\u001b)|(\\x1b)\[.*?m`) + if err != nil { + return true + } + + // The message has to be converted back to ascii characters otherwise the regex for the ansi code will not match. + matches := r.FindAllString(strconv.QuoteToASCII(message), -1) + + var filteredMatches []string + for _, match := range matches { + // In this scenario the reset color does not count as a color so the additional removal. The Go regexp package + // does not support the negative look-ahead which could ignore certain things right in the regexp. + if !strings.Contains(match, "[0m") { + filteredMatches = append(filteredMatches, match) + } + } + + return len(filteredMatches) > 1 +} diff --git a/log/logwriter/color_converter_test.go b/log/logwriter/color_converter_test.go new file mode 100644 index 000000000..083dd2b4f --- /dev/null +++ b/log/logwriter/color_converter_test.go @@ -0,0 +1,87 @@ +package logwriter + +import ( + "testing" + + "github.com/bitrise-io/bitrise/log/corelog" + "github.com/stretchr/testify/assert" +) + +func Test_converterConversion(t *testing.T) { + tests := []struct { + name string + message string + expectedLevel corelog.Level + expectedMessage string + }{ + { + name: "Normal message without a color literal", + message: "This is a normal message without a color literal\n", + expectedLevel: corelog.NormalLevel, + expectedMessage: "This is a normal message without a color literal\n", + }, + { + name: "Error message", + message: "\u001B[31;1mThis is an error\u001B[0m", + expectedLevel: corelog.ErrorLevel, + expectedMessage: "This is an error", + }, + { + name: "Warn message", + message: "\u001B[33;1mThis is a warning\u001B[0m", + expectedLevel: corelog.WarnLevel, + expectedMessage: "This is a warning", + }, + { + name: "Info message", + message: "\u001B[34;1mThis is an Info\u001B[0m", + expectedLevel: corelog.InfoLevel, + expectedMessage: "This is an Info", + }, + { + name: "Done message", + message: "\u001B[32;1mThis is a done message\u001B[0m", + expectedLevel: corelog.DoneLevel, + expectedMessage: "This is a done message", + }, + { + name: "Debug message", + message: "\u001B[35;1mThis is a debug message\u001B[0m", + expectedLevel: corelog.DebugLevel, + expectedMessage: "This is a debug message", + }, + { + name: "Error message with whitespaces at the end", + message: "\u001B[31;1mLast error\u001B[0m \n", + expectedLevel: corelog.ErrorLevel, + expectedMessage: "Last error \n", + }, + { + name: "Error message with whitespaces at the beginning", + message: " \u001B[31;1mLast error\u001B[0m \n", + expectedLevel: corelog.NormalLevel, + expectedMessage: " \u001B[31;1mLast error\u001B[0m \n", + }, + { + name: "Error message without a closing color literal", + message: "\u001B[31;1mAnother error\n", + expectedLevel: corelog.NormalLevel, + expectedMessage: "\u001B[31;1mAnother error\n", + }, + { + name: "Info message with multiple embedded colors", + message: "\u001B[34;1mThis is \u001B[33;1mmulti color \u001B[31;1mInfo message\u001B[0m", + expectedLevel: corelog.NormalLevel, + expectedMessage: "\u001B[34;1mThis is \u001B[33;1mmulti color \u001B[31;1mInfo message\u001B[0m", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + level, message := convertColoredString(tt.message) + + assert.Equal(t, tt.expectedLevel, level) + assert.Equal(t, tt.expectedMessage, message) + }) + } +} diff --git a/log/logwriter/writer.go b/log/logwriter/writer.go new file mode 100644 index 000000000..fd0351c11 --- /dev/null +++ b/log/logwriter/writer.go @@ -0,0 +1,23 @@ +package logwriter + +import ( + "github.com/bitrise-io/bitrise/log" +) + +// LogWriter ... +type LogWriter struct { + logger log.Logger +} + +// NewLogWriter ... +func NewLogWriter(logger log.Logger) LogWriter { + return LogWriter{ + logger: logger, + } +} + +func (w LogWriter) Write(p []byte) (n int, err error) { + level, message := convertColoredString(string(p)) + w.logger.LogMessage(message, level) + return len(p), nil +} diff --git a/log/logwriter/writer_test.go b/log/logwriter/writer_test.go new file mode 100644 index 000000000..a8b1a9e85 --- /dev/null +++ b/log/logwriter/writer_test.go @@ -0,0 +1,85 @@ +package logwriter_test + +import ( + "bytes" + "os" + "os/exec" + "testing" + "time" + + "github.com/bitrise-io/bitrise/log" + "github.com/bitrise-io/bitrise/log/logwriter" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func referenceTime() time.Time { + return time.Date(2022, 1, 1, 1, 1, 1, 0, time.UTC) +} + +func Test_GivenWriter_WhenStdoutIsUsed_ThenCapturesTheOutput(t *testing.T) { + tests := []struct { + name string + producer log.Producer + loggerType log.LoggerType + message string + expectedMessage string + }{ + { + name: "ClI console log", + producer: log.BitriseCLI, + loggerType: log.ConsoleLogger, + message: "Test message", + expectedMessage: "Test message", + }, + { + name: "Step JSON log", + producer: log.BitriseCLI, + loggerType: log.JSONLogger, + message: "Test message", + expectedMessage: `{"timestamp":"2022-01-01T01:01:01Z","type":"log","producer":"bitrise_cli","level":"normal","message":"Test message"}` + "\n", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + var buf bytes.Buffer + + opts := log.LoggerOpts{ + LoggerType: tt.loggerType, + Producer: tt.producer, + ConsoleLoggerOpts: log.ConsoleLoggerOpts{}, + DebugLogEnabled: true, + Writer: &buf, + TimeProvider: referenceTime, + } + logger := log.NewLogger(opts) + writer := logwriter.NewLogWriter(logger) + + b := []byte(tt.message) + + _, err := writer.Write(b) + assert.NoError(t, err) + require.Equal(t, tt.expectedMessage, buf.String()) + }) + } +} + +func ExampleNewLogWriter() { + opts := log.LoggerOpts{ + LoggerType: log.JSONLogger, + Producer: log.BitriseCLI, + ConsoleLoggerOpts: log.ConsoleLoggerOpts{}, + DebugLogEnabled: true, + Writer: os.Stdout, + TimeProvider: referenceTime, + } + logger := log.NewLogger(opts) + writer := logwriter.NewLogWriter(logger) + cmd := exec.Command("echo", "test") + cmd.Stdout = writer + if err := cmd.Run(); err != nil { + panic(err) + } + // Output: {"timestamp":"2022-01-01T01:01:01Z","type":"log","producer":"bitrise_cli","level":"normal","message":"test\n"} +} diff --git a/output/output.go b/output/output.go index ae703e619..ac2b066bb 100644 --- a/output/output.go +++ b/output/output.go @@ -6,7 +6,7 @@ import ( "gopkg.in/yaml.v2" - log "github.com/sirupsen/logrus" + "github.com/bitrise-io/bitrise/log" "github.com/urfave/cli" ) @@ -50,14 +50,14 @@ func Print(outModel interface{}, format string) { log.Errorf("[.print] ERROR: %s", err) return } - fmt.Printf("%s\n", serBytes) + log.Printf("%s", serBytes) case FormatYML: serBytes, err := yaml.Marshal(outModel) if err != nil { log.Errorf("[output.print] ERROR: %s", err) return } - fmt.Printf("%s\n", serBytes) + log.Printf("%s", serBytes) default: log.Errorf("[output.print] Invalid output format: %s", format) } diff --git a/plugins/install.go b/plugins/install.go index 2675fb235..6ceec6dc8 100644 --- a/plugins/install.go +++ b/plugins/install.go @@ -9,8 +9,8 @@ import ( "path/filepath" "strings" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/go-utils/command" - "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/pathutil" "github.com/bitrise-io/go-utils/progress" "github.com/bitrise-io/go-utils/sliceutil" diff --git a/plugins/paths.go b/plugins/paths.go index 6ac1e327a..a9b6ff8c1 100644 --- a/plugins/paths.go +++ b/plugins/paths.go @@ -8,7 +8,6 @@ import ( "github.com/bitrise-io/bitrise/configs" "github.com/bitrise-io/go-utils/fileutil" - "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/pathutil" ver "github.com/hashicorp/go-version" ) @@ -167,7 +166,7 @@ func GetPluginExecutablePath(name string) (string, bool, error) { func InitPaths() error { // Plugins dir if err := configs.EnsureBitriseConfigDirExists(); err != nil { - log.Errorf("Failed to ensure bitrise configs dir, err: %s", err) + return fmt.Errorf("failed to ensure bitrise configs dir, err: %s", err) } bitriseDir := configs.GetBitriseHomeDirPath() diff --git a/plugins/run.go b/plugins/run.go index 0e1a16e78..f09dbdec8 100644 --- a/plugins/run.go +++ b/plugins/run.go @@ -1,17 +1,16 @@ package plugins import ( - "fmt" "os" "path/filepath" "strings" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" + "github.com/bitrise-io/bitrise/log/logwriter" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/tools" "github.com/bitrise-io/bitrise/version" - "github.com/bitrise-io/go-utils/log" - flog "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/pathutil" ) @@ -76,11 +75,11 @@ func RunPluginByCommand(plugin Plugin, args []string) error { // PrintPluginUpdateInfos ... func PrintPluginUpdateInfos(newVersion string, plugin Plugin) { - flog.Warnf("") - flog.Warnf("New version (%s) of plugin (%s) available", newVersion, plugin.Name) - flog.Printf("Run command to update plugin:") - fmt.Println() - flog.Donef("$ bitrise plugin update %s", plugin.Name) + log.Warnf("") + log.Warnf("New version (%s) of plugin (%s) available", newVersion, plugin.Name) + log.Printf("Run command to update plugin:") + log.Print() + log.Donef("$ bitrise plugin update %s", plugin.Name) } func runPlugin(plugin Plugin, args []string, envs PluginConfig, input []byte) error { @@ -99,7 +98,7 @@ func runPlugin(plugin Plugin, args []string, envs PluginConfig, input []byte) er return err } - fmt.Println() + log.Print() } // Append common data to plugin iputs @@ -153,7 +152,21 @@ func runPlugin(plugin Plugin, args []string, envs PluginConfig, input []byte) er cmd = append([]string{"bash", pluginExecutable}, args...) } - if _, err := tools.EnvmanRun(pluginEnvstorePath, "", cmd, -1, -1, nil, input); err != nil { + logger := log.NewLogger(log.GetGlobalLoggerOpts()) + logWriter := logwriter.NewLogWriter(logger) + + _, err = tools.EnvmanRun( + pluginEnvstorePath, + "", + cmd, + -1, + -1, + nil, + input, + &logWriter, + &logWriter) + + if err != nil { return err } diff --git a/toolkits/command_runner.go b/toolkits/command_runner.go index b4e40b9c9..5df038e54 100644 --- a/toolkits/command_runner.go +++ b/toolkits/command_runner.go @@ -3,9 +3,9 @@ package toolkits import ( "fmt" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/go-utils/command" "github.com/bitrise-io/go-utils/errorutil" - log "github.com/sirupsen/logrus" ) // commandRunner ... diff --git a/toolkits/golang.go b/toolkits/golang.go index 7e5251aeb..549ee4aeb 100644 --- a/toolkits/golang.go +++ b/toolkits/golang.go @@ -11,6 +11,7 @@ import ( "time" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/models" "github.com/bitrise-io/bitrise/tools" "github.com/bitrise-io/bitrise/utils" @@ -21,7 +22,6 @@ import ( "github.com/bitrise-io/go-utils/versions" "github.com/bitrise-io/gows/gows" stepmanModels "github.com/bitrise-io/stepman/models" - log "github.com/sirupsen/logrus" ) // === Base Toolkit struct === @@ -237,14 +237,14 @@ func (toolkit GoToolkit) Install() error { return fmt.Errorf("Failed to download toolkit (%s), error: %s", downloadURL, downloadErr) } - fmt.Println("=> Installing ...") + log.Print("=> Installing ...") if err := installGoTar(goArchiveDownloadPath); err != nil { return fmt.Errorf("Failed to install Go toolkit, error: %s", err) } if err := os.Remove(goArchiveDownloadPath); err != nil { return fmt.Errorf("Failed to remove the downloaded Go archive (path: %s), error: %s", goArchiveDownloadPath, err) } - fmt.Println("=> Installing [DONE]") + log.Print("=> Installing [DONE]") return nil } diff --git a/tools/filterwriter/filterwriter.go b/tools/filterwriter/filterwriter.go index f921cdb50..c22190df9 100644 --- a/tools/filterwriter/filterwriter.go +++ b/tools/filterwriter/filterwriter.go @@ -8,7 +8,7 @@ import ( "sync" "time" - "github.com/bitrise-io/go-utils/log" + "github.com/bitrise-io/bitrise/log" ) // RedactStr ... diff --git a/tools/hangdetector/hang_detector.go b/tools/hangdetector/hang_detector.go index c053fc9d0..464b00395 100644 --- a/tools/hangdetector/hang_detector.go +++ b/tools/hangdetector/hang_detector.go @@ -5,7 +5,7 @@ import ( "sync/atomic" "time" - "github.com/bitrise-io/go-utils/log" + "github.com/bitrise-io/bitrise/log" ) // HangDetector ... @@ -47,6 +47,10 @@ func newHangDetector(ticker Ticker, tickLimit, heartbeatAtTick uint64) HangDetec // Start ... func (h *hangDetector) Start() { + opts := log.GetGlobalLoggerOpts() + opts.ConsoleLoggerOpts.Timestamp = true + log := log.NewLogger(opts) + if h.outWriter == nil { panic("Output is not set") } @@ -58,7 +62,7 @@ func (h *hangDetector) Start() { { count := atomic.AddUint64(&h.ticks, 1) if count == h.heartbeatAtTick { - log.TPrintf("No output received for a while. Bitrise CLI is still active.") + log.Printf("No output received for a while. Bitrise CLI is still active.") } if count >= h.tickLimit { h.notificationC <- true diff --git a/tools/timeoutcmd/timeoutcmd.go b/tools/timeoutcmd/timeoutcmd.go index 0bfe83f01..7b9120b60 100644 --- a/tools/timeoutcmd/timeoutcmd.go +++ b/tools/timeoutcmd/timeoutcmd.go @@ -8,8 +8,8 @@ import ( "syscall" "time" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/tools/hangdetector" - "github.com/bitrise-io/go-utils/log" ) // Command controls the command run. diff --git a/tools/tools.go b/tools/tools.go index ffa518d22..722fa13fa 100644 --- a/tools/tools.go +++ b/tools/tools.go @@ -12,6 +12,7 @@ import ( "time" "github.com/bitrise-io/bitrise/configs" + "github.com/bitrise-io/bitrise/log" "github.com/bitrise-io/bitrise/tools/errorfinder" "github.com/bitrise-io/bitrise/tools/filterwriter" "github.com/bitrise-io/bitrise/tools/timeoutcmd" @@ -19,11 +20,9 @@ import ( envmanEnv "github.com/bitrise-io/envman/env" envmanModels "github.com/bitrise-io/envman/models" "github.com/bitrise-io/go-utils/command" - utilslog "github.com/bitrise-io/go-utils/log" "github.com/bitrise-io/go-utils/pathutil" stepman "github.com/bitrise-io/stepman/cli" stepmanModels "github.com/bitrise-io/stepman/models" - log "github.com/sirupsen/logrus" "golang.org/x/sys/unix" ) @@ -137,35 +136,37 @@ func InstallFromURL(toolBinName, downloadURL string) error { // StepmanSetup ... func StepmanSetup(collection string) error { - return stepman.Setup(collection, "", utilslog.NewDefaultLogger(false)) + log := log.NewLogger(log.GetGlobalLoggerOpts()) + return stepman.Setup(collection, "", log) } // StepmanUpdate ... func StepmanUpdate(collection string) error { - return stepman.UpdateLibrary(collection, utilslog.NewDefaultLogger(false)) + log := log.NewLogger(log.GetGlobalLoggerOpts()) + return stepman.UpdateLibrary(collection, log) } // StepmanActivate ... func StepmanActivate(collection, stepID, stepVersion, dir, ymlPth string) error { - return stepman.Activate(collection, stepID, stepVersion, dir, ymlPth, false, utilslog.NewDefaultLogger(false)) + log := log.NewLogger(log.GetGlobalLoggerOpts()) + return stepman.Activate(collection, stepID, stepVersion, dir, ymlPth, false, log) } // StepmanStepInfo ... func StepmanStepInfo(collection, stepID, stepVersion string) (stepmanModels.StepInfoModel, error) { - return stepman.QueryStepInfo(collection, stepID, stepVersion, utilslog.NewDefaultLogger(false)) + log := log.NewLogger(log.GetGlobalLoggerOpts()) + return stepman.QueryStepInfo(collection, stepID, stepVersion, log) } // StepmanRawStepList ... func StepmanRawStepList(collection string) (string, error) { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "step-list", "--collection", collection, "--format", "raw"} + args := []string{"--loglevel", logLevel(), "step-list", "--collection", collection, "--format", "raw"} return command.RunCommandAndReturnCombinedStdoutAndStderr("stepman", args...) } // StepmanJSONStepList ... func StepmanJSONStepList(collection string) (string, error) { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "step-list", "--collection", collection, "--format", "json"} + args := []string{"--loglevel", logLevel(), "step-list", "--collection", collection, "--format", "json"} var outBuffer bytes.Buffer var errBuffer bytes.Buffer @@ -182,36 +183,31 @@ func StepmanJSONStepList(collection string) (string, error) { // StepmanShare ... func StepmanShare() error { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "share", "--toolmode"} + args := []string{"--loglevel", logLevel(), "share", "--toolmode"} return command.RunCommand("stepman", args...) } // StepmanShareAudit ... func StepmanShareAudit() error { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "share", "audit", "--toolmode"} + args := []string{"--loglevel", logLevel(), "share", "audit", "--toolmode"} return command.RunCommand("stepman", args...) } // StepmanShareCreate ... func StepmanShareCreate(tag, git, stepID string) error { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "share", "create", "--tag", tag, "--git", git, "--stepid", stepID, "--toolmode"} + args := []string{"--loglevel", logLevel(), "share", "create", "--tag", tag, "--git", git, "--stepid", stepID, "--toolmode"} return command.RunCommand("stepman", args...) } // StepmanShareFinish ... func StepmanShareFinish() error { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "share", "finish", "--toolmode"} + args := []string{"--loglevel", logLevel(), "share", "finish", "--toolmode"} return command.RunCommand("stepman", args...) } // StepmanShareStart ... func StepmanShareStart(collection string) error { - logLevel := log.GetLevel().String() - args := []string{"--loglevel", logLevel, "share", "start", "--collection", collection, "--toolmode"} + args := []string{"--loglevel", logLevel(), "share", "start", "--collection", collection, "--toolmode"} return command.RunCommand("stepman", args...) } @@ -281,6 +277,8 @@ func EnvmanRun(envStorePth, noOutputTimeout time.Duration, secrets []string, stdInPayload []byte, + stdout io.Writer, + stderr io.Writer, ) (int, error) { envs, err := envman.ReadAndEvaluateEnvs(envStorePth, &envmanEnv.DefaultEnvironmentSource{}) if err != nil { @@ -294,10 +292,10 @@ func EnvmanRun(envStorePth, var fw *filterwriter.Writer if !configs.IsSecretFiltering { - outWriter = errorFinder.WrapWriter(os.Stdout) - errWriter = errorFinder.WrapWriter(os.Stderr) + outWriter = errorFinder.WrapWriter(stdout) + errWriter = errorFinder.WrapWriter(stderr) } else { - fw = filterwriter.New(secrets, os.Stdout) + fw = filterwriter.New(secrets, stdout) outWriter = errorFinder.WrapWriter(fw) errWriter = outWriter } @@ -398,3 +396,10 @@ func IsBuiltInFlagTypeKey(env string) bool { return false } } + +func logLevel() string { + if configs.IsDebugMode { + return "debug" + } + return "info" +} diff --git a/vendor/github.com/bitrise-io/go-utils/v2/analytics/client.go b/vendor/github.com/bitrise-io/go-utils/v2/analytics/client.go index b646f3443..70e0af290 100644 --- a/vendor/github.com/bitrise-io/go-utils/v2/analytics/client.go +++ b/vendor/github.com/bitrise-io/go-utils/v2/analytics/client.go @@ -6,8 +6,8 @@ import ( "net/http" "time" - "github.com/bitrise-io/go-utils/retry" "github.com/bitrise-io/go-utils/v2/log" + "github.com/bitrise-io/go-utils/v2/retryhttp" ) const trackEndpoint = "https://bitrise-step-analytics.herokuapp.com/track" @@ -26,7 +26,7 @@ type client struct { // NewDefaultClient ... func NewDefaultClient(logger log.Logger, timeout time.Duration) Client { - httpClient := retry.NewHTTPClient().StandardClient() + httpClient := retryhttp.NewClient(logger).StandardClient() httpClient.Timeout = timeout return NewClient(httpClient, trackEndpoint, logger, timeout) } diff --git a/vendor/github.com/bitrise-io/go-utils/v2/log/colorstring/colorstring.go b/vendor/github.com/bitrise-io/go-utils/v2/log/colorstring/colorstring.go new file mode 100644 index 000000000..5401b91d3 --- /dev/null +++ b/vendor/github.com/bitrise-io/go-utils/v2/log/colorstring/colorstring.go @@ -0,0 +1,111 @@ +package colorstring + +// ANSI color escape sequences + +import ( + "fmt" +) + +// Color ... +type Color string + +const ( + blackColor Color = "\x1b[30;1m" + redColor Color = "\x1b[31;1m" + greenColor Color = "\x1b[32;1m" + yellowColor Color = "\x1b[33;1m" + blueColor Color = "\x1b[34;1m" + magentaColor Color = "\x1b[35;1m" + cyanColor Color = "\x1b[36;1m" + resetColor Color = "\x1b[0m" +) + +// ColorFunc ... +type ColorFunc func(a ...interface{}) string + +func addColor(color Color, msg string) string { + return string(color) + msg + string(resetColor) +} + +// NoColor ... +func NoColor(a ...interface{}) string { + return fmt.Sprint(a...) +} + +// Black ... +func Black(a ...interface{}) string { + return addColor(blackColor, fmt.Sprint(a...)) +} + +// Red ... +func Red(a ...interface{}) string { + return addColor(redColor, fmt.Sprint(a...)) +} + +// Green ... +func Green(a ...interface{}) string { + return addColor(greenColor, fmt.Sprint(a...)) +} + +// Yellow ... +func Yellow(a ...interface{}) string { + return addColor(yellowColor, fmt.Sprint(a...)) +} + +// Blue ... +func Blue(a ...interface{}) string { + return addColor(blueColor, fmt.Sprint(a...)) +} + +// Magenta ... +func Magenta(a ...interface{}) string { + return addColor(magentaColor, fmt.Sprint(a...)) +} + +// Cyan ... +func Cyan(a ...interface{}) string { + return addColor(cyanColor, fmt.Sprint(a...)) +} + +// ColorfFunc ... +type ColorfFunc func(format string, a ...interface{}) string + +// NoColorf ... +func NoColorf(format string, a ...interface{}) string { + return NoColor(fmt.Sprintf(format, a...)) +} + +// Blackf ... +func Blackf(format string, a ...interface{}) string { + return Black(fmt.Sprintf(format, a...)) +} + +// Redf ... +func Redf(format string, a ...interface{}) string { + return Red(fmt.Sprintf(format, a...)) +} + +// Greenf ... +func Greenf(format string, a ...interface{}) string { + return Green(fmt.Sprintf(format, a...)) +} + +// Yellowf ... +func Yellowf(format string, a ...interface{}) string { + return Yellow(fmt.Sprintf(format, a...)) +} + +// Bluef ... +func Bluef(format string, a ...interface{}) string { + return Blue(fmt.Sprintf(format, a...)) +} + +// Magentaf ... +func Magentaf(format string, a ...interface{}) string { + return Magenta(fmt.Sprintf(format, a...)) +} + +// Cyanf ... +func Cyanf(format string, a ...interface{}) string { + return Cyan(fmt.Sprintf(format, a...)) +} diff --git a/vendor/github.com/bitrise-io/go-utils/v2/log/severity.go b/vendor/github.com/bitrise-io/go-utils/v2/log/severity.go index fc1fc96a6..02a143166 100644 --- a/vendor/github.com/bitrise-io/go-utils/v2/log/severity.go +++ b/vendor/github.com/bitrise-io/go-utils/v2/log/severity.go @@ -1,6 +1,6 @@ package log -import "github.com/bitrise-io/go-utils/colorstring" +import "github.com/bitrise-io/go-utils/v2/log/colorstring" // Severity ... type Severity uint8 diff --git a/vendor/github.com/bitrise-io/go-utils/v2/retryhttp/retryhttp.go b/vendor/github.com/bitrise-io/go-utils/v2/retryhttp/retryhttp.go new file mode 100644 index 000000000..5169ac7d1 --- /dev/null +++ b/vendor/github.com/bitrise-io/go-utils/v2/retryhttp/retryhttp.go @@ -0,0 +1,25 @@ +package retryhttp + +import ( + "github.com/bitrise-io/go-utils/v2/log" + "github.com/hashicorp/go-retryablehttp" +) + +// NewClient returns a retryable HTTP client with common defaults +func NewClient(logger log.Logger) *retryablehttp.Client { + client := retryablehttp.NewClient() + client.Logger = &httpLogAdaptor{logger: logger} + client.ErrorHandler = retryablehttp.PassthroughErrorHandler + + return client +} + +// httpLogAdaptor adapts the retryablehttp.Logger interface to the go-utils logger. +type httpLogAdaptor struct { + logger log.Logger +} + +// Printf implements the retryablehttp.Logger interface +func (a *httpLogAdaptor) Printf(fmtStr string, vars ...interface{}) { + a.logger.Debugf(fmtStr, vars...) +} diff --git a/vendor/github.com/hashicorp/go-retryablehttp/README.md b/vendor/github.com/hashicorp/go-retryablehttp/README.md index 8943becf1..09f5eaf22 100644 --- a/vendor/github.com/hashicorp/go-retryablehttp/README.md +++ b/vendor/github.com/hashicorp/go-retryablehttp/README.md @@ -45,6 +45,25 @@ The returned response object is an `*http.Response`, the same thing you would usually get from `net/http`. Had the request failed one or more times, the above call would block and retry with exponential backoff. +## Retrying cases that fail after a seeming success + +It's possible for a request to succeed in the sense that the expected response headers are received, but then to encounter network-level errors while reading the response body. In go-retryablehttp's most basic usage, this error would not be retryable, due to the out-of-band handling of the response body. In some cases it may be desirable to handle the response body as part of the retryable operation. + +A toy example (which will retry the full request and succeed on the second attempt) is shown below: + +```go +c := retryablehttp.NewClient() +r := retryablehttp.NewRequest("GET", "://foo", nil) +handlerShouldRetry := true +r.SetResponseHandler(func(*http.Response) error { + if !handlerShouldRetry { + return nil + } + handlerShouldRetry = false + return errors.New("retryable error") +}) +``` + ## Getting a stdlib `*http.Client` with retries It's possible to convert a `*retryablehttp.Client` directly to a `*http.Client`. diff --git a/vendor/github.com/hashicorp/go-retryablehttp/client.go b/vendor/github.com/hashicorp/go-retryablehttp/client.go index adbdd92e3..57116e960 100644 --- a/vendor/github.com/hashicorp/go-retryablehttp/client.go +++ b/vendor/github.com/hashicorp/go-retryablehttp/client.go @@ -69,11 +69,21 @@ var ( // scheme specified in the URL is invalid. This error isn't typed // specifically so we resort to matching on the error string. schemeErrorRe = regexp.MustCompile(`unsupported protocol scheme`) + + // A regular expression to match the error returned by net/http when the + // TLS certificate is not trusted. This error isn't typed + // specifically so we resort to matching on the error string. + notTrustedErrorRe = regexp.MustCompile(`certificate is not trusted`) ) // ReaderFunc is the type of function that can be given natively to NewRequest type ReaderFunc func() (io.Reader, error) +// ResponseHandlerFunc is a type of function that takes in a Response, and does something with it. +// It only runs if the initial part of the request was successful. +// If an error is returned, the client's retry policy will be used to determine whether to retry the whole request. +type ResponseHandlerFunc func(*http.Response) error + // LenReader is an interface implemented by many in-memory io.Reader's. Used // for automatically sending the right Content-Length header when possible. type LenReader interface { @@ -86,6 +96,8 @@ type Request struct { // used to rewind the request data in between retries. body ReaderFunc + responseHandler ResponseHandlerFunc + // Embed an HTTP request directly. This makes a *Request act exactly // like an *http.Request so that all meta methods are supported. *http.Request @@ -94,8 +106,16 @@ type Request struct { // WithContext returns wrapped Request with a shallow copy of underlying *http.Request // with its context changed to ctx. The provided ctx must be non-nil. func (r *Request) WithContext(ctx context.Context) *Request { - r.Request = r.Request.WithContext(ctx) - return r + return &Request{ + body: r.body, + responseHandler: r.responseHandler, + Request: r.Request.WithContext(ctx), + } +} + +// SetResponseHandler allows setting the response handler. +func (r *Request) SetResponseHandler(fn ResponseHandlerFunc) { + r.responseHandler = fn } // BodyBytes allows accessing the request body. It is an analogue to @@ -252,23 +272,31 @@ func FromRequest(r *http.Request) (*Request, error) { return nil, err } // Could assert contentLength == r.ContentLength - return &Request{bodyReader, r}, nil + return &Request{body: bodyReader, Request: r}, nil } // NewRequest creates a new wrapped request. func NewRequest(method, url string, rawBody interface{}) (*Request, error) { + return NewRequestWithContext(context.Background(), method, url, rawBody) +} + +// NewRequestWithContext creates a new wrapped request with the provided context. +// +// The context controls the entire lifetime of a request and its response: +// obtaining a connection, sending the request, and reading the response headers and body. +func NewRequestWithContext(ctx context.Context, method, url string, rawBody interface{}) (*Request, error) { bodyReader, contentLength, err := getBodyReaderAndContentLength(rawBody) if err != nil { return nil, err } - httpReq, err := http.NewRequest(method, url, nil) + httpReq, err := http.NewRequestWithContext(ctx, method, url, nil) if err != nil { return nil, err } httpReq.ContentLength = contentLength - return &Request{bodyReader, httpReq}, nil + return &Request{body: bodyReader, Request: httpReq}, nil } // Logger interface allows to use other loggers than @@ -435,6 +463,9 @@ func baseRetryPolicy(resp *http.Response, err error) (bool, error) { } // Don't retry if the error was due to TLS cert verification failure. + if notTrustedErrorRe.MatchString(v.Error()) { + return false, v + } if _, ok := v.Err.(x509.UnknownAuthorityError); ok { return false, v } @@ -455,7 +486,7 @@ func baseRetryPolicy(resp *http.Response, err error) (bool, error) { // the server time to recover, as 500's are typically not permanent // errors and may relate to outages on the server side. This will catch // invalid response codes as well, like 0 and 999. - if resp.StatusCode == 0 || (resp.StatusCode >= 500 && resp.StatusCode != 501) { + if resp.StatusCode == 0 || (resp.StatusCode >= 500 && resp.StatusCode != http.StatusNotImplemented) { return true, fmt.Errorf("unexpected HTTP status %s", resp.Status) } @@ -555,13 +586,12 @@ func (c *Client) Do(req *Request) (*http.Response, error) { var resp *http.Response var attempt int var shouldRetry bool - var doErr, checkErr error + var doErr, respErr, checkErr error for i := 0; ; i++ { + doErr, respErr = nil, nil attempt++ - var code int // HTTP response code - // Always rewind the request body when non-nil. if req.body != nil { body, err := req.body() @@ -589,19 +619,24 @@ func (c *Client) Do(req *Request) (*http.Response, error) { // Attempt the request resp, doErr = c.HTTPClient.Do(req.Request) - if resp != nil { - code = resp.StatusCode - } // Check if we should continue with retries. shouldRetry, checkErr = c.CheckRetry(req.Context(), resp, doErr) + if !shouldRetry && doErr == nil && req.responseHandler != nil { + respErr = req.responseHandler(resp) + shouldRetry, checkErr = c.CheckRetry(req.Context(), resp, respErr) + } - if doErr != nil { + err := doErr + if respErr != nil { + err = respErr + } + if err != nil { switch v := logger.(type) { case LeveledLogger: - v.Error("request failed", "error", doErr, "method", req.Method, "url", req.URL) + v.Error("request failed", "error", err, "method", req.Method, "url", req.URL) case Logger: - v.Printf("[ERR] %s %s request failed: %v", req.Method, req.URL, doErr) + v.Printf("[ERR] %s %s request failed: %v", req.Method, req.URL, err) } } else { // Call this here to maintain the behavior of logging all requests, @@ -636,11 +671,11 @@ func (c *Client) Do(req *Request) (*http.Response, error) { } wait := c.Backoff(c.RetryWaitMin, c.RetryWaitMax, i, resp) - desc := fmt.Sprintf("%s %s", req.Method, req.URL) - if code > 0 { - desc = fmt.Sprintf("%s (status: %d)", desc, code) - } if logger != nil { + desc := fmt.Sprintf("%s %s", req.Method, req.URL) + if resp != nil { + desc = fmt.Sprintf("%s (status: %d)", desc, resp.StatusCode) + } switch v := logger.(type) { case LeveledLogger: v.Debug("retrying request", "request", desc, "timeout", wait, "remaining", remain) @@ -648,11 +683,13 @@ func (c *Client) Do(req *Request) (*http.Response, error) { v.Printf("[DEBUG] %s: retrying in %s (%d left)", desc, wait, remain) } } + timer := time.NewTimer(wait) select { case <-req.Context().Done(): + timer.Stop() c.HTTPClient.CloseIdleConnections() return nil, req.Context().Err() - case <-time.After(wait): + case <-timer.C: } // Make shallow copy of http Request so that we can modify its body @@ -662,15 +699,19 @@ func (c *Client) Do(req *Request) (*http.Response, error) { } // this is the closest we have to success criteria - if doErr == nil && checkErr == nil && !shouldRetry { + if doErr == nil && respErr == nil && checkErr == nil && !shouldRetry { return resp, nil } defer c.HTTPClient.CloseIdleConnections() - err := doErr + var err error if checkErr != nil { err = checkErr + } else if respErr != nil { + err = respErr + } else { + err = doErr } if c.ErrorHandler != nil { diff --git a/vendor/modules.txt b/vendor/modules.txt index d18b023d8..a325d5d9d 100644 --- a/vendor/modules.txt +++ b/vendor/modules.txt @@ -25,11 +25,13 @@ github.com/bitrise-io/go-utils/sliceutil github.com/bitrise-io/go-utils/stringutil github.com/bitrise-io/go-utils/urlutil github.com/bitrise-io/go-utils/versions -# github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.10 +# github.com/bitrise-io/go-utils/v2 v2.0.0-alpha.12.0.20221010132402-33be72261ded ## explicit github.com/bitrise-io/go-utils/v2/analytics github.com/bitrise-io/go-utils/v2/env github.com/bitrise-io/go-utils/v2/log +github.com/bitrise-io/go-utils/v2/log/colorstring +github.com/bitrise-io/go-utils/v2/retryhttp # github.com/bitrise-io/goinp v0.0.0-20211005113137-305e91b481f4 ## explicit github.com/bitrise-io/goinp/goinp @@ -51,7 +53,7 @@ github.com/davecgh/go-spew/spew github.com/gofrs/uuid # github.com/hashicorp/go-cleanhttp v0.5.2 github.com/hashicorp/go-cleanhttp -# github.com/hashicorp/go-retryablehttp v0.7.0 +# github.com/hashicorp/go-retryablehttp v0.7.1 github.com/hashicorp/go-retryablehttp # github.com/hashicorp/go-version v1.4.0 ## explicit @@ -66,7 +68,6 @@ github.com/russross/blackfriday/v2 ## explicit github.com/ryanuber/go-glob # github.com/sirupsen/logrus v1.8.1 -## explicit github.com/sirupsen/logrus # github.com/stretchr/testify v1.7.1 ## explicit