Skip to content

Dead lock when running a lot of projects in parallel #6408

@nvanheuverzwijn

Description

@nvanheuverzwijn

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

When running atlantis with a repo.yaml configuration that contains parallel_plan: true, we may stumble in a dead lock. It is very hard to debug.

Reproduction Steps

Have at least 10 project to run in your repo level atlantis.yaml and set parallel_plan: true. Make sure that you have the default number of process set to 15 (parallel-pool-size).

Run atlantis as usual, ideal with --log-level=debug. The last line of debug you should see is

{"level":"debug","ts":"2026-04-20T13:21:31.538Z","caller":"events/working_dir.go:272","msg":"runGitFetch: running git fetch in /atlantis-data/repos/...","json":{"repo":"...","pull":"##"}}

Logs

I added some debug logs around the locking mechanism.

In events/working_dir.go:243

	logger.Debug("------------------------------------------------(recheckDiverged)GETTING REFLOCK")
	// We already hold the write lock; take ref lock so fetch is serialized with other HasDiverged callers.
	unlockRef := w.gitRefLock(cloneDir)
	defer logger.Debug("------------------------------------------------(recheckDiverged)RELEASING REFLOCK")
	defer unlockRef()

In events/working_dir.go:253

	logger.Debug("################################################(HasDiverged)GETTING REFLOCK")
	// Hold ref lock and repo read lock for the full duration (fetch + status) so we don't race with
	// clone/reset/merge. recheckDiverged does not take the read lock because it already holds the write lock.
	unlockGitRefLock := w.gitRefLock(cloneDir)
	defer logger.Debug("################################################(HasDiverged)RELEASING REFLOCK")
	defer unlockGitRefLock()

In events/working_dir.go:260

	logger.Debug("**************************************************(HasDiverged)GETTING READLOCK")
	unlockGitReadLock := w.gitReadLock(cloneDir)
	defer logger.Debug("**************************************************(HasDiverged)RELEASING READLOCK")
	defer unlockGitReadLock()

In events/working_dir.go:190

	logger.Debug("$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK")
	// Unconditionally wait for the clone lock here, if anyone else is doing any clone
	// operation in this directory, we wait for it to finish before we check anything.
	gitWriteUnlockFn := w.gitWriteLock(cloneDir)
	defer logger.Debug("$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)RELEASING WRITE LOCK")
	defer gitWriteUnlockFn()

Notice how a bunch of goroutine are getting a write lock (denoted by a bunch of $ sign).

At the same time as this is happening, a goroutine is starting it's work and get a reflock (denoted by # sign).
That same goroutine is also getting a read lock (denoted by * sign).
This is all happening in HadDiverged function.

Because a write lock is there, the read lock is stuck And because the HasDiverged function has the reflock, the other goroutine cannot continue because they want the reflock.

It's complicated but the solution is rather simple, just invert the way we acquire locks. So instead of getting the reflock first, we should be getting the read/write lock first, THEN get a reflock.

Logs
dagger / $ atlantis server --log-level=debug 2>&1 | grep -v metrics
[removed logs]
^Z
[1]+  Stopped                    atlantis server --log-level=debug 2>&1 | grep -v metrics
dagger / $ bg
[1]+ atlantis server --log-level=debug 2>&1 | grep -v metrics &
dagger / $
exit
dagger / $ cd payload/
dagger /payload $ curl -X POST localhost:4141/events -H @headerfile001 -d @payload001.m.json
{"level":"debug","ts":"2026-04-20T13:19:45.936Z","caller":"server/middleware.go:45","msg":"POST /events – from [::1]:60250","json":{}}
[REMOVED DEBUG]
{"level":"debug","ts":"2026-04-20T13:20:01.400Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.406Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.412Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.415Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/unsub-api-sa/default/unsub-api-sa'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.415Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.421Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.423Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/esp-unsub-events/default/esp-unsub-events'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.423Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.425Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.426Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.426Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/esp-unsub-events-deadletter/default/esp-unsub-events-deadletter'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.427Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.432Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/unsub-event-consumer-sa-binding/default/unsub-event-consumer-sa-binding'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.432Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.437Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/wk-quality-assurance-bucket-iam/default/wk-quality-assurance-bucket-iam'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.437Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.448Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.453Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/unsub-website-fetcher-sa-binding/default/unsub-website-fetcher-sa-binding'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.453Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.509Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.511Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/unsub-api-bq-iam/default/unsub-api-bq-iam'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.511Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.534Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.536Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/bx-qa-sends-website-configs-bucket-iam/default/bx-qa-sends-website-configs-bucket-iam'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.536Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.538Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:01.544Z","caller":"events/project_locker.go:86","msg":"Acquired lock with id 'wunderkind-co/unsub-api/iac_tmp/qa/unsub-api-pubsub/default/unsub-api-pubsub'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:01.544Z","caller":"events/project_command_runner.go:603","msg":"acquired lock for project","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
dagger /payload $ {"level":"debug","ts":"2026-04-20T13:20:03.319Z","caller":"events/working_dir.go:238","msg":"------------------------------------------------(recheckDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:03.319Z","caller":"events/working_dir.go:272","msg":"runGitFetch: running git fetch in /atlantis-data/repos/wunderkind-co/unsub-api/11/default","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:03.842Z","caller":"events/working_dir.go:243","msg":"------------------------------------------------(recheckDiverged)RELEASING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:03.842Z","caller":"events/working_dir.go:190","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)RELEASING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:03.842Z","caller":"events/working_dir.go:253","msg":"################################################(HasDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:03.842Z","caller":"events/working_dir.go:260","msg":"**************************************************(HasDiverged)GETTING READLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:03.842Z","caller":"events/working_dir.go:272","msg":"runGitFetch: running git fetch in /atlantis-data/repos/wunderkind-co/unsub-api/11/default","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:04.348Z","caller":"events/working_dir.go:265","msg":"**************************************************(HasDiverged)RELEASING READLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:04.348Z","caller":"events/working_dir.go:265","msg":"################################################(HasDiverged)RELEASING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:04.348Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:04.351Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:20:04.351Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:04.351Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:04.352Z","caller":"models/shell_command_runner.go:117","msg":"starting 'sh -c \"cd $ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\\nexport IAC_REPO_ROOT=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\\nexport TG_WORKING_DIR=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE/$REPO_REL_DIR\\n\\n# echo \\\"Running terragrunt init -reconfigure/-upgrade in $TG_WORKING_DIR\\\"\\nterragrunt init -reconfigure --log-custom-format \\\"%msg\\\" > /dev/null\\nterragrunt init -upgrade --log-custom-format \\\"%msg\\\" > /dev/null\\n\\n# echo \\\"Running terragrunt validate\\\"\\nterragrunt validate --log-custom-format \\\"%msg\\\" > /dev/null\\n\\n# echo \\\"Running terragrunt plan\\\"\\nterragrunt --non-interactive plan -no-color -out=$PLANFILE --log-custom-format \\\"%msg\\\"\\n\"' in '/atlantis-data/repos/wunderkind-co/unsub-api/11/default/iac_tmp/qa/unsub-api-sa-binding'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:20:06.059Z","caller":"github/token_rotator.go:65","msg":"Refreshing Github tokens for .git-credentials","json":{}}
{"level":"debug","ts":"2026-04-20T13:20:06.059Z","caller":"github/token_rotator.go:71","msg":"Token successfully refreshed","json":{}}
{"level":"debug","ts":"2026-04-20T13:20:06.059Z","caller":"common/git_cred_writer.go:39","msg":"git credentials file has expected contents, not modifying","json":{}}
{"level":"debug","ts":"2026-04-20T13:20:36.058Z","caller":"github/token_rotator.go:65","msg":"Refreshing Github tokens for .git-credentials","json":{}}
{"level":"debug","ts":"2026-04-20T13:20:36.058Z","caller":"github/token_rotator.go:71","msg":"Token successfully refreshed","json":{}}
{"level":"debug","ts":"2026-04-20T13:20:36.059Z","caller":"common/git_cred_writer.go:39","msg":"git credentials file has expected contents, not modifying","json":{}}
{"level":"debug","ts":"2026-04-20T13:21:06.057Z","caller":"github/token_rotator.go:65","msg":"Refreshing Github tokens for .git-credentials","json":{}}
{"level":"debug","ts":"2026-04-20T13:21:06.057Z","caller":"github/token_rotator.go:71","msg":"Token successfully refreshed","json":{}}
{"level":"debug","ts":"2026-04-20T13:21:06.058Z","caller":"common/git_cred_writer.go:39","msg":"git credentials file has expected contents, not modifying","json":{}}
{"level":"info","ts":"2026-04-20T13:21:12.489Z","caller":"models/shell_command_runner.go:184","msg":"successfully ran 'sh -c' 'cd $ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\nexport IAC_REPO_ROOT=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\nexport TG_WORKING_DIR=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE/$REPO_REL_DIR\n\n# echo \"Running terragrunt init -reconfigure/-upgrade in $TG_WORKING_DIR\"\nterragrunt init -reconfigure --log-custom-format \"%msg\" > /dev/null\nterragrunt init -upgrade --log-custom-format \"%msg\" > /dev/null\n\n# echo \"Running terragrunt validate\"\nterragrunt validate --log-custom-format \"%msg\" > /dev/null\n\n# echo \"Running terragrunt plan\"\nterragrunt --non-interactive plan -no-color -out=$PLANFILE --log-custom-format \"%msg\"\n' in '/atlantis-data/repos/wunderkind-co/unsub-api/11/default/iac_tmp/qa/unsub-api-sa-binding'","json":{"repo":"wunderkind-co/unsub-api","pull":"11","duration":68.136953749}}
{"level":"info","ts":"2026-04-20T13:21:12.490Z","caller":"github/client.go:959","msg":"Updating GitHub Check status for 'iac-qa/plan: unsub-api-sa-binding' to 'success'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.363Z","caller":"events/working_dir.go:238","msg":"------------------------------------------------(recheckDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.363Z","caller":"events/working_dir.go:272","msg":"runGitFetch: running git fetch in /atlantis-data/repos/wunderkind-co/unsub-api/11/default","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.402Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:13.403Z","caller":"events/instrumented_project_command_runner.go:91","msg":"plan success. output available at: https://github.com/wunderkind-co/unsub-api/pull/11","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.754Z","caller":"events/working_dir.go:243","msg":"------------------------------------------------(recheckDiverged)RELEASING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.754Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.754Z","caller":"events/working_dir.go:190","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)RELEASING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.754Z","caller":"events/working_dir.go:253","msg":"################################################(HasDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.754Z","caller":"events/working_dir.go:260","msg":"**************************************************(HasDiverged)GETTING READLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.757Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:13.757Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.757Z","caller":"events/working_dir.go:272","msg":"runGitFetch: running git fetch in /atlantis-data/repos/wunderkind-co/unsub-api/11/default","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:13.757Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:14.152Z","caller":"events/working_dir.go:265","msg":"**************************************************(HasDiverged)RELEASING READLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:14.152Z","caller":"events/working_dir.go:265","msg":"################################################(HasDiverged)RELEASING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:14.152Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:14.155Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:14.155Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:14.155Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:14.155Z","caller":"models/shell_command_runner.go:117","msg":"starting 'sh -c \"cd $ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\\nexport IAC_REPO_ROOT=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\\nexport TG_WORKING_DIR=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE/$REPO_REL_DIR\\n\\n# echo \\\"Running terragrunt init -reconfigure/-upgrade in $TG_WORKING_DIR\\\"\\nterragrunt init -reconfigure --log-custom-format \\\"%msg\\\" > /dev/null\\nterragrunt init -upgrade --log-custom-format \\\"%msg\\\" > /dev/null\\n\\n# echo \\\"Running terragrunt validate\\\"\\nterragrunt validate --log-custom-format \\\"%msg\\\" > /dev/null\\n\\n# echo \\\"Running terragrunt plan\\\"\\nterragrunt --non-interactive plan -no-color -out=$PLANFILE --log-custom-format \\\"%msg\\\"\\n\"' in '/atlantis-data/repos/wunderkind-co/unsub-api/11/default/iac_tmp/qa/unsub-api-sa'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.662Z","caller":"models/shell_command_runner.go:184","msg":"successfully ran 'sh -c' 'cd $ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\nexport IAC_REPO_ROOT=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE\nexport TG_WORKING_DIR=$ATLANTIS_DATA_DIR/repos/$BASE_REPO_OWNER/$BASE_REPO_NAME/$PULL_NUM/$WORKSPACE/$REPO_REL_DIR\n\n# echo \"Running terragrunt init -reconfigure/-upgrade in $TG_WORKING_DIR\"\nterragrunt init -reconfigure --log-custom-format \"%msg\" > /dev/null\nterragrunt init -upgrade --log-custom-format \"%msg\" > /dev/null\n\n# echo \"Running terragrunt validate\"\nterragrunt validate --log-custom-format \"%msg\" > /dev/null\n\n# echo \"Running terragrunt plan\"\nterragrunt --non-interactive plan -no-color -out=$PLANFILE --log-custom-format \"%msg\"\n' in '/atlantis-data/repos/wunderkind-co/unsub-api/11/default/iac_tmp/qa/unsub-api-sa'","json":{"repo":"wunderkind-co/unsub-api","pull":"11","duration":16.508131765}}
{"level":"info","ts":"2026-04-20T13:21:30.662Z","caller":"github/client.go:959","msg":"Updating GitHub Check status for 'iac-qa/plan: unsub-api-sa' to 'success'","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.663Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.667Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.667Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.668Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.668Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.673Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.674Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.674Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.674Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.679Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.680Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.680Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.680Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.686Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.686Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.686Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.686Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.690Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.690Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.690Z","caller":"events/working_dir.go:130","msg":"clone directory '/atlantis-data/repos/wunderkind-co/unsub-api/11/default' already exists, checking if it's at the right commit","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.690Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.695Z","caller":"events/working_dir.go:362","msg":"Comparing PR ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" to local ref \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\"","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:30.695Z","caller":"events/working_dir.go:137","msg":"repo is at correct commit \"948cd2dfaee764dfe3c573bf420a16a6b9f78eb3\" so will not re-clone","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:30.695Z","caller":"events/working_dir.go:172","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)GETTING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:31.232Z","caller":"github/client.go:969","msg":"POST /repos/wunderkind-co/unsub-api/statuses/948cd2dfaee764dfe3c573bf420a16a6b9f78eb3 returned: 201","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"info","ts":"2026-04-20T13:21:31.233Z","caller":"events/instrumented_project_command_runner.go:91","msg":"plan success. output available at: https://github.com/wunderkind-co/unsub-api/pull/11","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:31.538Z","caller":"events/working_dir.go:238","msg":"------------------------------------------------(recheckDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:31.538Z","caller":"events/working_dir.go:272","msg":"runGitFetch: running git fetch in /atlantis-data/repos/wunderkind-co/unsub-api/11/default","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:32.022Z","caller":"events/working_dir.go:243","msg":"------------------------------------------------(recheckDiverged)RELEASING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:32.022Z","caller":"events/working_dir.go:190","msg":"$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$(MergeAgain)RELEASING WRITE LOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:32.022Z","caller":"events/working_dir.go:253","msg":"################################################(HasDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:32.022Z","caller":"events/working_dir.go:260","msg":"**************************************************(HasDiverged)GETTING READLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}
{"level":"debug","ts":"2026-04-20T13:21:32.980Z","caller":"events/working_dir.go:238","msg":"------------------------------------------------(recheckDiverged)GETTING REFLOCK","json":{"repo":"wunderkind-co/unsub-api","pull":"11"}}

If I ps a, I don't see any subshell executing anything. Everything is stuck. Sending another plan command won't do anything either.

Additional Context

I also tried claude code, asking it to search for potential deadlocks and it did found it. I had my suspicion but it gave me a patch to try, so I tried it and it solved the issue. However, I did not understand why it was working. Adding logs in the unlock functions also fixed the issue (probably because logging does lock/unlock and introduce enough lag to keep deadlock from happening).

Adding the logs as defer did the trick. I could see how many locks we were acquiring and count the number of unlock we were getting. The deadlock in the logs are very apparent that way.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions