From bab4d3bf3d3e685942e39193f990850aa37794d7 Mon Sep 17 00:00:00 2001 From: Greg Soltis Date: Thu, 20 Apr 2023 11:58:50 -0700 Subject: [PATCH 1/5] Existing and error logs behavior --- .../monorepo_dependency_error/.gitignore | 3 + .../apps/my-app/package.json | 9 +++ .../apps/other-app/package.json | 9 +++ .../apps/some-lib/package.json | 6 ++ .../monorepo_dependency_error/package.json | 6 ++ .../monorepo_dependency_error/turbo.json | 9 +++ turborepo-tests/integration/tests/continue.t | 80 +++++++++++++++++++ 7 files changed, 122 insertions(+) create mode 100644 turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/.gitignore create mode 100644 turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/my-app/package.json create mode 100644 turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/other-app/package.json create mode 100644 turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/some-lib/package.json create mode 100644 turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/package.json create mode 100644 turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/turbo.json create mode 100644 turborepo-tests/integration/tests/continue.t diff --git a/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/.gitignore b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/.gitignore new file mode 100644 index 0000000000000..77af9fc60321d --- /dev/null +++ b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/.gitignore @@ -0,0 +1,3 @@ +node_modules/ +.turbo +.npmrc diff --git a/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/my-app/package.json b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/my-app/package.json new file mode 100644 index 0000000000000..acfc61307753d --- /dev/null +++ b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/my-app/package.json @@ -0,0 +1,9 @@ +{ + "name": "my-app", + "scripts": { + "build": "echo 'working'" + }, + "dependencies": { + "some-lib": "*" + } +} diff --git a/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/other-app/package.json b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/other-app/package.json new file mode 100644 index 0000000000000..1985ed79922d3 --- /dev/null +++ b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/other-app/package.json @@ -0,0 +1,9 @@ +{ + "name": "other-app", + "scripts": { + "build": "exit 3" + }, + "dependencies": { + "some-lib": "*" + } +} diff --git a/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/some-lib/package.json b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/some-lib/package.json new file mode 100644 index 0000000000000..496cb9f3627d9 --- /dev/null +++ b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/apps/some-lib/package.json @@ -0,0 +1,6 @@ +{ + "name": "some-lib", + "scripts": { + "build": "exit 2" + } +} diff --git a/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/package.json b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/package.json new file mode 100644 index 0000000000000..9557291c8197e --- /dev/null +++ b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/package.json @@ -0,0 +1,6 @@ +{ + "name": "monorepo", + "workspaces": [ + "apps/**" + ] +} diff --git a/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/turbo.json b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/turbo.json new file mode 100644 index 0000000000000..30922a61b1baf --- /dev/null +++ b/turborepo-tests/integration/tests/_fixtures/monorepo_dependency_error/turbo.json @@ -0,0 +1,9 @@ +{ + "$schema": "https://turbo.build/schema.json", + "pipeline": { + "build": { + "dependsOn": ["^build"], + "outputs": [] + } + } +} diff --git a/turborepo-tests/integration/tests/continue.t b/turborepo-tests/integration/tests/continue.t new file mode 100644 index 0000000000000..070092f33bd93 --- /dev/null +++ b/turborepo-tests/integration/tests/continue.t @@ -0,0 +1,80 @@ +Setup + $ . ${TESTDIR}/../../helpers/setup.sh + $ . ${TESTDIR}/_helpers/setup_monorepo.sh $(pwd) monorepo_dependency_error +Run without --continue + $ ${TURBO} build + \xe2\x80\xa2 Packages in scope: my-app, other-app, some-lib (esc) + \xe2\x80\xa2 Running build in 3 packages (esc) + \xe2\x80\xa2 Remote caching disabled (esc) + some-lib:build: cache miss, executing 3494007308f52ad6 + some-lib:build: + some-lib:build: > build + some-lib:build: > exit 2 + some-lib:build: + some-lib:build: npm ERR! Lifecycle script `build` failed with error: + some-lib:build: npm ERR! Error: command failed + some-lib:build: npm ERR! in workspace: some-lib + some-lib:build: npm ERR! at location: (.*)/apps/some-lib (re) + some-lib:build: ERROR: command finished with error: command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) + command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) + + Tasks: 0 successful, 1 total + Cached: 0 cached, 1 total + Time:\s*[\.0-9]+m?s (re) + + ERROR run failed: command exited (1) + [1] + +Run without --continue, and with only errors. Note differences from above + $ ${TURBO} build --output-logs=errors-only + \xe2\x80\xa2 Packages in scope: my-app, other-app, some-lib (esc) + \xe2\x80\xa2 Running build in 3 packages (esc) + \xe2\x80\xa2 Remote caching disabled (esc) + some-lib:build: ERROR: command finished with error: command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) + some-lib:build: + some-lib:build: > build + some-lib:build: > exit 2 + some-lib:build: + some-lib:build: npm ERR! Lifecycle script `build` failed with error: + some-lib:build: npm ERR! Error: command failed + some-lib:build: npm ERR! in workspace: some-lib + some-lib:build: npm ERR! at location: (.*)/apps/some-lib (re) + command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) + + Tasks: 0 successful, 1 total + Cached: 0 cached, 1 total + Time:\s*[\.0-9]+m?s (re) + + ERROR run failed: command exited (1) + [1] + +Run with --continue + $ ${TURBO} build --output-logs=errors-only --continue + \xe2\x80\xa2 Packages in scope: my-app, other-app, some-lib (esc) + \xe2\x80\xa2 Running build in 3 packages (esc) + \xe2\x80\xa2 Remote caching disabled (esc) + some-lib:build: command finished with error, but continuing... + some-lib:build: + some-lib:build: > build + some-lib:build: > exit 2 + some-lib:build: + some-lib:build: npm ERR! Lifecycle script `build` failed with error: + some-lib:build: npm ERR! Error: command failed + some-lib:build: npm ERR! in workspace: some-lib + some-lib:build: npm ERR! at location: (.*)/apps/some-lib (re) + other-app:build: command finished with error, but continuing... + other-app:build: + other-app:build: > build + other-app:build: > exit 3 + other-app:build: + other-app:build: npm ERR! Lifecycle script `build` failed with error: + other-app:build: npm ERR! Error: command failed + other-app:build: npm ERR! in workspace: other-app + other-app:build: npm ERR! at location: (.*)/apps/other-app (re) + + Tasks: 1 successful, 3 total + Cached: 0 cached, 3 total + Time:\s*[\.0-9]+m?s (re) + + ERROR run failed: command exited (1) + [1] From 08db9415323f6356e79edc4f3fe4eecb1b608c18 Mon Sep 17 00:00:00 2001 From: Greg Soltis Date: Thu, 20 Apr 2023 12:04:17 -0700 Subject: [PATCH 2/5] errors-only matches full logs output for a task error --- cli/internal/run/real_run.go | 5 ++--- cli/internal/runcache/runcache.go | 1 + turborepo-tests/integration/tests/continue.t | 11 +++++++---- 3 files changed, 10 insertions(+), 7 deletions(-) diff --git a/cli/internal/run/real_run.go b/cli/internal/run/real_run.go index b72c6f6ebb3c2..0b1c5a1b17331 100644 --- a/cli/internal/run/real_run.go +++ b/cli/internal/run/real_run.go @@ -381,6 +381,8 @@ func (ec *execContext) exec(ctx gocontext.Context, packageTask *nodes.PackageTas tracer(runsummary.TargetBuildFailed, err, nil) } + // If there was an error, flush the buffered output + taskCache.OnError(prefixedUI, progressLogger) progressLogger.Error(fmt.Sprintf("Error: command finished with error: %v", err)) if !ec.rs.Opts.runOpts.ContinueOnError { prefixedUI.Error(fmt.Sprintf("ERROR: command finished with error: %s", err)) @@ -391,9 +393,6 @@ func (ec *execContext) exec(ctx gocontext.Context, packageTask *nodes.PackageTas err = nil } - // If there was an error, flush the buffered output - taskCache.OnError(prefixedUI, progressLogger) - return taskExecutionSummary, err } diff --git a/cli/internal/runcache/runcache.go b/cli/internal/runcache/runcache.go index ba6145b7d9661..1355fb45eed5c 100644 --- a/cli/internal/runcache/runcache.go +++ b/cli/internal/runcache/runcache.go @@ -190,6 +190,7 @@ func (tc TaskCache) ReplayLogFile(prefixedUI *cli.PrefixedUi, progressLogger hcl // This is called if the task exited with an non-zero error code. func (tc TaskCache) OnError(terminal *cli.PrefixedUi, logger hclog.Logger) { if tc.taskOutputMode == util.ErrorTaskOutput { + terminal.Output(fmt.Sprintf("cache miss, executing %s", ui.Dim(tc.hash))) tc.ReplayLogFile(terminal, logger) } } diff --git a/turborepo-tests/integration/tests/continue.t b/turborepo-tests/integration/tests/continue.t index 070092f33bd93..625549d2fd848 100644 --- a/turborepo-tests/integration/tests/continue.t +++ b/turborepo-tests/integration/tests/continue.t @@ -25,12 +25,12 @@ Run without --continue ERROR run failed: command exited (1) [1] -Run without --continue, and with only errors. Note differences from above +Run without --continue, and with only errors. $ ${TURBO} build --output-logs=errors-only \xe2\x80\xa2 Packages in scope: my-app, other-app, some-lib (esc) \xe2\x80\xa2 Running build in 3 packages (esc) \xe2\x80\xa2 Remote caching disabled (esc) - some-lib:build: ERROR: command finished with error: command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) + some-lib:build: cache miss, executing 3494007308f52ad6 some-lib:build: some-lib:build: > build some-lib:build: > exit 2 @@ -39,6 +39,7 @@ Run without --continue, and with only errors. Note differences from above some-lib:build: npm ERR! Error: command failed some-lib:build: npm ERR! in workspace: some-lib some-lib:build: npm ERR! at location: (.*)/apps/some-lib (re) + some-lib:build: ERROR: command finished with error: command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) Tasks: 0 successful, 1 total @@ -53,7 +54,7 @@ Run with --continue \xe2\x80\xa2 Packages in scope: my-app, other-app, some-lib (esc) \xe2\x80\xa2 Running build in 3 packages (esc) \xe2\x80\xa2 Remote caching disabled (esc) - some-lib:build: command finished with error, but continuing... + some-lib:build: cache miss, executing 3494007308f52ad6 some-lib:build: some-lib:build: > build some-lib:build: > exit 2 @@ -62,7 +63,8 @@ Run with --continue some-lib:build: npm ERR! Error: command failed some-lib:build: npm ERR! in workspace: some-lib some-lib:build: npm ERR! at location: (.*)/apps/some-lib (re) - other-app:build: command finished with error, but continuing... + some-lib:build: command finished with error, but continuing... + other-app:build: cache miss, executing af6505fe5634a5f5 other-app:build: other-app:build: > build other-app:build: > exit 3 @@ -71,6 +73,7 @@ Run with --continue other-app:build: npm ERR! Error: command failed other-app:build: npm ERR! in workspace: other-app other-app:build: npm ERR! at location: (.*)/apps/other-app (re) + other-app:build: command finished with error, but continuing... Tasks: 1 successful, 3 total Cached: 0 cached, 3 total From 8327560cc888bad07117958cb843998c81fe922c Mon Sep 17 00:00:00 2001 From: Greg Soltis Date: Thu, 20 Apr 2023 14:30:25 -0700 Subject: [PATCH 3/5] Resume printing failed commands at the end of a run --- cli/internal/core/engine.go | 98 +++++++++++++++----- cli/internal/core/engine_test.go | 2 +- cli/internal/run/real_run.go | 6 +- turborepo-tests/integration/tests/continue.t | 2 + 4 files changed, 80 insertions(+), 28 deletions(-) diff --git a/cli/internal/core/engine.go b/cli/internal/core/engine.go index 7f08ea8ed7a35..a7940e22ad830 100644 --- a/cli/internal/core/engine.go +++ b/cli/internal/core/engine.go @@ -6,6 +6,7 @@ import ( "os" "sort" "strings" + "sync" "sync/atomic" "github.com/vercel/turbo/cli/internal/fs" @@ -72,40 +73,87 @@ type EngineExecutionOptions struct { Concurrency int } +// StopExecutionSentinel is used to return an error from a graph Walk that indicates that +// all further walking should stop. +type StopExecutionSentinel struct { + err error +} + +// StopExecution wraps the given error in a sentinel error indicating that +// graph traversal should stop. Note that this will stop all tasks, not just +// downstream tasks. +func StopExecution(reason error) *StopExecutionSentinel { + return &StopExecutionSentinel{ + err: reason, + } +} + +// Error implements error.Error for StopExecutionSentinel +func (se *StopExecutionSentinel) Error() string { + return fmt.Sprintf("Execution stopped due to error: %v", se.err) +} + // Execute executes the pipeline, constructing an internal task graph and walking it accordingly. func (e *Engine) Execute(visitor Visitor, opts EngineExecutionOptions) []error { var sema = util.NewSemaphore(opts.Concurrency) var errored int32 - return e.TaskGraph.Walk(func(v dag.Vertex) error { - // If something has already errored, short-circuit. - // There is a race here between concurrent tasks. However, if there is not a - // dependency edge between them, we are not required to have a strict order - // between them, so a failed task can fail to short-circuit a concurrent - // task that happened to be starting at the same time. - if atomic.LoadInt32(&errored) != 0 { - return nil - } - // Each vertex in the graph is a taskID (package#task format) - taskID := dag.VertexName(v) - // Always return if it is the root node - if strings.Contains(taskID, ROOT_NODE_NAME) { - return nil - } + // Returning an error from the Walk callback cancels downstream tasks, but not unrelated tasks. + // The behavior we want is to either cancel everything or nothing (--continue). So, we do our own + // error handling. Collect any errors that occur in "errors", and report them as the result of + // Execute. panic on any other error returned by Walk. + var errorMu sync.Mutex + var errors []error + recordErr := func(err error) { + errorMu.Lock() + defer errorMu.Unlock() + errors = append(errors, err) + } + unusedErrs := e.TaskGraph.Walk(func(v dag.Vertex) error { + // Use an extra func() to ensure that we are not returning any errors to Walk + func() { + // If something has already errored, short-circuit. + // There is a race here between concurrent tasks. However, if there is not a + // dependency edge between them, we are not required to have a strict order + // between them, so a failed task can fail to short-circuit a concurrent + // task that happened to be starting at the same time. + if atomic.LoadInt32(&errored) != 0 { + return + } + // Each vertex in the graph is a taskID (package#task format) + taskID := dag.VertexName(v) - // Acquire the semaphore unless parallel - if !opts.Parallel { - sema.Acquire() - defer sema.Release() - } + // Always return if it is the root node + if strings.Contains(taskID, ROOT_NODE_NAME) { + return + } - if err := visitor(taskID); err != nil { - // We only ever flip from false to true, so we don't need to compare and swap the atomic - atomic.StoreInt32(&errored, 1) - return err - } + // Acquire the semaphore unless parallel + if !opts.Parallel { + sema.Acquire() + defer sema.Release() + } + + if err := visitor(taskID); err != nil { + if se, ok := err.(*StopExecutionSentinel); ok { + // We only ever flip from false to true, so we don't need to compare and swap the atomic + atomic.StoreInt32(&errored, 1) + recordErr(se.err) + // Note: returning an error here would cancel execution of downstream tasks only, and show + // up in the errors returned from Walk. However, we are doing our own error collection + // and intentionally ignoring errors from walk, so fallthrough and use the "errored" mechanism + // to skip downstream tasks + } else { + recordErr(err) + } + } + }() return nil }) + if len(unusedErrs) > 0 { + panic("we should be handling execution errors via our own errors + errored mechanism") + } + return errors } // MissingTaskError is a specialized Error thrown in the case that we can't find a task. diff --git a/cli/internal/core/engine_test.go b/cli/internal/core/engine_test.go index a92264de29cc1..3ce00bf44573f 100644 --- a/cli/internal/core/engine_test.go +++ b/cli/internal/core/engine_test.go @@ -71,7 +71,7 @@ func TestShortCircuiting(t *testing.T) { println(taskID) executed[taskID] = true if taskID == "b#build" { - return expectedErr + return StopExecution(expectedErr) } return nil } diff --git a/cli/internal/run/real_run.go b/cli/internal/run/real_run.go index 0b1c5a1b17331..5d7cb43de7c83 100644 --- a/cli/internal/run/real_run.go +++ b/cli/internal/run/real_run.go @@ -322,7 +322,7 @@ func (ec *execContext) exec(ctx gocontext.Context, packageTask *nodes.PackageTas ec.logError(prettyPrefix, err) if !ec.rs.Opts.runOpts.ContinueOnError { - return nil, errors.Wrapf(err, "failed to capture outputs for \"%v\"", packageTask.TaskID) + return nil, core.StopExecution(errors.Wrapf(err, "failed to capture outputs for \"%v\"", packageTask.TaskID)) } } @@ -387,10 +387,12 @@ func (ec *execContext) exec(ctx gocontext.Context, packageTask *nodes.PackageTas if !ec.rs.Opts.runOpts.ContinueOnError { prefixedUI.Error(fmt.Sprintf("ERROR: command finished with error: %s", err)) ec.processes.Close() + // We're not continuing, stop graph traversal + err = core.StopExecution(err) } else { prefixedUI.Warn("command finished with error, but continuing...") // Set to nil so we don't short-circuit any other execution - err = nil + //err = nil } return taskExecutionSummary, err diff --git a/turborepo-tests/integration/tests/continue.t b/turborepo-tests/integration/tests/continue.t index 625549d2fd848..f750394d8aea1 100644 --- a/turborepo-tests/integration/tests/continue.t +++ b/turborepo-tests/integration/tests/continue.t @@ -74,6 +74,8 @@ Run with --continue other-app:build: npm ERR! in workspace: other-app other-app:build: npm ERR! at location: (.*)/apps/other-app (re) other-app:build: command finished with error, but continuing... + command \((.*)/apps/some-lib\) npm run build exited \(1\) (re) + command \((.*)/apps/other-app\) npm run build exited \(1\) (re) Tasks: 1 successful, 3 total Cached: 0 cached, 3 total From 031fdf630f043d6c27df3a8322c53517806db2c6 Mon Sep 17 00:00:00 2001 From: Greg Soltis Date: Mon, 24 Apr 2023 14:31:52 -0700 Subject: [PATCH 4/5] Drop commented-out code --- cli/internal/run/real_run.go | 2 -- 1 file changed, 2 deletions(-) diff --git a/cli/internal/run/real_run.go b/cli/internal/run/real_run.go index 84a78311d8784..9f869e1c7b632 100644 --- a/cli/internal/run/real_run.go +++ b/cli/internal/run/real_run.go @@ -391,8 +391,6 @@ func (ec *execContext) exec(ctx gocontext.Context, packageTask *nodes.PackageTas err = core.StopExecution(err) } else { prefixedUI.Warn("command finished with error, but continuing...") - // Set to nil so we don't short-circuit any other execution - //err = nil } return taskExecutionSummary, err From d622cc99c7d9f0f9b8f617dba0d9991f0f9d8f6c Mon Sep 17 00:00:00 2001 From: Greg Soltis Date: Mon, 24 Apr 2023 14:33:45 -0700 Subject: [PATCH 5/5] Clarify comment a little --- cli/internal/core/engine.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/cli/internal/core/engine.go b/cli/internal/core/engine.go index a7940e22ad830..f6e3a7a91d42c 100644 --- a/cli/internal/core/engine.go +++ b/cli/internal/core/engine.go @@ -98,7 +98,8 @@ func (e *Engine) Execute(visitor Visitor, opts EngineExecutionOptions) []error { var sema = util.NewSemaphore(opts.Concurrency) var errored int32 - // Returning an error from the Walk callback cancels downstream tasks, but not unrelated tasks. + // The dag library's behavior is that returning an error from the Walk callback cancels downstream + // tasks, but not unrelated tasks. // The behavior we want is to either cancel everything or nothing (--continue). So, we do our own // error handling. Collect any errors that occur in "errors", and report them as the result of // Execute. panic on any other error returned by Walk.