diff --git a/.nextchanges/bundles/lock-retry.md b/.nextchanges/bundles/lock-retry.md new file mode 100644 index 00000000000..901f64ffb0f --- /dev/null +++ b/.nextchanges/bundles/lock-retry.md @@ -0,0 +1 @@ +* Retry creating the deployment lock (without `--force-lock`) when the request fails with a transient server error, times out ("request timed out after ... of inactivity") or loses its connection ("unexpected EOF"). ([#7594](https://github.com/databricks/cli/pull/7594)) diff --git a/acceptance/bundle/deploy/lock-retry/databricks.yml b/acceptance/bundle/deploy/lock-retry/databricks.yml new file mode 100644 index 00000000000..576d7a9ef25 --- /dev/null +++ b/acceptance/bundle/deploy/lock-retry/databricks.yml @@ -0,0 +1,2 @@ +bundle: + name: test-bundle diff --git a/acceptance/bundle/deploy/lock-retry/other.lock b/acceptance/bundle/deploy/lock-retry/other.lock new file mode 100644 index 00000000000..8a7caa3642c --- /dev/null +++ b/acceptance/bundle/deploy/lock-retry/other.lock @@ -0,0 +1 @@ +{"ID":"00000000-0000-0000-0000-000000000000","AcquisitionTime":"2026-01-01T00:00:00Z","IsForced":false,"User":"someone-else"} diff --git a/acceptance/bundle/deploy/lock-retry/out.test.toml b/acceptance/bundle/deploy/lock-retry/out.test.toml new file mode 100644 index 00000000000..a927a5fbc06 --- /dev/null +++ b/acceptance/bundle/deploy/lock-retry/out.test.toml @@ -0,0 +1,2 @@ +Cloud = false +EnvMatrix.DMS = ["", "true"] diff --git a/acceptance/bundle/deploy/lock-retry/output.txt b/acceptance/bundle/deploy/lock-retry/output.txt new file mode 100644 index 00000000000..4fb0e7377d7 --- /dev/null +++ b/acceptance/bundle/deploy/lock-retry/output.txt @@ -0,0 +1,95 @@ + +=== Lock create is applied, but the response is a 504: the retry finds our own lock + +>>> [CLI] bundle deploy +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Uploading bundle files to /Workspace/Users/[USERNAME]/.bundle/test-bundle/default/files... +Files: 0 uploaded, 0 deleted +Resources: 0 created, 0 changed, 0 deleted, 0 unchanged +["POST","false"] +["POST","false"] + +=== Lock create is not applied and fails with a 504: the retry creates the lock + +>>> [CLI] bundle deploy +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Uploading bundle files to /Workspace/Users/[USERNAME]/.bundle/test-bundle/default/files... +Files: 0 uploaded, 0 deleted +Resources: 0 created, 0 changed, 0 deleted, 0 unchanged +["POST","false"] +["POST","false"] + +=== Every attempt returns a 504, but the first one is applied: reading the lock back finds it is ours + +>>> [CLI] bundle deploy +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Uploading bundle files to /Workspace/Users/[USERNAME]/.bundle/test-bundle/default/files... +Files: 0 uploaded, 0 deleted +Resources: 0 created, 0 changed, 0 deleted, 0 unchanged +["POST","false"] +["POST","false"] +["POST","false"] + +=== Lock is held by another deployer: the retry gets a conflict and the error names the holder + +>>> [CLI] bundle deploy +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Error: Failed to acquire deployment lock: deploy lock acquired by someone-else at [TIMESTAMP] +0000 UTC. +Another deployment may be in progress. Use --force-lock to override, but this may +conflict with the other deployment if it is still active +Error: deploy lock acquired by someone-else at [TIMESTAMP] +0000 UTC. +Another deployment may be in progress. Use --force-lock to override, but this may +conflict with the other deployment if it is still active + + +Exit code: 1 + +=== Lock is held by another deployer and every attempt returns a 504: reading the lock back names the holder + +>>> [CLI] bundle deploy +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Error: Failed to acquire deployment lock: deploy lock acquired by someone-else at [TIMESTAMP] +0000 UTC. +Another deployment may be in progress. Use --force-lock to override, but this may +conflict with the other deployment if it is still active +Error: deploy lock acquired by someone-else at [TIMESTAMP] +0000 UTC. +Another deployment may be in progress. Use --force-lock to override, but this may +conflict with the other deployment if it is still active + + +Exit code: 1 +["POST","false"] +["POST","false"] +["POST","false"] + +=== Forced lock, every overwrite attempt returns a 504 but is applied: reading the lock back finds it is ours + +>>> [CLI] bundle deploy --force-lock +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Uploading bundle files to /Workspace/Users/[USERNAME]/.bundle/test-bundle/default/files... +Files: 0 uploaded, 0 deleted +Resources: 0 created, 0 changed, 0 deleted, 0 unchanged +["POST","true"] +["POST","true"] +["POST","true"] + +=== Forced lock over another deployer's lock, every overwrite attempt returns a 504 and is not applied: the error is the 504 + +>>> [CLI] bundle deploy --force-lock +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Warn: retrying after 504 Gateway Timeout from POST /api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +Error: Failed to acquire deployment lock: Fault injected by test. +Error: Fault injected by test. (504 INJECTED) + +Endpoint: POST [DATABRICKS_URL]/api/2.0/workspace-files/import-file/Workspace%2FUsers%2F[USERNAME]%2F.bundle%2Ftest-bundle%2Fdefault%2Fstate%2Fdeploy.lock?overwrite=true +HTTP Status: 504 Gateway Timeout +API error_code: INJECTED +API message: Fault injected by test. + + +Exit code: 1 +["POST","true"] +["POST","true"] +["POST","true"] diff --git a/acceptance/bundle/deploy/lock-retry/script b/acceptance/bundle/deploy/lock-retry/script new file mode 100644 index 00000000000..eeb95425736 --- /dev/null +++ b/acceptance/bundle/deploy/lock-retry/script @@ -0,0 +1,43 @@ +# Deploy once so that the state directory exists and the lock create is a single request. +$CLI bundle deploy > /dev/null 2>&1 +print_requests.py > /dev/null + +title "Lock create is applied, but the response is a 504: the retry finds our own lock" +fault.py --after-handler "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 1 +trace $CLI bundle deploy +print_requests.py //api/2.0/workspace-files/import-file | jq -c 'select(.path | contains("deploy.lock")) | [.method, .q.overwrite]' + +title "Lock create is not applied and fails with a 504: the retry creates the lock" +fault.py "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 1 +trace $CLI bundle deploy +print_requests.py //api/2.0/workspace-files/import-file | jq -c 'select(.path | contains("deploy.lock")) | [.method, .q.overwrite]' + +title "Every attempt returns a 504, but the first one is applied: reading the lock back finds it is ours" +fault.py --after-handler "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 3 +trace $CLI bundle deploy +print_requests.py //api/2.0/workspace-files/import-file | jq -c 'select(.path | contains("deploy.lock")) | [.method, .q.overwrite]' + +title "Lock is held by another deployer: the retry gets a conflict and the error names the holder" +fault.py "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 1 +# other.lock is a lock held by another deployer. +# MSYS_NO_PATHCONV stops Git Bash on Windows from turning the workspace path into a local one. +MSYS_NO_PATHCONV=1 $CLI workspace import /Workspace/Users/$CURRENT_USER_NAME/.bundle/test-bundle/default/state/deploy.lock --file other.lock --format AUTO > /dev/null +errcode trace $CLI bundle deploy +print_requests.py > /dev/null + +title "Lock is held by another deployer and every attempt returns a 504: reading the lock back names the holder" +fault.py --after-handler "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 3 +errcode trace $CLI bundle deploy +print_requests.py //api/2.0/workspace-files/import-file | jq -c 'select(.path | contains("deploy.lock")) | [.method, .q.overwrite]' + +title "Forced lock, every overwrite attempt returns a 504 but is applied: reading the lock back finds it is ours" +fault.py --after-handler "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 3 +trace $CLI bundle deploy --force-lock +print_requests.py //api/2.0/workspace-files/import-file | jq -c 'select(.path | contains("deploy.lock")) | [.method, .q.overwrite]' + +title "Forced lock over another deployer's lock, every overwrite attempt returns a 504 and is not applied: the error is the 504" +MSYS_NO_PATHCONV=1 $CLI workspace import /Workspace/Users/$CURRENT_USER_NAME/.bundle/test-bundle/default/state/deploy.lock --file other.lock --format AUTO --overwrite > /dev/null +print_requests.py > /dev/null +fault.py "POST /api/2.0/workspace-files/import-file/**/deploy.lock" 504 0 3 +errcode trace $CLI bundle deploy --force-lock +print_requests.py //api/2.0/workspace-files/import-file | jq -c 'select(.path | contains("deploy.lock")) | [.method, .q.overwrite]' diff --git a/acceptance/bundle/deploy/lock-retry/test.toml b/acceptance/bundle/deploy/lock-retry/test.toml new file mode 100644 index 00000000000..711ede517b9 --- /dev/null +++ b/acceptance/bundle/deploy/lock-retry/test.toml @@ -0,0 +1,3 @@ +RecordRequests = true +Env.DATABRICKS_BUNDLE_RETRY_INTERVAL_MS = "100" +SuppressLines.warn_retry = "" diff --git a/acceptance/bundle/deploy/lock-timeout/databricks.yml b/acceptance/bundle/deploy/lock-timeout/databricks.yml new file mode 100644 index 00000000000..576d7a9ef25 --- /dev/null +++ b/acceptance/bundle/deploy/lock-timeout/databricks.yml @@ -0,0 +1,2 @@ +bundle: + name: test-bundle diff --git a/acceptance/bundle/deploy/lock-timeout/out.test.toml b/acceptance/bundle/deploy/lock-timeout/out.test.toml new file mode 100644 index 00000000000..a927a5fbc06 --- /dev/null +++ b/acceptance/bundle/deploy/lock-timeout/out.test.toml @@ -0,0 +1,2 @@ +Cloud = false +EnvMatrix.DMS = ["", "true"] diff --git a/acceptance/bundle/deploy/lock-timeout/output.txt b/acceptance/bundle/deploy/lock-timeout/output.txt new file mode 100644 index 00000000000..b54178c0ec2 --- /dev/null +++ b/acceptance/bundle/deploy/lock-timeout/output.txt @@ -0,0 +1,8 @@ +Warn: retrying after Post "[DATABRICKS_URL]/api/2.0/workspace-files/import-file/Workspace%2FUsers%2F[USERNAME]%2F.bundle%2Ftest-bundle%2Fdefault%2Fstate%2Fdeploy.lock?overwrite=false": request timed out after 5s of inactivity +Warn: retrying after Post "[DATABRICKS_URL]/api/2.0/workspace-files/import-file/Workspace%2FUsers%2F[USERNAME]%2F.bundle%2Ftest-bundle%2Fdefault%2Fstate%2Fdeploy.lock?overwrite=false": request timed out after 5s of inactivity +Error: Failed to acquire deployment lock: Post "[DATABRICKS_URL]/api/2.0/workspace-files/import-file/Workspace%2FUsers%2F[USERNAME]%2F.bundle%2Ftest-bundle%2Fdefault%2Fstate%2Fdeploy.lock?overwrite=false": request timed out after 5s of inactivity +Error: Post "[DATABRICKS_URL]/api/2.0/workspace-files/import-file/Workspace%2FUsers%2F[USERNAME]%2F.bundle%2Ftest-bundle%2Fdefault%2Fstate%2Fdeploy.lock?overwrite=false": request timed out after 5s of inactivity + +/api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +/api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock +/api/2.0/workspace-files/import-file/Workspace/Users/[USERNAME]/.bundle/test-bundle/default/state/deploy.lock diff --git a/acceptance/bundle/deploy/lock-timeout/script b/acceptance/bundle/deploy/lock-timeout/script new file mode 100644 index 00000000000..65341c0f0b2 --- /dev/null +++ b/acceptance/bundle/deploy/lock-timeout/script @@ -0,0 +1,4 @@ +musterr $CLI bundle deploy + +# Three attempts: the first one and two retries. +print_requests.py //api/2.0/workspace-files/import-file | jq -r .path | grep 'deploy.lock' diff --git a/acceptance/bundle/deploy/lock-timeout/test.toml b/acceptance/bundle/deploy/lock-timeout/test.toml new file mode 100644 index 00000000000..14ad89aff1f --- /dev/null +++ b/acceptance/bundle/deploy/lock-timeout/test.toml @@ -0,0 +1,11 @@ +Env.DATABRICKS_BUNDLE_HTTP_TIMEOUT_SECONDS = "5" +Env.DATABRICKS_BUNDLE_RETRY_INTERVAL_MS = "100" +SuppressLines.warn_retry = "" +RecordRequests = true + +[[Server]] +# Every lock create attempt outlives the 5s inactivity timeout, so the CLI retries it twice, +# finds no lock when it reads it back, and fails with the timeout. +Delay = "30s" +Pattern = "POST /api/2.0/workspace-files/import-file/Workspace/Users/tester@databricks.com/.bundle/test-bundle/default/state/deploy.lock" +Response.StatusCode = 200 diff --git a/acceptance/bundle/telemetry/deploy-failed-engine-unknown/test.toml b/acceptance/bundle/telemetry/deploy-failed-engine-unknown/test.toml index 86d366ba8c2..1592114326e 100644 --- a/acceptance/bundle/telemetry/deploy-failed-engine-unknown/test.toml +++ b/acceptance/bundle/telemetry/deploy-failed-engine-unknown/test.toml @@ -11,6 +11,9 @@ # diverges across the engine matrix only in state_engine; it is captured per-engine. Cloud = false +# The lock create fails with a 500, which the CLI retries; keep the pauses between attempts short. +Env.DATABRICKS_BUNDLE_RETRY_INTERVAL_MS = "100" + [[Server]] Pattern = "POST /api/2.0/workspace-files/import-file/{path...}" Response.StatusCode = 500 diff --git a/libs/locker/locker.go b/libs/locker/locker.go index 857139c79b4..95b9f86a233 100644 --- a/libs/locker/locker.go +++ b/libs/locker/locker.go @@ -105,6 +105,11 @@ func (locker *Locker) assertLockHeld(ctx context.Context) error { if err != nil { return err } + return locker.checkHolder(activeLockState) +} + +// checkHolder returns a descriptive error naming the holder if activeLockState is not ours. +func (locker *Locker) checkHolder(activeLockState *LockState) error { if activeLockState.ID != locker.State.ID && !activeLockState.IsForced { return fmt.Errorf("deploy lock acquired by %s at %v.\n"+ "Another deployment may be in progress. Use --force-lock to override, but this may\n"+ @@ -147,29 +152,45 @@ func (locker *Locker) Lock(ctx context.Context, isForced bool) error { return err } - modes := []filer.WriteMode{ - // Always create parent directory if it doesn't yet exist. - filer.CreateParentDirectories, - } - - // Only overwrite lock file if `isForced`. if isForced { - modes = append(modes, filer.OverwriteIfExists) - } - - err = locker.filer.Write(ctx, LockFileName, bytes.NewReader(buf), modes...) - if err != nil { - // If the write failed because the lock file already exists, don't return - // the error and instead fall through to [assertLockHeld] below. - // This function will return a more descriptive error message that includes - // details about the current holder of the lock. - if !errors.Is(err, fs.ErrExist) { + // The retrying filer already retries overwrite writes, on the errors [retry.IsTransient] + // covers; an "unexpected EOF" is not retried there, only read back below. + err = locker.filer.Write(ctx, LockFileName, bytes.NewReader(buf), filer.CreateParentDirectories, filer.OverwriteIfExists) + } else { + // The retrying filer does not repeat writes that do not overwrite. Repeating this one is + // safe because the lock file carries our unique ID: if an attempt that failed with a + // transient error did create the file, the retry fails with fs.ErrExist and + // assertLockHeld below tells whether the lock is ours. That holds for a connection cut + // mid-response ("unexpected EOF") too, so this uses the wider check meant for reads. + _, err = retry.With(ctx, retry.IsTransientRead, func() (struct{}, error) { + return struct{}{}, locker.filer.Write(ctx, LockFileName, bytes.NewReader(buf), filer.CreateParentDirectories) + }) + } + + switch { + case err == nil || errors.Is(err, fs.ErrExist): + // If the lock file already exists, [assertLockHeld] returns a more descriptive + // error that names the current holder of the lock. + if err := locker.assertLockHeld(ctx); err != nil { return err } - } - - err = locker.assertLockHeld(ctx) - if err != nil { + case retry.IsTransientRead(ctx, err): + // The last attempt may have been applied even though its response was lost. Read the + // lock back so that such a write does not leave behind a lock nobody releases. This + // covers forced locks too. + activeLockState, readErr := locker.GetActiveLockState(ctx) + if readErr != nil { + // No lock, or the read failed too: the write error says more. + return err + } + if holderErr := locker.checkHolder(activeLockState); holderErr != nil { + if isForced { + // The holder error suggests --force-lock, which is already in use. + return err + } + return holderErr + } + default: return err } diff --git a/libs/locker/locker_test.go b/libs/locker/locker_test.go new file mode 100644 index 00000000000..c5bb8068840 --- /dev/null +++ b/libs/locker/locker_test.go @@ -0,0 +1,88 @@ +package locker + +import ( + "context" + "io" + "net/url" + "testing" + "uuid" + + "github.com/databricks/cli/libs/env" + "github.com/databricks/cli/libs/filer" + "github.com/databricks/cli/libs/retry" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// eofFiler fails the first `failures` writes with the error net/http returns when the connection +// is cut mid-response. The write numbered appliedOn (1-based, 0 for none) still writes the file +// before failing, like a request the server applied before the connection was cut. +type eofFiler struct { + filer.Filer + failures int + appliedOn int + writes int +} + +func (f *eofFiler) Write(ctx context.Context, path string, reader io.Reader, mode ...filer.WriteMode) error { + f.writes++ + if f.writes > f.failures { + return f.Filer.Write(ctx, path, reader, mode...) + } + if f.writes == f.appliedOn { + if err := f.Filer.Write(ctx, path, reader, mode...); err != nil { + return err + } + } + return &url.Error{Op: "Post", URL: "https://example.com/" + path, Err: io.ErrUnexpectedEOF} +} + +func newTestLocker(t *testing.T, f filer.Filer) *Locker { + return &Locker{ + filer: f, + TargetDir: t.TempDir(), + State: &LockState{ID: uuid.New(), User: "tester"}, + } +} + +func TestLockRetriesUnexpectedEOF(t *testing.T) { + ctx := env.Set(t.Context(), retry.IntervalMsVariable, "1") + + tests := []struct { + name string + failures int + appliedOn int + }{ + // The retry creates the lock. + {name: "not applied", failures: 1, appliedOn: 0}, + // The retry fails with "already exists" and the read-back finds our lock. + {name: "applied", failures: 1, appliedOn: 1}, + // Retries run out, but the last attempt was applied: the read-back finds our lock. + {name: "last attempt applied", failures: 3, appliedOn: 3}, + } + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + local, err := filer.NewLocalClient(t.TempDir()) + require.NoError(t, err) + f := &eofFiler{Filer: local, failures: tc.failures, appliedOn: tc.appliedOn} + locker := newTestLocker(t, f) + + require.NoError(t, locker.Lock(ctx, false)) + assert.True(t, locker.Active) + assert.Equal(t, min(tc.failures+1, 3), f.writes) + }) + } +} + +func TestLockFailsWhenEveryAttemptHitsUnexpectedEOF(t *testing.T) { + ctx := env.Set(t.Context(), retry.IntervalMsVariable, "1") + local, err := filer.NewLocalClient(t.TempDir()) + require.NoError(t, err) + f := &eofFiler{Filer: local, failures: 3} + locker := newTestLocker(t, f) + + err = locker.Lock(ctx, false) + require.ErrorIs(t, err, io.ErrUnexpectedEOF) + assert.False(t, locker.Active) + assert.Equal(t, 3, f.writes) +}