Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

Locking error error on initial plan or apply #2346

Closed
andyshinn opened this issue Jun 29, 2022 · 2 comments
Closed

Locking error error on initial plan or apply #2346

andyshinn opened this issue Jun 29, 2022 · 2 comments
Labels
bug Something isn't working

Comments

@andyshinn
Copy link

andyshinn commented Jun 29, 2022 •
edited
Loading

Community Note

  • Please vote on this issue by adding a 👍 reaction to the original issue to help the community and maintainers prioritize this request. Searching for pre-existing feature requests helps us consolidate datapoints for identical requirements into a single place, thank you!
  • Please do not leave "+1" or other comments that do not add relevant new information or questions, they generate extra noise for issue followers and do not help prioritize the request.
  • If you are interested in working on this issue or have submitted a pull request, please leave a comment.

Overview of the Issue

The following plan and apply errors always happen:

On plan:

The default workspace at path . is currently locked by another command that is running for this pull request.
Wait until the previous command is complete and try again.

On apply:

The Atlantis working dir is currently locked by another command that is running for this pull request.
Wait until the previous command is complete and try again.

However, the plan and applies do continue to run fine despite the errors. They happen each time a plan or apply is started and generate a lot of noise.

In addition to this, unlocks are duplicated:

image

Reproduction Steps

  • Open pull request.
  • Error immediately happens.
  • Plan and apply continue as normal.

Logs

Provide log files from Atlantis server

Logs 
Date,Message
"2022-06-29T03:14:41.284Z","updating DB with pull results"
"2022-06-29T03:14:40.975Z","POST /events – respond HTTP 200"
"2022-06-29T03:14:40.975Z","request valid"
"2022-06-29T03:14:40.974Z","handling GitHub post"
"2022-06-29T03:14:40.974Z","POST /events – from 10.120.1.54:30202"
"2022-06-29T03:14:40.913Z","POST /events – respond HTTP 200"
"2022-06-29T03:14:40.913Z","request valid"
"2022-06-29T03:14:40.912Z","handling GitHub post"
"2022-06-29T03:14:40.912Z","POST /events – from 10.120.2.151:5168"
"2022-06-29T03:14:40.586Z","POST /repos/myorg/automation/issues/355/comments"
"2022-06-29T03:14:40.568Z","POST /events – respond HTTP 200"
"2022-06-29T03:14:40.568Z","request valid"
"2022-06-29T03:14:40.568Z","handling GitHub post"
"2022-06-29T03:14:40.568Z","POST /events – from 10.120.1.54:30202"
"2022-06-29T03:14:40.514Z","POST /events – respond HTTP 200"
"2022-06-29T03:14:40.514Z","request valid"
"2022-06-29T03:14:40.514Z","handling GitHub post"
"2022-06-29T03:14:40.514Z","POST /events – from 10.120.2.151:5166"
"2022-06-29T03:14:39.141Z","GET /repos/myorg/automation/issues/355/comments"
"2022-06-29T03:14:39.141Z","plan success. output available at: https://github.com/myorg/automation/pull/355"
"2022-06-29T03:14:38.793Z","successfully ran ""/home/atlantis/.atlantis/bin/terraform1.2.3 plan -input=false -refresh -out \""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common/common-default.tfplan\"""" in ""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common"""
"2022-06-29T03:14:28.951Z","starting ""/home/atlantis/.atlantis/bin/terraform1.2.3 plan -input=false -refresh -out \""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common/common-default.tfplan\"""" in ""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common"""
"2022-06-29T03:14:28.949Z","successfully ran ""/home/atlantis/.atlantis/bin/terraform1.2.3 workspace show"" in ""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common"""
"2022-06-29T03:14:28.917Z","successfully ran ""/home/atlantis/.atlantis/bin/terraform1.2.3 init -input=false"" in ""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common"""
"2022-06-29T03:14:28.750Z","GET /jobs/8a3af906-c5bf-4ca6-87af-e8e05144e444/ws – respond HTTP 500"
"2022-06-29T03:14:28.750Z","2022/06/29 03:14:28 http: response.Write on hijacked connection from github.com/urfave/negroni.(*responseWriter).Write (response_writer.go:61)"
"2022-06-29T03:14:28.750Z","2022/06/29 03:14:28 http: response.WriteHeader on hijacked connection from github.com/urfave/negroni.(*responseWriter).WriteHeader (response_writer.go:53)"
"2022-06-29T03:14:28.750Z","writing to ws 8a3af906-c5bf-4ca6-87af-e8e05144e444: write tcp 10.120.129.131:4141->10.120.0.145:20132: write: broken pipe"
"2022-06-29T03:14:28.750Z","Removing channel for 8a3af906-c5bf-4ca6-87af-e8e05144e444"
"2022-06-29T03:14:28.750Z","Failed to write ws message: write tcp 10.120.129.131:4141->10.120.0.145:20132: write: broken pipe"
"2022-06-29T03:14:16.083Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:14:16.083Z","GET /healthz – from 10.120.2.151:5112"
"2022-06-29T03:14:16.027Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:14:16.027Z","GET /healthz – from 10.120.0.145:20152"
"2022-06-29T03:14:15.997Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:14:15.997Z","GET /healthz – from 10.120.1.54:30148"
"2022-06-29T03:14:08.213Z","GET /jobs/8a3af906-c5bf-4ca6-87af-e8e05144e444/ws – from 10.120.0.145:20132"
"2022-06-29T03:14:08.002Z","GET /jobs/8a3af906-c5bf-4ca6-87af-e8e05144e444 – respond HTTP 200"
"2022-06-29T03:14:08.002Z","GET /jobs/8a3af906-c5bf-4ca6-87af-e8e05144e444 – from 10.120.0.145:20130"
"2022-06-29T03:13:46.063Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:13:46.063Z","GET /healthz – from 10.120.2.151:5038"
"2022-06-29T03:13:46.017Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:13:46.017Z","GET /healthz – from 10.120.0.145:20080"
"2022-06-29T03:13:45.978Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:13:45.978Z","GET /healthz – from 10.120.1.54:30082"
"2022-06-29T03:13:16.032Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:13:16.032Z","GET /healthz – from 10.120.2.151:4970"
"2022-06-29T03:13:15.987Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:13:15.987Z","GET /healthz – from 10.120.0.145:19988"
"2022-06-29T03:13:15.968Z","GET /healthz – respond HTTP 200"
"2022-06-29T03:13:15.968Z","GET /healthz – from 10.120.1.54:30016"
"2022-06-29T03:12:59.004Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:59.004Z","request valid"
"2022-06-29T03:12:59.004Z","handling GitHub post"
"2022-06-29T03:12:59.004Z","POST /events – from 10.120.1.54:29974"
"2022-06-29T03:12:58.610Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:58.610Z","request valid"
"2022-06-29T03:12:58.609Z","handling GitHub post"
"2022-06-29T03:12:58.609Z","POST /events – from 10.120.0.145:19942"
"2022-06-29T03:12:57.950Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:57.950Z","request valid"
"2022-06-29T03:12:57.949Z","handling GitHub post"
"2022-06-29T03:12:57.949Z","POST /events – from 10.120.0.145:19942"
"2022-06-29T03:12:57.870Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:57.869Z","request valid"
"2022-06-29T03:12:57.869Z","handling GitHub post"
"2022-06-29T03:12:57.869Z","POST /events – from 10.120.2.151:4864"
"2022-06-29T03:12:57.464Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:57.464Z","request valid"
"2022-06-29T03:12:57.464Z","handling GitHub post"
"2022-06-29T03:12:57.464Z","POST /events – from 10.120.2.151:4864"
"2022-06-29T03:12:57.454Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:57.453Z","request valid"
"2022-06-29T03:12:57.453Z","handling GitHub post"
"2022-06-29T03:12:57.453Z","POST /events – from 10.120.0.145:19942"
"2022-06-29T03:12:57.188Z","POST /repos/myorg/automation/issues/355/comments"
"2022-06-29T03:12:56.282Z","starting ""/home/atlantis/.atlantis/bin/terraform1.2.3 init -input=false"" in ""/home/atlantis/.atlantis/repos/myorg/automation/355/default/terraform/myorg-common"""
"2022-06-29T03:12:56.259Z","repo is at correct commit ""5a00c667339bb25eed2da9ef9337ab35144b096b"" so will not re-clone"
"2022-06-29T03:12:56.248Z","clone directory ""/home/atlantis/.atlantis/repos/myorg/automation/355/default"" already exists, checking if it's at the right commit"
"2022-06-29T03:12:56.248Z","git credentials file has expected contents, not modifying"
"2022-06-29T03:12:56.246Z","Refreshing git tokens for Github App"
"2022-06-29T03:12:56.246Z","acquired lock for project"
"2022-06-29T03:12:56.246Z","acquired lock with id ""myorg/automation/terraform/myorg-common/default"""
"2022-06-29T03:12:56.198Z","GET /repos/myorg/automation/issues/355/comments"
"2022-06-29T03:12:56.198Z","The default workspace at path . is currently locked by another command that is running for this pull request.Wait until the previous command is complete and try again."
"2022-06-29T03:12:55.833Z","Running applies in parallel"
"2022-06-29T03:12:55.833Z","Building project command context for plan"
"2022-06-29T03:12:55.833Z","final settings: apply_requirements: [approved,mergeable,undiverged], workflow: default"
"2022-06-29T03:12:55.833Z","MergeProjectCfg completed"
"2022-06-29T03:12:55.833Z","setting delete_source_branch_on_merge: false from default server config"
"2022-06-29T03:12:55.833Z","setting allow_custom_workflows: false from default server config"
"2022-06-29T03:12:55.833Z","setting allowed_overrides: [apply_requirements] from repos[1], id: /.*/"
"2022-06-29T03:12:55.833Z","setting workflow: ""default"" from repos[1], id: /.*/"
"2022-06-29T03:12:55.833Z","setting apply_requirements: [approved,mergeable,undiverged] from repos[1], id: /.*/"
"2022-06-29T03:12:55.833Z","MergeProjectCfg started"
"2022-06-29T03:12:55.833Z","determining config for project at dir: ""terraform/myorg-common"" workspace: ""default"""
"2022-06-29T03:12:55.833Z","1 projects are to be planned based on their when_modified config"
"2022-06-29T03:12:55.833Z","checking if project at dir ""terraform/myorg-organization"" workspace ""default"" was modified"
"2022-06-29T03:12:55.832Z","checking if project at dir ""terraform/myorg-dns"" workspace ""default"" was modified"
"2022-06-29T03:12:55.832Z","checking if project at dir ""terraform/myorg-audit"" workspace ""default"" was modified"
"2022-06-29T03:12:55.832Z","checking if project at dir ""terraform/myorg-special"" workspace ""prod"" was modified"
"2022-06-29T03:12:55.832Z","checking if project at dir ""terraform/myorg-special"" workspace ""qa"" was modified"
"2022-06-29T03:12:55.830Z","file ""terraform/myorg-common/atlantis.tf"" matched pattern"
"2022-06-29T03:12:55.829Z","checking if project at dir ""terraform/myorg-common"" workspace ""default"" was modified"
"2022-06-29T03:12:55.829Z","successfully parsed atlantis.yaml file"
"2022-06-29T03:12:55.826Z","repo is at correct commit ""5a00c667339bb25eed2da9ef9337ab35144b096b"" so will not re-clone"
"2022-06-29T03:12:55.817Z","Error building plan commands: The default workspace at path . is currently locked by another command that is running for this pull request.Wait until the previous command is complete and try again."
"2022-06-29T03:12:55.817Z","workspace was locked"
"2022-06-29T03:12:55.816Z","2 files were modified in this pull request"
"2022-06-29T03:12:55.798Z","clone directory ""/home/atlantis/.atlantis/repos/myorg/automation/355/default"" already exists, checking if it's at the right commit"
"2022-06-29T03:12:55.792Z","git credentials file has expected contents, not modifying"
"2022-06-29T03:12:55.786Z","Refreshing git tokens for Github App"
"2022-06-29T03:12:55.786Z","got workspace lock"
"2022-06-29T03:12:55.786Z","2 files were modified in this pull request"
"2022-06-29T03:12:55.663Z","[attempt 1] GET /repos/myorg/automation/pulls/355/files"
"2022-06-29T03:12:55.626Z","[attempt 1] GET /repos/myorg/automation/pulls/355/files"
"2022-06-29T03:12:55.155Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:55.155Z","executing command"
"2022-06-29T03:12:55.155Z","parsed comment as command=""plan"" verbose=false dir="""" workspace="""" project="""" flags="""""
"2022-06-29T03:12:55.155Z","request valid"
"2022-06-29T03:12:55.153Z","handling GitHub post"
"2022-06-29T03:12:55.153Z","POST /events – from 10.120.2.151:4918"
"2022-06-29T03:12:55.102Z","POST /events – respond HTTP 200"
"2022-06-29T03:12:55.102Z","executing command"
"2022-06-29T03:12:55.102Z","parsed comment as command=""plan"" verbose=false dir="""" workspace="""" project="""" flags="""""
"2022-06-29T03:12:55.102Z","request valid"
"2022-06-29T03:12:55.101Z","handling GitHub post"
"2022-06-29T03:12:55.101Z","POST /events – from 10.120.0.145:19936"
"2022-06-29T03:12:46.023Z","GET /healthz – respond HTTP 200"

Environment details

If not already included, please provide the following:

  • Atlantis version: 0.19.4
  • If not running the latest Atlantis version have you tried to reproduce this issue on the latest version:
  • Atlantis flags:

Atlantis server-side config file:

gh-org: myorg
default-tf-version: v1.2.3
repos:
  - id: /.*/
    allowed_overrides:
      - apply_requirements
    apply_requirements:
      - approved
      - mergeable
      - undiverged
    workflow: default
metrics:
  statsd:
    host: "127.0.0.1"
    port: "8125"

Repo atlantis.yaml file:

version: 3
parallel_plan: true
parallel_apply: true
projects:
  - name: bootstrap-qa
    dir: automation/gov/terraform/bootstrap
    workspace: qa
    autoplan:
      when_modified: ["*.tf", "../modules/**/*.tf"]
      enabled: true
    apply_requirements: [mergeable, approved]
  - name: bootstrap-prod
    dir: automation/gov/terraform/bootstrap
    workspace: prod
    autoplan:
      when_modified: ["*.tf", "../modules/**/*.tf"]
      enabled: true
    apply_requirements: [mergeable, approved]

Any other information you can provide about the environment/deployment.

This is deployed using https://github.com/terraform-aws-modules/terraform-aws-atlantis

Additional Context

Related to comment #2200 (comment) and PR #2131 (I think). CC @pauloconnor
@andyshinn andyshinn added the bug Something isn't working label Jun 29, 2022
@andyshinn
Copy link
Author

So, turns out this was because of a switch to the GitHub App instead of using a machine user with personal access token. The app seems to have it's own built-in webhook. After removing the org-level webhook the problem went away. If anyone else is using the GitHub App and have manually set up webhooks I would double check if this is your same issue.

@kevin-fitlg
Copy link
Contributor

kevin-fitlg commented Jun 9, 2023 •
edited
Loading

Hi
This has caused issue for me and unfortunately it is documented properly.
I was scratching my head for hours as this looks likes to be related to https://github.com/runatlantis/atlantis/blob/e681c328363cbf3214653f144d4c3dace320dc72/docs/adr/0002-project-locks.md , but it is not!

I raised PR #3506 to update docs.
Thanks

@nitrocode nitrocode mentioned this issue Jun 10, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@andyshinn @jamengual @kevin-fitlg