Concurrent app creates deadlock on `buildpack_lifecycle_data` (MySQL) since #5065: one_to_one setter issues a no-op un-link UPDATE
Los mantenedores suelen responder en 3 días
Nadie ha tomado este issue todavía.
Evaluación
- Dificultad
- 4/5
- Tiempo estimado
- 3-5 días
- Aptitud para principiantes
- 43/100
Línea de trabajo
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.
Escrito por el modelo de indexación a partir del texto del issue.
Descripción
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.
- Lenguaje dominante
- Ruby
- Estrellas
- 207
- Forks
- 373
- Merge medio
- 2 d 18 h
- PR fusionados (30 d)
- 82
Preparar el entorno
Inicia el contenedor de desarrollo del proyecto en tu navegador, con tu propia cuenta de GitHub.
- Incluye un Dockerfile o un archivo de Docker Compose
- Tiene una plantilla de pull request
- Leer la guía de contribución
Primeros pasos
- Lee el issue completo y luego la guía de contribución del proyecto.
- Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
- Haz un fork del repositorio y trabaja en una rama.
- Abre un pull request que haga referencia al número del issue.
Más de cloudfoundry/cloud_controller_ng
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 72/100
cloudfoundry/cloud_controller_ng#5560 ·
Los mantenedores suelen responder en 3 días
-
Dificultad 1/5 Menos de una hora Aptitud para principiantes 72/100
cloudfoundry/cloud_controller_ng#5255 · 1 comentario ·
Los mantenedores suelen responder en 3 días
-
What field should represent "when was this application last refreshed (pushed or restaged)"?Abierto
Dificultad 5/5 Más de una semana Aptitud para principiantes 35/100
cloudfoundry/cloud_controller_ng#5347 · 2 comentarios ·
Los mantenedores suelen responder en 3 días
-
Dificultad 5/5 Más de una semana Aptitud para principiantes 35/100
cloudfoundry/cloud_controller_ng#5313 ·
Los mantenedores suelen responder en 3 días
-
Dificultad 4/5 3-5 días Aptitud para principiantes 50/100
cloudfoundry/cloud_controller_ng#5285 ·
Los mantenedores suelen responder en 3 días
Todos los issues de cloudfoundry/cloud_controller_ng
Issues similares
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 85/100
Los mantenedores suelen responder en 1 día
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 72/100
Los mantenedores suelen responder en 1 día
-
account: profile
Dificultad 2/5 1-3 horas Aptitud para principiantes 75/100
Los mantenedores suelen responder en 5 días
-
Dificultad 2/5 1-3 horas Aptitud para principiantes 82/100
Los mantenedores suelen responder en 1 día
-
bug good first issue help wanted
Dificultad 2/5 1-3 horas Aptitud para principiantes 90/100
ysb3996-blip/oops#24 ·
Los mantenedores suelen responder en 1 día