Issue #8750
closedDeadlock on rpm repository pulp2pulp sync
Description
When running repository sync, I am hitting the below deadlock.
The content is a mirror of "http://linux.dell.com/repo/hardware/dsu/os_independent/"
{'child_tasks': [],
'created_resources': [],
'error': {'description': 'deadlock detected\n'
'DETAIL: Process 31559 waits for ShareLock on '
'transaction 4972396; blocked by process 31883.\n'
'Process 31883 waits for ShareLock on transaction '
'4972398; blocked by process 31559.\n'
'HINT: See server log for query details.\n'
'CONTEXT: while inserting index tuple (49588,3) in '
'relation "rpm_package_pkgId_key"\n',
'traceback': ' File '
'"/opt/bats/lib/python3.8/site-packages/rq/worker.py", '
'line 1008, in perform_job\n'
' rv = job.perform()\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/rq/job.py", '
'line 706, in perform\n'
' self._result = self._execute()\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/rq/job.py", '
'line 729, in _execute\n'
' result = self.func(*self.args, **self.kwargs)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/pulp_rpm/app/tasks/synchronizing.py", '
'line 269, in synchronize\n'
' dv.create()\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/pulpcore/plugin/stages/declarative_version.py", '
'line 149, in create\n'
' loop.run_until_complete(pipeline)\n'
' File '
'"/opt/bats/lib/python3.8/asyncio/base_events.py", '
'line 616, in run_until_complete\n'
' return future.result()\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/pulpcore/plugin/stages/api.py", '
'line 225, in create_pipeline\n'
' await asyncio.gather(*futures)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/pulpcore/plugin/stages/api.py", '
'line 43, in __call__\n'
' await self.run()\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/pulpcore/plugin/stages/content_stages.py", '
'line 96, in run\n'
' d_content.content.save()\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/pulpcore/app/models/base.py", '
'line 149, in save\n'
' return super().save(*args, **kwargs)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django_lifecycle/mixins.py", '
'line 134, in save\n'
' save(*args, **kwargs)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/base.py", '
'line 743, in save\n'
' self.save_base(using=using, '
'force_insert=force_insert,\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/base.py", '
'line 780, in save_base\n'
' updated = self._save_table(\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/base.py", '
'line 873, in _save_table\n'
' result = self._do_insert(cls._base_manager, '
'using, fields, update_pk, raw)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/base.py", '
'line 910, in _do_insert\n'
' return manager._insert([self], fields=fields, '
'return_id=update_pk,\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/manager.py", '
'line 82, in manager_method\n'
' return getattr(self.get_queryset(), name)(*args, '
'**kwargs)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/query.py", '
'line 1186, in _insert\n'
' return '
'query.get_compiler(using=using).execute_sql(return_id)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/models/sql/compiler.py", '
'line 1377, in execute_sql\n'
' cursor.execute(sql, params)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 67, in execute\n'
' return self._execute_with_wrappers(sql, params, '
'many=False, executor=self._execute)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 76, in _execute_with_wrappers\n'
' return executor(sql, params, many, context)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 84, in _execute\n'
' return self.cursor.execute(sql, params)\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/utils.py", '
'line 89, in __exit__\n'
' raise dj_exc_value.with_traceback(traceback) from '
'exc_value\n'
' File '
'"/opt/bats/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 84, in _execute\n'
' return self.cursor.execute(sql, params)\n'},
'finished_at': datetime.datetime(2021, 5, 13, 16, 4, 16, 230996, tzinfo=tzutc()),
'logging_cid': '01b00ffb6c684f1a83bd46878184fe5b',
'name': 'pulp_rpm.app.tasks.synchronizing.synchronize',
'parent_task': None,
'progress_reports': [{'code': 'downloading.metadata',
'done': 5,
'message': 'Downloading Metadata Files',
'state': 'canceled',
'suffix': None,
'total': None},
{'code': 'sync.downloading.artifacts',
'done': 5501,
'message': 'Downloading Artifacts',
'state': 'canceled',
'suffix': None,
'total': None},
{'code': 'associating.content',
'done': 5501,
'message': 'Associating Content',
'state': 'canceled',
'suffix': None,
'total': None},
{'code': 'parsing.advisories',
'done': 0,
'message': 'Parsed Advisories',
'state': 'completed',
'suffix': None,
'total': 0},
{'code': 'parsing.packages',
'done': 9010,
'message': 'Parsed Packages',
'state': 'canceled',
'suffix': None,
'total': 34644}],
'pulp_created': datetime.datetime(2021, 5, 13, 15, 8, 17, 924670, tzinfo=tzutc()),
'pulp_href': '/pulp/api/v3/tasks/c4ed6290-a764-4ec3-96a4-1b6ce55597f3/',
'reserved_resources_record': ['/pulp/api/v3/repositories/rpm/rpm/f8bfd15c-a831-4e63-a8f7-2fd3156c97af/',
'/pulp/api/v3/remotes/rpm/rpm/d12fcb7e-9c0f-4226-bf0a-42381f4d9b51/'],
'started_at': datetime.datetime(2021, 5, 13, 15, 8, 18, 18915, tzinfo=tzutc()),
'state': 'failed',
'task_group': None,
'worker': '/pulp/api/v3/workers/b63013da-896e-4882-884a-6f9b9b6410b0/'}
A little context.
I have 3 secondary Pulp3 servers, syncing against a primary Pulp3 server, I kick off a sync of ~130 repositories per secondary in one go.
I've done this 3 times, and I've hit this deadlock on three occasions and so far only on this dell dsu repository.
Let me know if there is any more information that I can provide.
Related issues
Updated by dalley over 3 years ago
- Priority changed from Normal to High
- Triaged changed from No to Yes
- Sprint set to Sprint 97
Updated by wibbit over 3 years ago
Morning all
Additional deadlock hit, not sure if it is related.
2021-06-16 04:45:44|ERROR |Server: ncc1r8.us.daisies.net, Task: /pulp/api/v3/tasks/7c3fdf21-1b21-43dd-b9ad-19bbd98f4a88/ is in a failed state. With message: deadlock detected
DETAIL: Process 21577 waits for ShareLock on transaction 13163681; blocked by process 21565.
Process 21565 waits for ShareLock on transaction 13163680; blocked by process 21577.
HINT: See server log for query details.
CONTEXT: while inserting index tuple (10762,2) in relation "core_artifact_sha256_key"
{'child_tasks': [], [49/129]
'created_resources': [],
'error': {'description': 'deadlock detected\n'
'DETAIL: Process 21577 waits for ShareLock on '
'transaction 13163681; blocked by process 21565.\n'
'Process 21565 waits for ShareLock on transaction '
'13163680; blocked by process 21577.\n'
'HINT: See server log for query details.\n'
'CONTEXT: while inserting index tuple (10762,2) in '
'relation "core_artifact_sha256_key"\n',
'traceback': ' File '
'"/opt/puppies/lib/python3.8/site-packages/pulpcore/tasking/pulpcore_worker.py", '
'line 199, in _perform_task\n'
' result = func(*args, **kwargs)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/pulp_rpm/app/tasks/synchronizing.py", '
'line 383, in synchronize\n'
' version = dv.create()\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/pulpcore/plugin/stages/declarative_version.py", '
'line 151, in create\n'
' loop.run_until_complete(pipeline)\n'
' File '
'"/opt/puppies/lib/python3.8/asyncio/base_events.py", '
'line 616, in run_until_complete\n'
' return future.result()\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/pulpcore/plugin/stages/api.py", '
'line 225, in create_pipeline\n'
' await asyncio.gather(*futures)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/pulpcore/plugin/stages/api.py", '
'line 43, in __call__\n'
' await self.run()\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/pulpcore/plugin/stages/artifact_stages.py", '
'line 240, in run\n'
' Artifact.objects.bulk_get_or_create(\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/pulpcore/app/models/content.py", '
'line 82, in bulk_get_or_create\n'
' return super().bulk_create(objs, '
'batch_size=batch_size)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/models/manager.py", '
'line 82, in manager_method\n'
' return getattr(self.get_queryset(), name)(*args, '
'**kwargs)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/models/query.py", '
'line 468, in bulk_create\n'
' self._batched_insert(objs_with_pk, fields, '
'batch_size, ignore_conflicts=ignore_conflicts)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/models/query.py", '
'line 1202, in _batched_insert\n'
' inserted_id = self._insert(\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/models/query.py", '
'line 1186, in _insert\n'
' return '
'query.get_compiler(using=using).execute_sql(return_id)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/models/sql/compiler.py", '
'line 1377, in execute_sql\n'
' cursor.execute(sql, params)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 67, in execute\n'
' return self._execute_with_wrappers(sql, params, '
'many=False, executor=self._execute)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 76, in _execute_with_wrappers\n'
' return executor(sql, params, many, context)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 84, in _execute\n'
' return self.cursor.execute(sql, params)\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/utils.py", '
'line 89, in __exit__\n'
' raise dj_exc_value.with_traceback(traceback) from '
'exc_value\n'
' File '
'"/opt/puppies/lib/python3.8/site-packages/django/db/backends/utils.py", '
'line 84, in _execute\n'
' return self.cursor.execute(sql, params)\n'},
'finished_at': datetime.datetime(2021, 6, 16, 8, 40, 17, 194098, tzinfo=tzutc()),
'logging_cid': 'fc876948b9d644f988743eb828d99ee4',
'name': 'pulp_rpm.app.tasks.synchronizing.synchronize',
'parent_task': None,
'progress_reports': [{'code': 'sync.downloading.metadata',
'done': 6,
'message': 'Downloading Metadata Files',
'state': 'completed',
'suffix': None,
'total': None},
{'code': 'sync.parsing.packages',
'done': 193,
'message': 'Parsed Packages',
'state': 'completed',
'suffix': None,
'total': 193},
{'code': 'sync.parsing.comps',
'done': 0,
'message': 'Parsed Comps',
'state': 'completed',
'suffix': None,
'total': 0},
{'code': 'sync.parsing.advisories',
'done': 0,
'message': 'Parsed Advisories',
'state': 'completed',
'suffix': None,
'total': 0},
{'code': 'sync.downloading.artifacts',
'done': 4,
'message': 'Downloading Artifacts',
'state': 'completed',
'suffix': None,
'total': None},
{'code': 'associating.content',
'done': 0,
'message': 'Associating Content',
'state': 'canceled',
'suffix': None,
'total': None}],
'pulp_created': datetime.datetime(2021, 6, 16, 8, 40, 10, 566935, tzinfo=tzutc()),
'pulp_href': '/pulp/api/v3/tasks/7c3fdf21-1b21-43dd-b9ad-19bbd98f4a88/',
'reserved_resources_record': ['/pulp/api/v3/remotes/rpm/rpm/48462531-7d83-4dc2-adf7-cd88e4d65495/',
'/pulp/api/v3/repositories/rpm/rpm/60559b7c-0acd-4c63-9e50-c8dad09e6bb1/'],
'started_at': datetime.datetime(2021, 6, 16, 8, 40, 10, 632317, tzinfo=tzutc()),
'state': 'failed',
'task_group': None,
'worker': '/pulp/api/v3/workers/82c16745-9a8f-4e58-8395-c0a360672ba0/'}
Associated sql
127.0.0.1(43873):60c9b8ea.5449:2021-06-16 04:40:17.065 EDT:app=[unknown]:pid=21577:ERROR: deadlock detected
127.0.0.1(43873):60c9b8ea.5449:2021-06-16 04:40:17.065 EDT:app=[unknown]:pid=21577:DETAIL: Process 21577 waits for ShareLock on transaction 13163681; blocked by process 21565.
Process 21565 waits for ShareLock on transaction 13163680; blocked by process 21577.
Process 21577: INSERT INTO "core_artifact" ("pulp_id", "pulp_created", "pulp_last_updated", "file", "size", "md5", "sha1", "sha224", "sha256", "sha384", "sha512") VALUES ('15b7946a-1e75-461c-99d9-c2244eea44e0'::uuid, '2021-06-16T08:40:16.019791+00:00'::timestamptz, '2021-06-16T08:40:16.019827+00:00'::timestamptz, 'artifact/44/414c7788cd8a1722906fb34bb019290d1269bb24bbf3ce9f1d63fe15464354', 83110084, NULL, 'ca43066416a794b8cfb822eff9ebf9f28cb202cd', '6699ad24ccbecc3508bc22d5890f489ea047518d4e43c4766a39e33a', '44414c7788cd8a1722906fb34bb019290d1269bb24bbf3ce9f1d63fe15464354', 'dbff1aaf5bec37bbe77a028826fa2df26a1cc23185d9fb8e32160a2fe626bda835c81232ba10092cec9d40e175cd1b8d', '0e2bb59c3bcb8304e7879ed1a7a6f099be74cde005a814ea57df1e8cd670f19f0638cfaddecfd1804632bbac599a34729c23d6a9b0bdfdc5ab87f29bfe040194'), ('eb61e401-00aa-405d-9746-788e0cb8171e'::uuid, '2021-06-16T08:40:16.025499+00:00'::timestamptz, '2021-06-16T08:40:16.025541+00:00'::timestamptz, 'artifact/aa/71e111378ebf86acc7cc3be9342bd531686e7da57c4ba9d11dce28568356fd', 8
Process 21565: INSERT INTO "core_artifact" ("pulp_id", "pulp_created", "pulp_last_updated", "file", "size", "md5", "sha1", "sha224", "sha256", "sha384", "sha512") VALUES ('c7b9cbea-b8fb-4de8-ace5-9cd656c57f9b'::uuid, '2021-06-16T08:40:15.723890+00:00'::timestamptz, '2021-06-16T08:40:15.723913+00:00'::timestamptz, 'artifact/aa/71e111378ebf86acc7cc3be9342bd531686e7da57c4ba9d11dce28568356fd', 83759432, NULL, '2144350cd1442c7cb26ca6bc9d8d62723cb885de', '822899be4cb83ecb84951913d66b6e77c9b75d9d17e610b835ab4445', 'aa71e111378ebf86acc7cc3be9342bd531686e7da57c4ba9d11dce28568356fd', 'fe2f747706bdb6e59fd6e072a4ef4de240f4aaaa5fee3230a5a8386d9efdfc45561c066dfb55577eb10c150db5189aee', '28e0923bce01f818c174868538c3fb321c469458485978d8a0dff93ea2efbddbcb2de9e671a9924197fd3e74b7c99d43d1bf8a0744e3277ea1f7e5827ddc358f'), ('b2e45e1b-5201-40a0-be7c-eabe5de5b81f'::uuid, '2021-06-16T08:40:15.834199+00:00'::timestamptz, '2021-06-16T08:40:15.834241+00:00'::timestamptz, 'artifact/44/414c7788cd8a1722906fb34bb019290d1269bb24bbf3ce9f1d63fe15464354', 8
127.0.0.1(43873):60c9b8ea.5449:2021-06-16 04:40:17.065 EDT:app=[unknown]:pid=21577:HINT: See server log for query details.
127.0.0.1(43873):60c9b8ea.5449:2021-06-16 04:40:17.065 EDT:app=[unknown]:pid=21577:CONTEXT: while inserting index tuple (10762,2) in relation "core_artifact_sha256_key"
127.0.0.1(43873):60c9b8ea.5449:2021-06-16 04:40:17.065 EDT:app=[unknown]:pid=21577:STATEMENT: INSERT INTO "core_artifact" ("pulp_id", "pulp_created", "pulp_last_updated", "file", "size", "md5", "sha1", "sha224", "sha256", "sha384", "sha512") VALUES ('15b7946a-1e75-461c-99d9-c2244eea44e0'::uuid, '2021-06-16T08:40:16.019791+00:00'::timestamptz, '2021-06-16T08:40:16.019827+00:00'::timestamptz, 'artifact/44/414c7788cd8a1722906fb34bb019290d1269bb24bbf3ce9f1d63fe15464354', 83110084, NULL, 'ca43066416a794b8cfb822eff9ebf9f28cb202cd', '6699ad24ccbecc3508bc22d5890f489ea047518d4e43c4766a39e33a', '44414c7788cd8a1722906fb34bb019290d1269bb24bbf3ce9f1d63fe15464354', 'dbff1aaf5bec37bbe77a028826fa2df26a1cc23185d9fb8e32160a2fe626bda835c81232ba10092cec9d40e175cd1b8d', '0e2bb59c3bcb8304e7879ed1a7a6f099be74cde005a814ea57df1e8cd670f19f0638cfaddecfd1804632bbac599a34729c23d6a9b0bdfdc5ab87f29bfe040194'), ('eb61e401-00aa-405d-9746-788e0cb8171e'::uuid, '2021-06-16T08:40:16.025499+00:00'::timestamptz, '2021-06-16T08:40:16.025541+00:00'::timestamptz, 'artifact/aa/71e111378ebf86acc7cc3be9342bd531686e7da57c4ba9d11dce28568356fd', 83759432, NULL, '2144350cd1442c7cb26ca6bc9d8d62723cb885de', '822899be4cb83ecb84951913d66b6e77c9b75d9d17e610b835ab4445', 'aa71e111378ebf86acc7cc3be9342bd531686e7da57c4ba9d11dce28568356fd', 'fe2f747706bdb6e59fd6e072a4ef4de240f4aaaa5fee3230a5a8386d9efdfc45561c066dfb55577eb10c150db5189aee', '28e0923bce01f818c174868538c3fb321c469458485978d8a0dff93ea2efbddbcb2de9e671a9924197fd3e74b7c99d43d1bf8a0744e3277ea1f7e5827ddc358f'), ('6ad9c70e-1b89-4141-80d8-5c08c62a6391'::uuid, '2021-06-16T08:40:16.026218+00:00'::timestamptz, '2021-06-16T08:40:16.026239+00:00'::timestamptz, 'artifact/01/41012c79a64e19eb7226de0c92f7132aaf85aba98c90fde4190a912e646bbf', 83113088, NULL, 'e916686c96edb4552054fb6de000ccfcb6bf3740', 'fe480371f7cd2a95c36d0e1b42f8d6179838f5bd6f8e97de9b5fcd8c', '0141012c79a64e19eb7226de0c92f7132aaf85aba98c90fde4190a912e646bbf', '5523d2af63f3f39676e86776871f13fbcd45c540eec274a7bd2df31bba1aaf9619d1e6abfa175ebcf16c0aa69642ffe0', 'cec5e688a31602bab11595f5316e5c0ce7278271a612737d9b41a67f1b9873713781b2f1bdec8b0f7d6a0e27728a831714bd99d79cec7916e3d7751f09976369'), ('52688fd7-23ef-40da-8f0e-680ecf79af9e'::uuid, '2021-06-16T08:40:16.026752+00:00'::timestamptz, '2021-06-16T08:40:16.026772+00:00'::timestamptz, 'artifact/2a/20884fea781c0e27b39ea3def7da7e5c829c0c26fe9cca8a9a9a7317adc580', 81421384, NULL, '63e540ef02aad8dc10395a31c1e8c52f62e9c25b', 'c93578e511e306afde1a50307eacd61647ce30020b4f5d36c11983e4', '2a20884fea781c0e27b39ea3def7da7e5c829c0c26fe9cca8a9a9a7317adc580', 'b438fc8d7efcfdebe356ab35bedf4ac61fabbff4cddb09885a570c7fc95aca1f594e2b32e8eefed03c9274c35eadd60d', '799fdc774c33e1c9227c5c5a9d50cc421ab053899de630e65ae48420d5af204839c4674f7a2e5c474a056d2ad64f65a5506825fab94db838e7cef1e4de032be7') RETURNING "core_artifact"."pulp_id"
Updated by ttereshc over 3 years ago
- Subject changed from Deadlock on rpm repository sync to Deadlock on rpm repository pulp2pulp sync
Updated by dalley over 3 years ago
- Has duplicate Issue #8985: deadlock detected during pulp3 to pulp3 sync added
Updated by dalley over 3 years ago
- Status changed from NEW to ASSIGNED
- Assignee set to dalley
Updated by dalley over 3 years ago
- Related to Issue #9082: deadlock during rpm repo sync: " CONTEXT: while inserting index tuple (1,9) in relation "rpm_package_pkgId_key"" added
Updated by dalley over 3 years ago
- Status changed from ASSIGNED to NEW
- Assignee deleted (
dalley)
Updated by dalley over 3 years ago
- Status changed from NEW to CLOSED - DUPLICATE
Updated by dalley over 3 years ago
- Status changed from CLOSED - DUPLICATE to NEW
Updated by dalley over 3 years ago
- Related to deleted (Issue #9082: deadlock during rpm repo sync: " CONTEXT: while inserting index tuple (1,9) in relation "rpm_package_pkgId_key"")
Updated by dalley over 3 years ago
- Has duplicate Issue #9082: deadlock during rpm repo sync: " CONTEXT: while inserting index tuple (1,9) in relation "rpm_package_pkgId_key"" added
Updated by dalley over 3 years ago
- Related to Issue #8963: deadlock when synching Foreman proxy added
Updated by dalley over 3 years ago
- Related to deleted (Issue #8963: deadlock when synching Foreman proxy)
Updated by dalley over 3 years ago
- Has duplicate Issue #8963: deadlock when synching Foreman proxy added
Updated by ggainey over 3 years ago
- Status changed from NEW to ASSIGNED
- Assignee set to ggainey
Updated by ggainey over 3 years ago
I can reproduce this problem at-will on core/3.11 and rpm/3.10. However, I cannot reproduce it, at all, on pulpcore-latest.
It's possible the new tasking-system has changed the timing enough that we no longer fall into the window. But there have also been A LOT of changes between 3.11 and Now.
The script I'm using to recreate is here:
https://github.com/ggainey/pulp_startup/blob/main/8750_deadlocks/repro_3-11.sh
(Same but with --autopublish for latest: https://github.com/ggainey/pulp_startup/blob/main/8750_deadlocks/repro.sh )
I'm going to try to reproduce on exactly core/3.14, rpm/3.13; I also have a lock-ordering theory that will try out on 3.11-et-al. Will report back here with results.
Updated by ggainey over 3 years ago
Update from QE - problem can be recreated on 3.14, but only by turning on the Olde Taskinge Systemme . Investigation continues.
Updated by ipanova@redhat.com over 3 years ago
- Sprint changed from Sprint 101 to Sprint 102
Updated by jsherril@redhat.com over 3 years ago
We've hit this on the new tasking system in 3.14: https://community.theforeman.org/t/katello-nightly-rpm-pipeline-1061-failed/24932
Updated by dalley over 3 years ago
Updated by dalley over 3 years ago
- Has duplicate Issue #9343: Deadlock during sync added
Updated by ttereshc over 3 years ago
- Copied to Backport #9379: Backport "Deadlock on rpm repository pulp2pulp sync"to 3.14.z added
Updated by Skullman over 3 years ago
More examples: python3-pulpcore-3.14.5-2 python3-pulp-rpm-3.14.2-1
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: pulp [62672f3c1f5844b29a8c0869db07cf4c]: pulpcore.tasking.pulpcore_worker:INFO: Task a2d9b01f-3a62-4f35-8ad6-9b793c43a9c1 failed (deadlock detected
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: DETAIL: Process 244121 waits for ShareLock on transaction 2141154; blocked by process 244124.
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: Process 244124 waits for ShareLock on transaction 2141157; blocked by process 244121.
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: HINT: See server log for query details.
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: CONTEXT: while updating tuple (24547,1) in relation "core_artifact"
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: )
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: pulp [62672f3c1f5844b29a8c0869db07cf4c]: pulpcore.tasking.pulpcore_worker:INFO: File "/usr/lib/python3.6/site-packages/pulpcore/tasking/pulpcore_worker.py", line 272, in _perform_task
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: result = func(*args, **kwargs)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 475, in synchronize
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: version = dv.create()
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 151, in create
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: loop.run_until_complete(pipeline)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: return future.result()
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 225, in create_pipeline
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: await asyncio.gather(*futures)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: await self.run()
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 89, in run
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: existing_artifacts.touch()
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/pulpcore/app/models/content.py", line 103, in touch
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: return self.update(timestamp_of_interest=now())
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 741, in update
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: rows = query.get_compiler(self.db).execute_sql(CURSOR)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1471, in execute_sql
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: cursor = super().execute_sql(result_type)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1142, in execute_sql
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: cursor.execute(sql, params)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 67, in execute
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 76, in _execute_with_wrappers
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: return executor(sql, params, many, context)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: return self.cursor.execute(sql, params)
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/utils.py", line 89, in __exit__
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: raise dj_exc_value.with_traceback(traceback) from exc_value
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Sep 15 06:42:11 pulp314-machine pulpcore-worker[49536]: return self.cursor.execute(sql, params)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: pulp [7b40012f6a534fb89265b6f5048677f1]: pulpcore.tasking.pulpcore_worker:INFO: Task a598f9f2-5e00-445b-85d4-f8a9baa85328 failed (deadlock detected
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: DETAIL: Process 245936 waits for ShareLock on transaction 2154128; blocked by process 245931.
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: Process 245931 waits for ShareLock on transaction 2154127; blocked by process 245936.
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: HINT: See server log for query details.
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: CONTEXT: while updating tuple (1306,29) in relation "core_contentartifact"
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: )
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: pulp [7b40012f6a534fb89265b6f5048677f1]: pulpcore.tasking.pulpcore_worker:INFO: File "/usr/lib/python3.6/site-packages/pulpcore/tasking/pulpcore_worker.py", line 272, in _perform_task
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: result = func(*args, **kwargs)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 475, in synchronize
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: version = dv.create()
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 151, in create
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: loop.run_until_complete(pipeline)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: return future.result()
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 225, in create_pipeline
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: await asyncio.gather(*futures)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: await self.run()
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/content_stages.py", line 151, in run
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: ContentArtifact.objects.bulk_update(to_update_ca_bulk, ["artifact"])
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: return getattr(self.get_queryset(), name)(*args, **kwargs)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 525, in bulk_update
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: self.filter(pk__in=pks).update(**update_kwargs)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 741, in update
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: rows = query.get_compiler(self.db).execute_sql(CURSOR)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1471, in execute_sql
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: cursor = super().execute_sql(result_type)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1142, in execute_sql
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: cursor.execute(sql, params)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 67, in execute
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 76, in _execute_with_wrappers
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: return executor(sql, params, many, context)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: return self.cursor.execute(sql, params)
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/utils.py", line 89, in __exit__
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: raise dj_exc_value.with_traceback(traceback) from exc_value
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Sep 15 07:26:09 pulp314-machine pulpcore-worker[48925]: return self.cursor.execute(sql, params)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: pulp [49271f8bee164dc8ab0d9df7183796ea]: pulpcore.tasking.pulpcore_worker:INFO: Task 578dbe28-c9b7-4e87-b68e-6d5beb15aa32 failed (deadlock detected
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: DETAIL: Process 258618 waits for ShareLock on transaction 2192080; blocked by process 258632.
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: Process 258632 waits for ShareLock on transaction 2192082; blocked by process 258618.
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: HINT: See server log for query details.
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: CONTEXT: while inserting index tuple (106599,2) in relation "rpm_package_pkgId_key"
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: )
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: pulp [49271f8bee164dc8ab0d9df7183796ea]: pulpcore.tasking.pulpcore_worker:INFO: File "/usr/lib/python3.6/site-packages/pulpcore/tasking/pulpcore_worker.py", line 272, in _perform_task
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: result = func(*args, **kwargs)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 475, in synchronize
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: version = dv.create()
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 151, in create
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: loop.run_until_complete(pipeline)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return future.result()
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 225, in create_pipeline
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: await asyncio.gather(*futures)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: await self.run()
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/content_stages.py", line 113, in run
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: d_content.content.save()
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/pulpcore/app/models/base.py", line 149, in save
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return super().save(*args, **kwargs)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django_lifecycle/mixins.py", line 134, in save
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: save(*args, **kwargs)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/base.py", line 744, in save
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: force_update=force_update, update_fields=update_fields)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/base.py", line 782, in save_base
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: force_update, using, update_fields,
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/base.py", line 873, in _save_table
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: result = self._do_insert(cls._base_manager, using, fields, update_pk, raw)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/base.py", line 911, in _do_insert
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: using=using, raw=raw)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return getattr(self.get_queryset(), name)(*args, **kwargs)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/query.py", line 1186, in _insert
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return query.get_compiler(using=using).execute_sql(return_id)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1377, in execute_sql
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: cursor.execute(sql, params)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 67, in execute
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 76, in _execute_with_wrappers
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return executor(sql, params, many, context)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return self.cursor.execute(sql, params)
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/utils.py", line 89, in __exit__
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: raise dj_exc_value.with_traceback(traceback) from exc_value
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: File "/usr/lib/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Sep 15 12:53:35 pulp314-machine pulpcore-worker[49383]: return self.cursor.execute(sql, params)
Updated by pulpbot about 3 years ago
- Status changed from ASSIGNED to POST
Updated by rchan about 3 years ago
- Sprint changed from Sprint 105 to Sprint 106
Added by ggainey about 3 years ago
Updated by ggainey about 3 years ago
- Status changed from POST to MODIFIED
Applied in changeset pulpcore|6af3519b4931bd34c49653a80c52fd1c7cd08821.
Updated by pulpbot about 3 years ago
- Status changed from MODIFIED to CLOSED - CURRENTRELEASE
Fix occasional deadlocks when doing multiple similar syncs concurrently.
Forcing deadlocks requires a lot of time and pulpcore-workers running. There is therefore no specific CI test for this, but there is a reproducer script that will force deadlocks to happen (and show that they're fixed) here:
https://github.com/ggainey/pulp_startup/blob/main/8750_deadlocks/file_repro.sh
fixes #8750. [nocoverage]