Concurrent app creates deadlock on `buildpack_lifecycle_data` (MySQL) since #5065: one_to_one setter issues a no-op un-link UPDATE
Mantenedores costumam responder em até 3 dias
Ninguém assumiu esta issue ainda.
Avaliação
- Dificuldade
- 4/5
- Tempo estimado
- 3-5 dias
- Facilidade para iniciantes
- 43/100
Direção de pesquisa
Start by reading the lifecycle data assignments in lib/cloud_controller/diego/lifecycles/app_buildpack_lifecycle.rb, then compare the same setter pattern in the four other listed lifecycle and droplet creation sites. The issue includes repro.sh for reproducing the deadlock with MySQL 8.4; run it with ./repro.sh 4 setter and compare with ./repro.sh 4 fix. Done means concurrent creates no longer deadlock, including on small tables under REPEATABLE-READ.
Escrita pelo modelo de indexação a partir do texto da issue.
Descrição
Summary
Since #5065 (6e6d356581cd355964058a44307d817f865c9bcf), every app, build and droplet create assigns its new lifecycle data through Sequel's one_to_one setter. The setter first "un-links" any other row that belongs to the parent. It does that by running an extra UPDATE inside the create transaction:
UPDATE `buildpack_lifecycle_data` SET `app_guid` = NULL
WHERE ((`app_guid` = '<new app guid>') AND (`id` != <new row id>)) LIMIT 1
For a parent that was just created, no other row can match, so the UPDATE never changes anything. It still takes exclusive locks on every row it scans.
On MySQL at the default REPEATABLE-READ, with a small buildpack_lifecycle_data table, the optimizer scans PRIMARY instead of using the app_guid index. Two concurrent app creates then deadlock:
- Each transaction holds the lock on its own new row.
- Each one waits on rows the other has locked.
One transaction is rolled back. The client gets 500 UnknownError (10001).
Where it comes from
lib/cloud_controller/diego/lifecycles/app_buildpack_lifecycle.rb (the same pattern in all sites below):
def create_lifecycle_data_model(app)
app.buildpack_lifecycle_data = BuildpackLifecycleDataModel.create( # before #5065: BuildpackLifecycleDataModel.create(...)
buildpacks:,
stack:,
app:
)
end
- The caller: this runs inside
AppModel.db.transactioninAppCreate#create(app/actions/app_create.rb:23,31), so the INSERT and the UPDATE share one transaction. - The association:
AppModeldeclaresone_to_one :buildpack_lifecycle_data, key: :app_guid, primary_key: :guid. - The setter: the UPDATE comes from Sequel's one_to_one setter (associations.rb L2602–2629 in 5.108.0). It filters on the key, adds
exclude(o.pk_hash), then runsupdate(key => nil)withLIMIT 1.
Setter assignments added by #5065, all still on main:
| File | Un-links on |
|---|---|
lib/cloud_controller/diego/lifecycles/app_buildpack_lifecycle.rb |
buildpack_lifecycle_data.app_guid |
lib/cloud_controller/diego/lifecycles/app_cnb_lifecycle.rb |
cnb_lifecycle_data.app_guid |
lib/cloud_controller/diego/lifecycles/buildpack_lifecycle.rb |
buildpack_lifecycle_data.build_guid |
lib/cloud_controller/diego/lifecycles/cnb_lifecycle.rb |
cnb_lifecycle_data.build_guid |
app/actions/droplet_create.rb:24 |
buildpack_lifecycle_data.droplet_guid |
Example (observed)
Setup: a freshly deployed foundation with CAPI 1.250.0 and Percona XtraDB Cluster 8.4. Three cf push (apply_manifest → AppFindOrCreateSkeleton → AppCreate, binary_buildpack) were issued within about 30 ms of each other, each into a different space. One of them failed.
cloud_controller_ng.log (backtrace trimmed to CC frames):
Request failed: 500: {"errors" => [{"title" => "UnknownError", "detail" => "An unknown error occurred.", "code" => 10001,
"test_mode_info" => {"detail" => "Mysql2::Error: Deadlock found when trying to get lock; try restarting transaction",
"title" => "CF-SerializationFailure", "backtrace" => [
lib/cloud_controller/diego/lifecycles/app_buildpack_lifecycle.rb:21:in 'AppBuildpackLifecycle#create_lifecycle_data_model'
app/actions/app_create.rb:31:in 'block in AppCreate#create'
app/actions/app_create.rb:23:in 'AppCreate#create'
app/actions/app_find_or_create_skeleton.rb:16:in 'AppFindOrCreateSkeleton#find_or_create'
app/controllers/v3/space_manifests_controller.rb:45:in 'block in SpaceManifestsController#apply_manifest'
SHOW ENGINE INNODB STATUS, LATEST DETECTED DEADLOCK (record dumps replaced by the row ids):
*** (1) TRANSACTION: ACTIVE 0 sec fetching rows
UPDATE `buildpack_lifecycle_data` SET `app_guid` = NULL WHERE ((`app_guid` = '0f0f0f7a-…') AND (`id` != 6)) LIMIT 1
*** (1) HOLDS THE LOCK(S):
index PRIMARY ... lock_mode X <- ids 1, 2, 3, 4 (scanned)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
index PRIMARY ... lock_mode X waiting <- id 5 (trx 2's uncommitted new row)
*** (2) TRANSACTION: ACTIVE 0 sec starting index read
UPDATE `buildpack_lifecycle_data` SET `app_guid` = NULL WHERE ((`app_guid` = '2625ac4f-…') AND (`id` != 5)) LIMIT 1
*** (2) HOLDS THE LOCK(S):
index PRIMARY ... lock_mode X locks rec but not gap <- id 5 (its own INSERT)
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
index PRIMARY ... lock_mode X waiting <- id 1
*** WE ROLL BACK TRANSACTION (2)
Table size and plan: the table held about 6 rows at the time. A few minutes later, at 10 rows, EXPLAIN of the same UPDATE chose key: buildpack_lifecycle_data_app_guid, type: range. New and small foundations, typically CI and acceptance environments, are the ones that get the scan.
Reproduction
Plain SQL in two client sessions against mysql:8.4 in Docker, with no CC involved. The table matches the migrations (13 columns and the same indexes) and is seeded with N rows. Steps:
| Step | Session A | Session B |
|---|---|---|
| 1 | BEGIN; INSERT … app_guid='aaaa…' → id 5 |
|
| 2 | BEGIN; INSERT … app_guid='bbbb…' → id 6 |
|
| 3 | UPDATE … SET app_guid=NULL WHERE app_guid='bbbb…' AND id != 6 LIMIT 1X-locks ids 1–4, waits on 5 |
|
| 4 | UPDATE … SET app_guid=NULL WHERE app_guid='aaaa…' AND id != 5 LIMIT 1waits on 1 → ERROR 1213 (40001) |
resumes, commits |
performance_schema.data_locks after step 3:
| thread | index_name | lock_mode | lock_status | lock_data |
| 66 | PRIMARY | X,REC_NOT_GAP | GRANTED | 5 | <- A's own INSERT
| 67 | PRIMARY | X | GRANTED | 1 | <- B's scan
| 67 | PRIMARY | X | GRANTED | 2 |
| 67 | PRIMARY | X | GRANTED | 3 |
| 67 | PRIMARY | X | GRANTED | 4 |
| 67 | PRIMARY | X | WAITING | 5 |
The InnoDB deadlock record has the same shape as the production one above: the same two UPDATEs, (1) holding ids 1–4 and waiting on 5, (2) holding 5 and waiting on 1.
Results (setter = INSERT + un-link UPDATE, as CC does today; fix = INSERT only):
| Case | Plan for the UPDATE | Result |
|---|---|---|
setter, 4 rows, REPEATABLE-READ (MySQL 8.4, also Percona Server 8.4.11, 5/5 runs) |
PRIMARY | Deadlock. A rolled back, only B's row committed. |
fix, 4 rows |
n/a | No deadlock. Both rows committed. |
setter, 4 rows, READ-COMMITTED |
PRIMARY | No deadlock (no next-key locks) |
setter, 5 rows |
mixed (B index, A PRIMARY) | A waits about 1 s on B, then succeeds |
setter, 6 / 8 / 10 / 16 / 32 / 64 rows |
buildpack_lifecycle_data_app_guid |
No deadlock, but A still waits on B's lock (about 1 s, the time until B commits) |
Run it with ./repro.sh 4 setter and ./repro.sh 4 fix. ISOLATION=READ-COMMITTED and IMAGE=<mysql-compatible image> are optional overrides.
repro.sh
#!/usr/bin/env bash
# Deterministic repro of the CC buildpack_lifecycle_data deadlock (cloud_controller_ng#5065).
#
# Two sessions play two concurrent AppCreate transactions step by step:
# both INSERT their lifecycle row, then both run the un-link UPDATE that Sequel's one_to_one
# setter issues (associations.rb L2605-2625). A third session snapshots InnoDB locks in between.
#
# usage: repro.sh <seed_rows> <mode>
# mode = setter : CC since #5065 (INSERT + un-link UPDATE)
# fix : proposed fix / pre-#5065 behaviour (INSERT only, no UPDATE)
# env: ISOLATION (default REPEATABLE-READ), IMAGE (default mysql:8.4)
set -euo pipefail
SEED=${1:?seed rows}; MODE=${2:?setter|fix}
ISOLATION=${ISOLATION:-REPEATABLE-READ}; IMAGE=${IMAGE:-mysql:8.4}
C=ccdl-repro; OUT=$(cd "$(dirname "$0")" && pwd)/out/${SEED}-${MODE}-${ISOLATION}; mkdir -p "$OUT"
my() { docker exec -i "$C" mysql -uroot -prepro --unbuffered -vvv -n "$@" 2>&1 | grep -v 'Using a password'; }
if ! docker ps --format '{{.Names}}' | grep -qx "$C"; then
docker run -d --rm --name "$C" -e MYSQL_ROOT_PASSWORD=repro -e MYSQL_DATABASE=ccdb "$IMAGE" >/dev/null
until docker exec "$C" mysql -uroot -prepro -e 'select 1' ccdb >/dev/null 2>&1; do sleep 2; done
fi
docker exec "$C" mysql -uroot -prepro -e "SET GLOBAL transaction_isolation='$ISOLATION'" 2>/dev/null
# Table as built by db/migrations (create_buildpack_lifecycle_data + later alters); 13 columns,
# matching the 15-field records (13 + trx id + roll ptr) in the production deadlock dump.
my ccdb >/dev/null <<SQL
DROP TABLE IF EXISTS buildpack_lifecycle_data;
CREATE TABLE buildpack_lifecycle_data (
id int NOT NULL AUTO_INCREMENT PRIMARY KEY,
guid varchar(255) NOT NULL,
created_at timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,
updated_at timestamp NULL,
app_guid varchar(255), droplet_guid varchar(255), stack varchar(255),
salt varchar(255), encrypted_buildpack_url varchar(255), build_guid varchar(255),
encryption_key_label varchar(255), encryption_iterations int NOT NULL DEFAULT 2048,
admin_buildpack_name varchar(255),
UNIQUE KEY buildpack_lifecycle_data_guid_index (guid),
KEY buildpack_lifecycle_data_created_at_index (created_at),
KEY buildpack_lifecycle_data_updated_at_index (updated_at),
KEY buildpack_lifecycle_data_app_guid (app_guid),
KEY bp_lifecycle_data_droplet_guid (droplet_guid),
KEY buildpack_lifecycle_data_admin_buildpack_name_index (admin_buildpack_name),
KEY buildpack_lifecycle_data_build_guid_index (build_guid)
);
INSERT INTO buildpack_lifecycle_data (guid, app_guid, stack)
WITH RECURSIVE n(i) AS (SELECT 1 UNION ALL SELECT i+1 FROM n WHERE i < $SEED)
SELECT uuid(), uuid(), 'cflinuxfs4' FROM n;
ALTER TABLE buildpack_lifecycle_data AUTO_INCREMENT = $((SEED+1));
ANALYZE TABLE buildpack_lifecycle_data;
SQL
A=aaaaaaaa-0000-0000-0000-00000000000a; B=bbbbbbbb-0000-0000-0000-00000000000b
ins() { echo "INSERT INTO buildpack_lifecycle_data (guid, app_guid, stack) VALUES (uuid(), '$1', 'cflinuxfs4'); SELECT LAST_INSERT_ID() AS new_id;"; }
# Literal id, exactly as Sequel sends it (up_ds.exclude(o.pk_hash)).
unlink() { echo "UPDATE buildpack_lifecycle_data SET app_guid = NULL WHERE ((app_guid = '$1') AND (id != $2)) LIMIT 1;"; }
locks() {
echo "== locks: $1" >>"$OUT/locks.txt"
my -t performance_schema >>"$OUT/locks.txt" <<'SQL'
SELECT t.trx_mysql_thread_id AS thread, l.index_name, l.lock_mode, l.lock_status, l.lock_data
FROM data_locks l JOIN information_schema.innodb_trx t ON t.trx_id = l.engine_transaction_id
WHERE l.lock_type = 'RECORD' ORDER BY thread, l.lock_status, l.lock_data;
SQL
}
my ccdb >"$OUT/explain.txt" <<SQL
EXPLAIN UPDATE buildpack_lifecycle_data SET app_guid = NULL WHERE ((app_guid = '$A') AND (id != $((SEED+1)))) LIMIT 1;
SQL
: >"$OUT/locks.txt"
rm -f "$OUT"/fa "$OUT"/fb; mkfifo "$OUT/fa" "$OUT/fb"
my --force ccdb <"$OUT/fa" >"$OUT/session-a.txt" & PA=$!
my --force ccdb <"$OUT/fb" >"$OUT/session-b.txt" & PB=$!
exec 3>"$OUT/fa" 4>"$OUT/fb"
step() { sleep 1; }
echo "BEGIN; SELECT CONNECTION_ID() AS session_a; $(ins $A)" >&3; step # A inserts id SEED+1
echo "BEGIN; SELECT CONNECTION_ID() AS session_b; $(ins $B)" >&4; step # B inserts id SEED+2
if [ "$MODE" = setter ]; then
echo "$(unlink $B $((SEED+2)))" >&4; step; locks "after B's un-link UPDATE" # production trx (1)
echo "$(unlink $A $((SEED+1)))" >&3; step; locks "after A's un-link UPDATE" # production trx (2)
fi
echo "COMMIT;" >&3; echo "COMMIT;" >&4; exec 3>&- 4>&-
wait $PA $PB || true
my ccdb >"$OUT/innodb-status.txt" <<<'SHOW ENGINE INNODB STATUS\G'
echo "seed=$SEED mode=$MODE isolation=$ISOLATION image=$IMAGE"
echo "explain: $(grep -E '^\| +1 ' "$OUT/explain.txt" | awk -F'|' '{gsub(/ /,""); print "type=" $6, "key=" $8, "rows=" $11}')"
grep -hE 'ERROR|Query OK|rows affected' "$OUT"/session-*.txt | sed 's/^/ /' | sort | uniq -c
my ccdb <<<'SELECT id, app_guid FROM buildpack_lifecycle_data WHERE app_guid LIKE "aaaa%" OR app_guid LIKE "bbbb%";' | grep -E '^\| *[0-9]' || echo " (no A/B rows committed)"
echo "out: $OUT"
Expected
Creating an app, build or droplet shouldn't issue an un-link UPDATE for an association that can't have a previous value. Concurrent creates in different spaces shouldn't be able to deadlock each other.
Suggested fix
The #5065 description says the assignment "avoids Sequel caching issues", so the goal is to populate the in-memory association. Doing that directly avoids the setter's database side effect:
def create_lifecycle_data_model(app)
app.associations[:buildpack_lifecycle_data] = BuildpackLifecycleDataModel.create(
buildpacks:,
stack:,
app:
)
end
The same change applies to the other four sites listed above. A spec could check that AppCreate and BuildCreate issue no UPDATE … SET app_guid = NULL or SET build_guid = NULL.
Notes
- We've only tested the SQL behaviour above, not the CC code change.
- Postgres is untested.
- Related, but a separate problem: #5313, about shared lifecycle_data rows between a build and a droplet.
- Linguagem predominante
- Ruby
- Estrelas
- 207
- Forks
- 373
- Merge médio
- 2d 18h
- PRs com merge (30d)
- 82
Preparar o ambiente
Inicia o contêiner de desenvolvimento do projeto no navegador, com a sua própria conta do GitHub.
- Inclui um Dockerfile ou arquivo Docker Compose
- Tem um modelo de pull request
- Ler o guia de contribuição
Primeiros passos
- Leia a issue inteira e depois o guia de contribuição do projeto.
- Comente na issue dizendo que vai assumir — evita que duas pessoas façam o mesmo trabalho.
- Faça um fork do repositório e trabalhe em uma branch.
- Abra um pull request que referencie o número da issue.
Mais de cloudfoundry/cloud_controller_ng
-
Dificuldade 2/5 1-3 horas Facilidade para iniciantes 72/100
cloudfoundry/cloud_controller_ng#5560 ·
Mantenedores costumam responder em até 3 dias
-
Dificuldade 1/5 Menos de uma hora Facilidade para iniciantes 72/100
cloudfoundry/cloud_controller_ng#5255 · 1 comentário ·
Mantenedores costumam responder em até 3 dias
-
Dificuldade 5/5 Mais de uma semana Facilidade para iniciantes 35/100
cloudfoundry/cloud_controller_ng#5347 · 2 comentários ·
Mantenedores costumam responder em até 3 dias
-
Dificuldade 5/5 Mais de uma semana Facilidade para iniciantes 35/100
cloudfoundry/cloud_controller_ng#5313 ·
Mantenedores costumam responder em até 3 dias
-
Dificuldade 4/5 3-5 dias Facilidade para iniciantes 50/100
cloudfoundry/cloud_controller_ng#5285 ·
Mantenedores costumam responder em até 3 dias
Todas as issues de cloudfoundry/cloud_controller_ng
Issues semelhantes
-
Dificuldade 2/5 1-3 horas Facilidade para iniciantes 85/100
Mantenedores costumam responder em até 1 dia
-
Dificuldade 2/5 1-3 horas Facilidade para iniciantes 72/100
Mantenedores costumam responder em até 1 dia
-
account: profile
Dificuldade 2/5 1-3 horas Facilidade para iniciantes 75/100
Mantenedores costumam responder em até 5 dias
-
Dificuldade 2/5 1-3 horas Facilidade para iniciantes 82/100
Mantenedores costumam responder em até 1 dia
-
bug good first issue help wanted
Dificuldade 2/5 1-3 horas Facilidade para iniciantes 90/100
ysb3996-blip/oops#24 ·
Mantenedores costumam responder em até 1 dia