diff --git a/backend/local/backend_apply.go b/backend/local/backend_apply.go index 1b479c752..66c437971 100644 --- a/backend/local/backend_apply.go +++ b/backend/local/backend_apply.go @@ -143,6 +143,7 @@ func (b *Local) opApply( doneCh := make(chan struct{}) go func() { defer close(doneCh) + log.Printf("[INFO] backend/local: apply calling Apply") _, applyDiags = tfCtx.Apply() // we always want the state, even if apply failed applyState = tfCtx.State() diff --git a/backend/local/backend_local.go b/backend/local/backend_local.go index e972098e1..0e9ec77f3 100644 --- a/backend/local/backend_local.go +++ b/backend/local/backend_local.go @@ -1,6 +1,7 @@ package local import ( + "log" "context" "fmt" @@ -35,15 +36,18 @@ func (b *Local) context(op *backend.Operation) (*terraform.Context, *configload. var diags tfdiags.Diagnostics // Get the latest state. + log.Printf("[TRACE] backend/local: requesting state manager for workspace %q", op.Workspace) s, err := b.StateMgr(op.Workspace) if err != nil { diags = diags.Append(errwrap.Wrapf("Error loading state: {{err}}", err)) return nil, nil, nil, diags } + log.Printf("[TRACE] backend/local: requesting state lock for workspace %q", op.Workspace) if err := op.StateLocker.Lock(s, op.Type.String()); err != nil { diags = diags.Append(errwrap.Wrapf("Error locking state: {{err}}", err)) return nil, nil, nil, diags } + log.Printf("[TRACE] backend/local: reading remote state for workspace %q", op.Workspace) if err := s.RefreshState(); err != nil { diags = diags.Append(errwrap.Wrapf("Error loading state: {{err}}", err)) return nil, nil, nil, diags @@ -63,6 +67,7 @@ func (b *Local) context(op *backend.Operation) (*terraform.Context, *configload. // Load the latest state. If we enter contextFromPlanFile below then the // state snapshot in the plan file must match this, or else it'll return // error diagnostics. + log.Printf("[TRACE] backend/local: retrieving the local state snapshot for workspace %q", op.Workspace) opts.State = s.State() var tfCtx *terraform.Context @@ -77,17 +82,20 @@ func (b *Local) context(op *backend.Operation) (*terraform.Context, *configload. m := sm.StateSnapshotMeta() stateMeta = &m } + log.Printf("[TRACE] backend/local: building context from plan file") tfCtx, configSnap, ctxDiags = b.contextFromPlanFile(op.PlanFile, opts, stateMeta) // Write sources into the cache of the main loader so that they are // available if we need to generate diagnostic message snippets. op.ConfigLoader.ImportSourcesFromSnapshot(configSnap) } else { + log.Printf("[TRACE] backend/local: building context for current working directory") tfCtx, configSnap, ctxDiags = b.contextDirect(op, opts) } diags = diags.Append(ctxDiags) if diags.HasErrors() { return nil, nil, nil, diags } + log.Printf("[TRACE] backend/local: finished building terraform.Context") // If we have an operation, then we automatically do the input/validate // here since every option requires this. @@ -98,6 +106,7 @@ func (b *Local) context(op *backend.Operation) (*terraform.Context, *configload. mode |= terraform.InputModeVar mode |= terraform.InputModeVarUnset + log.Printf("[TRACE] backend/local: requesting interactive input, if necessary") inputDiags := tfCtx.Input(mode) diags = diags.Append(inputDiags) if inputDiags.HasErrors() { @@ -107,6 +116,7 @@ func (b *Local) context(op *backend.Operation) (*terraform.Context, *configload. // If validation is enabled, validate if b.OpValidation { + log.Printf("[TRACE] backend/local: running validation operation") validateDiags := tfCtx.Validate() diags = diags.Append(validateDiags) } diff --git a/terraform/context.go b/terraform/context.go index ff3679aa1..b6e6b73ac 100644 --- a/terraform/context.go +++ b/terraform/context.go @@ -123,6 +123,7 @@ type Context struct { // If the returned diagnostics contains errors then the resulting context is // invalid and must not be used. func NewContext(opts *ContextOpts) (*Context, tfdiags.Diagnostics) { + log.Printf("[TRACE] terraform.NewContext: starting") diags := CheckCoreVersionRequirements(opts.Config) // If version constraints are not met then we'll bail early since otherwise // we're likely to just see a bunch of other errors related to @@ -175,6 +176,7 @@ func NewContext(opts *ContextOpts) (*Context, tfdiags.Diagnostics) { if opts.ProviderSHA256s != nil && !opts.SkipProviderVerify { reqd.LockExecutables(opts.ProviderSHA256s) } + log.Printf("[TRACE] terraform.NewContext: resolving provider version selections") providerFactories, err = resourceProviderFactories(opts.ProviderResolver, reqd) if err != nil { diags = diags.Append(err) @@ -189,6 +191,7 @@ func NewContext(opts *ContextOpts) (*Context, tfdiags.Diagnostics) { provisioners: opts.Provisioners, } + log.Printf("[TRACE] terraform.NewContext: loading provider schemas") schemas, err := LoadSchemas(opts.Config, opts.State, components) if err != nil { diags = diags.Append(err) @@ -205,6 +208,8 @@ func NewContext(opts *ContextOpts) (*Context, tfdiags.Diagnostics) { config = configs.NewEmptyConfig() } + log.Printf("[TRACE] terraform.NewContext: complete") + return &Context{ components: components, schemas: schemas,