payloadcms / payload

Payload is the open-source, fullstack Next.js framework, giving you instant backend superpowers. Get a full TypeScript backend and admin panel instantly. Use Payload as a headless CMS or for building powerful applications.
https://payloadcms.com
MIT License
23.37k stars 1.49k forks source link

db-postgres and nested-docs-plugin can lead to deadlocks generating the breadcrumb #7788

Open yobottehg opened 4 weeks ago

yobottehg commented 4 weeks ago

Link to reproduction

No response

Payload Version

3.0.0-beta.78

Node Version

20 LTS

Next.js Version

15.104

Describe the Bug

In our production logs we have some entries of deadlocks. I'm unsure when this happens or how this can happen but perhaps anyone has an idea?

Server logs:

[14:53:04] ERROR: There was an error while saving a version for the Page with ID 3.
[14:53:04] ERROR: deadlock detected
    err: {
      "type": "DatabaseError",
      "message": "deadlock detected",
      "stack":
          error: deadlock detected
              at /app/node_modules/pg/lib/client.js:526:17
              at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
              at <anonymous> (webpack://babu-cms/node_modules/@payloadcms/db-postgres/node_modules/drizzle-orm/node-postgres/session.js:47:1)
              at Object.oE (webpack://babu-cms/node_modules/@payloadcms/db-postgres/dist/insert.js:7:1)
              at tE (webpack://babu-cms/node_modules/@payloadcms/drizzle/dist/upsertRow/insertArrays.js:41:1)
              at tk (webpack://babu-cms/node_modules/@payloadcms/drizzle/dist/upsertRow/index.js:271:1)
              at Object.iu (webpack://babu-cms/node_modules/@payloadcms/drizzle/dist/updateVersion.js:22:1)
              at l (webpack://babu-cms/node_modules/payload/dist/versions/saveVersion.js:53:1)
              at P (webpack://babu-cms/node_modules/payload/dist/collections/operations/updateByID.js:221:1)
              at Object.tW (webpack://babu-cms/node_modules/@payloadcms/next/dist/routes/rest/collections/updateByID.js:16:1)
      "length": 445,
      "name": "error",
      "severity": "ERROR",
      "code": "40P01",
      "detail": "Process 2526203 waits for ShareLock on transaction 27702; blocked by process 2526153.\nProcess 2526153 waits for ShareLock on transaction 27703; blocked by process 2526203.",
      "hint": "See server log for query details.",
      "where": "while locking tuple (0,52) in relation \"pages\"\nSQL statement \"SELECT 1 FROM ONLY \"public\".\"pages\" x WHERE \"id\" OPERATOR(pg_catalog.=) $1 FOR KEY SHARE OF x\"",
      "file": "deadlock.c",
      "line": "1130",
      "routine": "DeadLockReport"
    }
[14:53:04] ERROR: TypeError: Cannot read properties of undefined (reading 'title')
    at promise (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/promise.js:23:73)
    at <anonymous> (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/traverseFields.js:4:28)
    at Array.forEach (<anonymous>)
    at traverseFields (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/traverseFields.js:3:1)
    at promise (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/promise.js:413:17)
    at <anonymous> (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/traverseFields.js:4:28)
    at Array.forEach (<anonymous>)
    at traverseFields (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/traverseFields.js:3:1)
    at promise (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/promise.js:441:17)
    at <anonymous> (webpack://babu-cms/node_modules/payload/dist/fields/hooks/afterRead/traverseFields.js:4:28)

Postgres logs:

2024-08-20 16:24:04.245 CEST [2815046] sa-cms-db@cms ERROR:  deadlock detected
2024-08-20 16:24:04.245 CEST [2815046] sa-cms-db@cms DETAIL:  Process 2815046 waits for ShareLock on transaction 31221; blocked by process 2815251.
    Process 2815251 waits for ShareLock on transaction 31222; blocked by process 2815046.
    Process 2815046: insert into "_pages_v_version_breadcrumbs" ("_order", "_parent_id", "_locale", "id", "doc_id", "url", "label", "_uuid") values ($1, $2, $3, default, $4, $5, $6, $7), ($8, $9, $10, default, $11, $12, $13, $14), ($15, $16, $17, default, $18, $19, $20, $21), ($22, $23, $24, default, $25, $26, $27, $28) returning "_order", "_parent_id", "_locale", "id", "doc_id", "url", "label", "_uuid"
    Process 2815251: 
          UPDATE "_pages_v"
          SET latest = false
          WHERE "_pages_v"."id" != $1
            AND "_pages_v"."parent_id" = $2

2024-08-20 16:24:04.245 CEST [2815046] sa-cms-db@cms HINT:  See server log for query details.
2024-08-20 16:24:04.245 CEST [2815046] sa-cms-db@cms CONTEXT:  while locking tuple (0,19) in relation "pages"
    SQL statement "SELECT 1 FROM ONLY "public"."pages" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR KEY SHARE OF x"
2024-08-20 16:24:04.245 CEST [2815046] sa-cms-db@cms STATEMENT:  insert into "_pages_v_version_breadcrumbs" ("_order", "_parent_id", "_locale", "id", "doc_id", "url", "label", "_uuid") values ($1, $2, $3, default, $4, $5, $6, $7), ($8, $9, $10, default, $11, $12, $13, $14), ($15, $16, $17, default, $18, $19, $20, $21), ($22, $23, $24, default, $25, $26, $27, $28) returning "_order", "_parent_id", "_locale", "id", "doc_id", "url", "label", "_uuid"

From postgres logs it seems to be related to versions, drafts and the nested_docs plugin with it's breadcrumb field.

Reproduction Steps

Currently unsure.

Adapters and Plugins

db-postgres

sowasred commented 3 weeks ago

I started having the same issue in my dev encironment as well. It happens sporadically and I'm not sure how to replicate it.

Payload Version 2.0.0

Node Version 21.6.1

Next.js Version 13.5.2

Server logs

ozan@Ozans-Air ecommerce % yarn dev
yarn run v1.22.19
$ cross-env PAYLOAD_CONFIG_PATH=src/payload/payload.config.ts nodemon
[nodemon] 2.0.22
[nodemon] to restart at any time, enter `rs`
[nodemon] watching path(s): server.ts
[nodemon] watching extensions: js,ts
[nodemon] starting `ts-node --project tsconfig.server.json src/server.ts -- -I`
(node:71462) [DEP0040] DeprecationWarning: The `punycode` module is deprecated. Please use a userland alternative instead.
(Use `node --trace-deprecation ...` to show where the warning was created)
unhandledRejection error: deadlock detected
    at /Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/pg-pool/index.js:45:11
    at processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async DrizzleORMPgClient.query (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/drizzle-kit/payload.js:34498:21)
    at async apply (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/drizzle-kit/payload.js:36648:9)
    at async Object.connect (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/@payloadcms/db-postgres/src/connect.ts:124:3)
    at async BasePayload.init (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/payload/src/payload.ts:372:7)
    at async getPayload (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/payload/src/payload.ts:443:22)
    at async initHTTP (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/payload/src/initHTTP.ts:33:19)
    at async Payload.init (/Users/ozan/Desktop/Desktop/code/techfi/ecommerce/node_modules/payload/src/index.ts:17:21) {
  length: 321,
  severity: 'ERROR',
  code: '40P01',
  detail: 'Process 5336 waits for AccessExclusiveLock on relation 16743 of database 16384; blocked by process 5351.\n' +
    'Process 5351 waits for AccessShareLock on relation 18989 of database 16384; blocked by process 5336.',
  hint: 'See server log for query details.',
  position: undefined,
  internalPosition: undefined,
  internalQuery: undefined,
  where: undefined,
  schema: undefined,
  table: undefined,
  column: undefined,
  dataType: undefined,
  constraint: undefined,
  file: 'deadlock.c',
  line: '1130',
  routine: 'DeadLockReport'
}
[nodemon] app crashed - waiting for file changes before starting...

Postgres Logs

    Process 5348: select "pages"."id", "pages"."title", "pages"."published_on", "pages"."hero_type", "pages"."hero_rich_text", "pages"."slug", "pages"."meta_title", "pages"."meta_description", "pages"."updated_at", "pages"."created_at", "pages"."_status", "pages__rels"."data" as "_rels", "pages_hero_links"."data" as "hero_links", "pages__blocks_cta"."data" as "_blocks_cta", "pages__blocks_content"."data" as "_blocks_content", "pages__blocks_mediaBlock"."data" as "_blocks_mediaBlock", "pages__blocks_archive"."data" as "_blocks_archive" from "pages" left join lateral (select coalesce(json_agg(json_build_array("pages__rels"."order", "pages__rels"."path", "pages__rels"."pages_id", "pages__rels"."media_id", "pages__rels"."categories_id", "pages__rels"."products_id") order by "pages__rels"."order" asc), '[]'::json) as "data" from (select * from "pages_rels" "pages__rels" where "pages__rels"."parent_id" = "pages"."id" order by "pages__rels"."order" asc) "pages__rels") "pages__rels" on true left join lateral (select coalesce(json_agg

    Process 5336: ALTER TABLE "pages_hero_links" DROP CONSTRAINT "pages_hero_links_parent_id_fk";

2024-08-28 02:10:18.595 UTC [5348] HINT:  See server log for query details.

2024-08-28 02:10:18.595 UTC [5348] STATEMENT:  select "pages"."id", "pages"."title", "pages"."published_on", "pages"."hero_type", "pages"."hero_rich_text", "pages"."slug", "pages"."meta_title", "pages"."meta_description", "pages"."updated_at", "pages"."created_at", "pages"."_status", "pages__rels"."data" as "_rels", "pages_hero_links"."data" as "hero_links", "pages__blocks_cta"."data" as "_blocks_cta", "pages__blocks_content"."data" as "_blocks_content", "pages__blocks_mediaBlock"."data" as "_blocks_mediaBlock", "pages__blocks_archive"."data" as "_blocks_archive" from "pages" left join lateral (select coalesce(json_agg(json_build_array("pages__rels"."order", "pages__rels"."path", "pages__rels"."pages_id", "pages__rels"."media_id", "pages__rels"."categories_id", "pages__rels"."products_id") order by "pages__rels"."order" asc), '[]'::json) as "data" from (select * from "pages_rels" "pages__rels" where "pages__rels"."parent_id" = "pages"."id" order by "pages__rels"."order" asc) "pages__rels") "pages__rels" on true left join lateral (select coalesce(json_agg(json_build_array("pages_hero_links"."_order", "pages_hero_links"."id", "pages_hero_links"."link_type", "pages_hero_links"."link_new_tab", "pages_hero_links"."link_url", "pages_hero_links"."link_label", "pages_hero_links"."link_appearance") order by "pages_hero_links"."_order" asc), '[]'::json) as "data" from (select * from "pages_hero_links" where "pages_hero_links"."_parent_id" = "pages"."id" order by "pages_hero_links"."_order" asc) "pages_hero_links") "pages_hero_links" on true left join lateral (select coalesce(json_agg(json_build_array("pages__blocks_cta"."_order", "pages__blocks_cta"."_path", "pages__blocks_cta"."id", "pages__blocks_cta"."invert_background", "pages__blocks_cta"."rich_text", "pages__blocks_cta"."block_name", "pages__blocks_cta_links"."data") order by "pages__blocks_cta"."_order" asc), '[]'::json) as "data" from (select * from "pages_blocks_cta" "pages__blocks_cta" where "pages__blocks_cta"."_parent_id" = "pages"."id" order by "pages__blocks_cta"."_order" asc) "pages__blocks_cta" left join lateral (select coalesce(json_agg(json_build_array("pages__blocks_cta_links"."_order", "pages__blocks_cta_links"."id", "pages__blocks_cta_links"."link_type", "pages__blocks_cta_links"."link_new_tab", "pages__blocks_cta_links"."link_url", "pages__blocks_cta_links"."link_label", "pages__blocks_cta_links"."link_appearance") order by "pages__blocks_cta_links"."_order" asc), '[]'::json) as "data" from (select * from "pages_blocks_cta_links" "pages__blocks_cta_links" where "pages__blocks_cta_links"."_parent_id" = "pages__blocks_cta"."id" order by "pages__blocks_cta_links"."_order" asc) "pages__blocks_cta_links") "pages__blocks_cta_links" on true) "pages__blocks_cta" on true left join lateral (select coalesce(json_agg(json_build_array("pages__blocks_content"."_order", "pages__blocks_content"."_path", "pages__blocks_content"."id", "pages__blocks_content"."invert_background", "pages__blocks_content"."block_name", "pages__blocks_content_columns"."data") order by "pages__blocks_content"."_order" asc), '[]'::json) as "data" from (select * from "pages_blocks_content" "pages__blocks_content" where "pages__blocks_content"."_parent_id" = "pages"."id" order by "pages__blocks_content"."_order" asc) "pages__blocks_content" left join lateral (select coalesce(json_agg(json_build_array("pages__blocks_content_columns"."_order", "pages__blocks_content_columns"."id", "pages__blocks_content_columns"."size", "pages__blocks_content_columns"."rich_text", "pages__blocks_content_columns"."enable_link", "pages__blocks_content_columns"."link_type", "pages__blocks_content_columns"."link_new_tab", "pages__blocks_content_columns"."link_url", "pages__blocks_content_columns"."link_label", "pages__blocks_content_columns"."link_appearance") order by "pages__blocks_content_columns"."_order" asc), '[]'::json) as "data" from (select * from "pages_blocks_content_columns" "pages__blocks_content_columns" where "pages__blocks_content_columns"."_parent_id" = "pages__blocks_content"."id" order by "pages__blocks_content_columns"."_order" asc) "pages__blocks_content_columns") "pages__blocks_content_columns" on true) "pages__blocks_content" on true left join lateral (select coalesce(json_agg(json_build_array("pages__blocks_mediaBlock"."_order", "pages__blocks_mediaBlock"."_path", "pages__blocks_mediaBlock"."id", "pages__blocks_mediaBlock"."invert_background", "pages__blocks_mediaBlock"."position", "pages__blocks_mediaBlock"."block_name") order by "pages__blocks_mediaBlock"."_order" asc), '[]'::json) as "data" from (select * from "pages_blocks_media_block" "pages__blocks_mediaBlock" where "pages__blocks_mediaBlock"."_parent_id" = "pages"."id" order by "pages__blocks_mediaBlock"."_order" asc) "pages__blocks_mediaBlock") "pages__blocks_mediaBlock" on true left join lateral (select coalesce(json_agg(json_build_array("pages__blocks_archive"."_order", "pages__blocks_archive"."_path", "pages__blocks_archive"."id", "pages__blocks_archive"."intro_content", "pages__blocks_archive"."populateBy", "pages__blocks_archive"."relationTo", "pages__blocks_archive"."limit", "pages__blocks_archive"."populated_docs_total", "pages__blocks_archive"."block_name") order by "pages__blocks_archive"."_order" asc), '[]'::json) as "data" from (select * from "pages_blocks_archive" "pages__blocks_archive" where "pages__blocks_archive"."_parent_id" = "pages"."id" order by "pages__blocks_archive"."_order" asc) "pages__blocks_archive") "pages__blocks_archive" on true where ("pages"."id" in ($1) and "pages"."_status" = $2) order by "pages"."created_at" desc

2024-08-28 02:10:18.600 UTC [5336] ERROR:  deadlock detected

2024-08-28 02:10:18.600 UTC [5336] DETAIL:  Process 5336 waits for AccessExclusiveLock on relation 16743 of database 16384; blocked by process 5351.

    Process 5351 waits for AccessShareLock on relation 18989 of database 16384; blocked by process 5336.

    Process 5336: ALTER TABLE "pages_hero_links" DROP CONSTRAINT "pages_hero_links_parent_id_fk";

    Process 5351: select "pages"."id", "pages"."title", "pages"."published_on", "pages"."hero_type", "pages"."hero_rich_text", "pages"."slug", "pages"."meta_title", "pages"."meta_description", "pages"."updated_at", "pages"."created_at", "pages"."_status", "pages__rels"."data" as "_rels", "pages_hero_links"."data" as "hero_links", "pages__blocks_cta"."data" as "_blocks_cta", "pages__blocks_content"."data" as "_blocks_content", "pages__blocks_mediaBlock"."data" as "_blocks_mediaBlock", "pages__blocks_archive"."data" as "_blocks_archive" from "pages" left join lateral (select coalesce(json_agg(json_build_array("pages__rels"."order", "pages__rels"."path", "pages__rels"."pages_id", "pages__rels"."media_id", "pages__rels"."categories_id", "pages__rels"."products_id") order by "pages__rels"."order" asc), '[]'::json) as "data" from (select * from "pages_rels" "pages__rels" where "pages__rels"."parent_id" = "pages"."id" order by "pages__rels"."order" asc) "pages__rels") "pages__rels" on true left join lateral (select coalesce(json_agg

2024-08-28 02:10:18.600 UTC [5336] HINT:  See server log for query details.

2024-08-28 02:10:18.600 UTC [5336] STATEMENT:  ALTER TABLE "pages_hero_links" DROP CONSTRAINT "pages_hero_links_parent_id_fk";

2024-08-28 02:13:41.288 UTC [26] LOG:  checkpoint starting: tim