Skip to content

Data race leading to Multiple Database deadlocks processing 'Delete' Activity #15005

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.

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

Open
1 task done
eternal-flame-AD opened this issue Nov 20, 2024 · 2 comments · Fixed by #15574
Open
1 task done
Labels
🐛Bug Unexpected behavior 🔥high priority packages/backend Server side specific issue/PR

Comments

@eternal-flame-AD
Copy link
Contributor

💡 Summary

リモートから"Delete"と"Update"アクテビティがデータ競合あります、同時に受け取ったら競合を起こりアカウントは削除できません。

Proposed fix (not deployed yet) partially taken from #14752, should also fix #14728 as a side effect : https://forge.yumechi.jp/yume/yumechi-no-kuni/commit/7a581b7e80209c30cef7b47f95efa40e3f0f3797

Partial diff:

diff --git a/packages/backend/src/core/activitypub/ApInboxService.ts b/packages/backend/src/core/activitypub/ApInboxService.ts
index f3aa46292e..fccf86cb91 100644
--- a/packages/backend/src/core/activitypub/ApInboxService.ts
+++ b/packages/backend/src/core/activitypub/ApInboxService.ts
@@ -509,19 +509,12 @@ export class ApInboxService {
 			return `skip: delete actor ${actor.uri} !== ${uri}`;
 		}
 
-		const user = await this.usersRepository.findOneBy({ id: actor.id });
-		if (user == null) {
-			return 'skip: actor not found';
-		} else if (user.isDeleted) {
+		if (!(await this.usersRepository.update({ id: actor.id, isDeleted: false }, { isDeleted: true })).affected) {
 			return 'skip: already deleted';
 		}
 
 		const job = await this.queueService.createDeleteAccountJob(actor);
 
-		await this.usersRepository.update(actor.id, {
-			isDeleted: true,
-		});
-
 		this.globalEventService.publishInternalEvent('remoteUserUpdated', { id: actor.id });
 
 		return `ok: queued ${job.name} ${job.id}`;
diff --git a/packages/backend/src/core/activitypub/models/ApPersonService.ts b/packages/backend/src/core/activitypub/models/ApPersonService.ts
index 8c4e40c561..e01b098194 100644
--- a/packages/backend/src/core/activitypub/models/ApPersonService.ts
+++ b/packages/backend/src/core/activitypub/models/ApPersonService.ts
@@ -557,7 +557,9 @@ export class ApPersonService implements OnModuleInit {
 		if (moving) updates.movedAt = new Date();
 
 		// Update user
-		await this.usersRepository.update(exist.id, updates);
+		if (!(await this.usersRepository.update({ id: exist.id, isDeleted: false }, updates)).affected) {
+			return 'skip';
+		}
 
 		if (person.publicKey) {
 			await this.userPublickeysRepository.update({ userId: exist.id }, {
@@ -662,7 +664,7 @@ export class ApPersonService implements OnModuleInit {
 
 	@bindThis
 	public async updateFeatured(userId: MiUser['id'], resolver?: Resolver): Promise<void> {
-		const user = await this.usersRepository.findOneByOrFail({ id: userId });
+		const user = await this.usersRepository.findOneByOrFail({ id: userId, isDeleted: false });
 		if (!this.userEntityService.isRemoteUser(user)) return;
 		if (!user.featured) return;
 

🥰 Expected Behavior

Delete アクティビティの処理アトミック化にして上にUpdateより優先する。

🤬 Actual Behavior

Deadlockを何回繰り返している

024-11-19 18:30:58.284 UTC [649591] ERROR:  deadlock detected
2024-11-19 18:30:58.284 UTC [649591] DETAIL:  Process 649591 waits for ShareLock on transaction 49746958; blocked by process 649589.
        Process 649589 waits for ShareLock on transaction 49746959; blocked by process 649591.
        Process 649591: DELETE FROM "drive_file" WHERE "id" IN ($1)
        Process 649589: DELETE FROM "user" WHERE "id" IN ($1)
2024-11-19 18:30:58.284 UTC [649591] HINT:  See server log for query details.
2024-11-19 18:30:58.284 UTC [649591] CONTEXT:  while updating tuple (15737,1) in relation "user"
        SQL statement "UPDATE ONLY "public"."user" SET "bannerId" = NULL WHERE $1::pg_catalog.text OPERATOR(pg_catalog.=) "bannerId"::pg_catalog.text"
2024-11-19 18:30:58.284 UTC [649591] STATEMENT:  DELETE FROM "drive_file" WHERE "id" IN ($1)
2024-11-19 18:30:58.333 UTC [649589] LOG:  duration: 1050.252 ms  execute <unnamed>: DELETE FROM "user" WHERE "id" IN ($1)
2024-11-19 18:30:58.333 UTC [649589] DETAIL:  parameters: $1 = '9zlddyw7rq6n0etg'
INFO 2  [remote ap]     Deleting the Actor: https://social.vivaldi.net/users/ismaelwahid
INFO 3  [queue delete-account]  Deleting account of 9zlddyw7rq6n0etg ...
DONE 3  [queue delete-account]  All of notes deleted
DONE 3  [queue delete-account]  All of files deleted
INFO 2  [remote ap]     Updating the Person: https://social.vivaldi.net/users/ismaelwahid
QueryFailedError: deadlock detected
    at PostgresQueryRunner.query (/misskey/node_modules/.pnpm/[email protected][email protected][email protected]/node_modules/typeorm/driver/postgres/PostgresQueryRunner.js:219:19)
    at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
    at async DeleteQueryBuilder.execute (/misskey/node_modules/.pnpm/[email protected][email protected][email protected]/node_modules/typeorm/query-builder/DeleteQueryBuilder.js:52:33) {
  query: 'DELETE FROM "drive_file" WHERE "id" IN ($1)',
  parameters: [ '9zlddz8grq6n0eth' ],
  driverError: error: deadlock detected
      at /misskey/node_modules/.pnpm/[email protected]/node_modules/pg/lib/client.js:535:17
      at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
      at async PostgresQueryRunner.query (/misskey/node_modules/.pnpm/[email protected][email protected][email protected]/node_modules/typeorm/driver/postgres/PostgresQueryRunner.js:184:25)
      at async DeleteQueryBuilder.execute (/misskey/node_modules/.pnpm/[email protected][email protected][email protected]/node_modules/typeorm/query-builder/DeleteQueryBuilder.js:52:33) {
    length: 483,
    severity: 'ERROR',
    code: '40P01',
    detail: 'Process 649591 waits for ShareLock on transaction 49746958; blocked by process 649589.\n' +
      'Process 649589 waits for ShareLock on transaction 49746959; blocked by process 649591.',
    hint: 'See server log for query details.',
    position: undefined,
    internalPosition: undefined,
    internalQuery: undefined,
    where: 'while updating tuple (15737,1) in relation "user"\n' +
      'SQL statement "UPDATE ONLY "public"."user" SET "bannerId" = NULL WHERE $1::pg_catalog.text OPERATOR(pg_catalog.=) "bannerId"::pg_catalog.text"',
    schema: undefined,
    table: undefined,
    column: undefined,
    dataType: undefined,
    constraint: undefined,
    file: 'deadlock.c',
    line: '1147',
    routine: 'DeadLockReport'
  },
  length: 483,
  severity: 'ERROR',
  code: '40P01',
  detail: 'Process 649591 waits for ShareLock on transaction 49746958; blocked by process 649589.\n' +
    'Process 649589 waits for ShareLock on transaction 49746959; blocked by process 649591.',
  hint: 'See server log for query details.',
  position: undefined,
  internalPosition: undefined,
  internalQuery: undefined,
  where: 'while updating tuple (15737,1) in relation "user"\n' +
    'SQL statement "UPDATE ONLY "public"."user" SET "bannerId" = NULL WHERE $1::pg_catalog.text OPERATOR(pg_catalog.=) "bannerId"::pg_catalog.text"',
  schema: undefined,
  table: undefined,
  column: undefined,
  dataType: undefined,
  constraint: undefined,

📝 Steps to Reproduce

I can't reproduce it on purpose but I did contact another instance owner and they observed the same issue ...

前提条件が複雑ために意図的に再現することはできませんが、別のインスタンス所有者に連絡したところ、同じ問題が発生しているそうです。

💻 Frontend Environment

Not frontend issue.

🛰 Backend Environment (for server admin)

* Installation Method or Hosting Service: Docker-compose.yml (https://forge.yumechi.jp/yume/yumechi-no-kuni/src/branch/develop/compose_example.yml)
* Misskey: [2024.11.0-yumechinokuni.5](https://forge.yumechi.jp/yume/yumechi-no-kuni/src/tag/2024.11.0-yumechinokuni.5) (tracking misskey-dev#develop)
* OS and Architecture: Arch Linux x86_64

Reported to be also reproducible on:

https://github.com/paricafe/misskey/tree/pari

Do you want to address this bug yourself?

  • Yes, I will patch the bug myself and send a pull request
@eternal-flame-AD eternal-flame-AD added the ⚠️bug? This might be a bug label Nov 20, 2024
syuilo added a commit that referenced this issue Mar 1, 2025
syuilo added a commit that referenced this issue Mar 1, 2025
kakkokari-gtyih pushed a commit that referenced this issue Mar 1, 2025
syuilo added a commit that referenced this issue Mar 1, 2025
@github-project-automation github-project-automation bot moved this from Todo to Done in [実験中] 管理用 Mar 1, 2025
@syuilo
Copy link
Member

syuilo commented Mar 1, 2025

直ってない

@syuilo syuilo reopened this Mar 1, 2025
@github-project-automation github-project-automation bot moved this from Done to Todo in [実験中] 管理用 Mar 1, 2025
@syuilo syuilo added 🐛Bug Unexpected behavior packages/backend Server side specific issue/PR 🔥high priority and removed ⚠️bug? This might be a bug labels Mar 1, 2025
@eternal-flame-AD
Copy link
Contributor Author

eternal-flame-AD commented Mar 1, 2025

Maybe consider retrying up to 2/3 times, it is accepted practice to do it for frequent mutations.

File diff: https://forge.yumechi.jp/yume/yumechi-no-kuni/commit/7a581b7e80209c30cef7b47f95efa40e3f0f3797#diff-c65816e336a0d7f4b9cccceb04f5f5e07383d9f0

Reference https://dba.stackexchange.com/questions/286040/is-deadlock-detected-really-an-error-should-i-be-suppressing-them-after-handl

Deadlock just means the database spent too much time on conflicting locks and would like to reject one of them for now so it does not cause memory leaks, if the condition is not a true deadlock you can just retry.

ruruke pushed a commit to ruruke/rukey that referenced this issue Mar 1, 2025
syuilo added a commit that referenced this issue Mar 2, 2025
* wip

* wip

* wip

* Update SystemAccountService.ts

* Update 1740121393164-system-accounts.js

* Update DeleteAccountService.ts

* wip

* wip

* wip

* wip

* Update 1740121393164-system-accounts.js

* Update RepositoryModule.ts

* wip

* wip

* wip

* Update ApRendererService.ts

* wip

* wip

* Update SystemAccountService.ts

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* add print logs

* ログが長すぎて出てないかもしれない

* fix migration

* refactor

* fix fed-tests

* Update RelayService.ts

* merge

* Update user.test.ts

* chore: emit log

* fix: tweak sleep duration

* fix: exit 1

* fix: wait for misskey processes to become healthy

* fix: longer sleep for user deletion

* fix: make sleep longer again

* デッドロック解消の試み

#15005

* Revert "デッドロック解消の試み"

This reverts commit 266141f.

* wip

* Update SystemAccountService.ts

---------

Co-authored-by: おさむのひと <[email protected]>
Co-authored-by: zyoshoka <[email protected]>
harumaki2000 pushed a commit to harumaki2000/misskey2000 that referenced this issue Mar 2, 2025
harumaki2000 pushed a commit to harumaki2000/misskey2000 that referenced this issue Mar 2, 2025
* wip

* wip

* wip

* Update SystemAccountService.ts

* Update 1740121393164-system-accounts.js

* Update DeleteAccountService.ts

* wip

* wip

* wip

* wip

* Update 1740121393164-system-accounts.js

* Update RepositoryModule.ts

* wip

* wip

* wip

* Update ApRendererService.ts

* wip

* wip

* Update SystemAccountService.ts

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* add print logs

* ログが長すぎて出てないかもしれない

* fix migration

* refactor

* fix fed-tests

* Update RelayService.ts

* merge

* Update user.test.ts

* chore: emit log

* fix: tweak sleep duration

* fix: exit 1

* fix: wait for misskey processes to become healthy

* fix: longer sleep for user deletion

* fix: make sleep longer again

* デッドロック解消の試み

misskey-dev#15005

* Revert "デッドロック解消の試み"

This reverts commit 266141f.

* wip

* Update SystemAccountService.ts

---------

Co-authored-by: おさむのひと <[email protected]>
Co-authored-by: zyoshoka <[email protected]>
DA-TENSHI pushed a commit to SHINANOSKEY-Projekt/SHINANOSKEY that referenced this issue Mar 6, 2025
DA-TENSHI pushed a commit to SHINANOSKEY-Projekt/SHINANOSKEY that referenced this issue Mar 6, 2025
* wip

* wip

* wip

* Update SystemAccountService.ts

* Update 1740121393164-system-accounts.js

* Update DeleteAccountService.ts

* wip

* wip

* wip

* wip

* Update 1740121393164-system-accounts.js

* Update RepositoryModule.ts

* wip

* wip

* wip

* Update ApRendererService.ts

* wip

* wip

* Update SystemAccountService.ts

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* add print logs

* ログが長すぎて出てないかもしれない

* fix migration

* refactor

* fix fed-tests

* Update RelayService.ts

* merge

* Update user.test.ts

* chore: emit log

* fix: tweak sleep duration

* fix: exit 1

* fix: wait for misskey processes to become healthy

* fix: longer sleep for user deletion

* fix: make sleep longer again

* デッドロック解消の試み

misskey-dev#15005

* Revert "デッドロック解消の試み"

This reverts commit 266141f.

* wip

* Update SystemAccountService.ts

---------

Co-authored-by: おさむのひと <[email protected]>
Co-authored-by: zyoshoka <[email protected]>
ruruke pushed a commit to ruruke/rukey that referenced this issue Mar 6, 2025
* wip

* wip

* wip

* Update SystemAccountService.ts

* Update 1740121393164-system-accounts.js

* Update DeleteAccountService.ts

* wip

* wip

* wip

* wip

* Update 1740121393164-system-accounts.js

* Update RepositoryModule.ts

* wip

* wip

* wip

* Update ApRendererService.ts

* wip

* wip

* Update SystemAccountService.ts

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* add print logs

* ログが長すぎて出てないかもしれない

* fix migration

* refactor

* fix fed-tests

* Update RelayService.ts

* merge

* Update user.test.ts

* chore: emit log

* fix: tweak sleep duration

* fix: exit 1

* fix: wait for misskey processes to become healthy

* fix: longer sleep for user deletion

* fix: make sleep longer again

* デッドロック解消の試み

misskey-dev#15005

* Revert "デッドロック解消の試み"

This reverts commit 266141f.

* wip

* Update SystemAccountService.ts

---------

Co-authored-by: おさむのひと <[email protected]>
Co-authored-by: zyoshoka <[email protected]>
Gingarenpo pushed a commit to Gingarenpo/G-Misskey that referenced this issue Apr 10, 2025
Gingarenpo pushed a commit to Gingarenpo/G-Misskey that referenced this issue Apr 10, 2025
* wip

* wip

* wip

* Update SystemAccountService.ts

* Update 1740121393164-system-accounts.js

* Update DeleteAccountService.ts

* wip

* wip

* wip

* wip

* Update 1740121393164-system-accounts.js

* Update RepositoryModule.ts

* wip

* wip

* wip

* Update ApRendererService.ts

* wip

* wip

* Update SystemAccountService.ts

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* fix tests

* add print logs

* ログが長すぎて出てないかもしれない

* fix migration

* refactor

* fix fed-tests

* Update RelayService.ts

* merge

* Update user.test.ts

* chore: emit log

* fix: tweak sleep duration

* fix: exit 1

* fix: wait for misskey processes to become healthy

* fix: longer sleep for user deletion

* fix: make sleep longer again

* デッドロック解消の試み

misskey-dev/misskey#15005

* Revert "デッドロック解消の試み"

This reverts commit 266141f66fb584371bbb56ef7eba04e14bcff94d.

* wip

* Update SystemAccountService.ts

---------

Co-authored-by: おさむのひと <[email protected]>
Co-authored-by: zyoshoka <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🐛Bug Unexpected behavior 🔥high priority packages/backend Server side specific issue/PR
Projects
Development

Successfully merging a pull request may close this issue.

2 participants