Issue #7904: PulpImport can deadlock when importing Centos*-base and app-stream in one import file - RPM Support - Pulp

Actions

Send by e-mail Copy link

Issue #7904

closed

PulpImport can deadlock when importing Centos*-base and app-stream in one import file

Added by ggainey over 3 years ago. Updated over 2 years ago.

Status:

CLOSED - CURRENTRELEASE

Priority:

Normal

Assignee:

ggainey

Sprint/Milestone:

3.12.0

Start date:

Due date:

Estimated time:

Severity:

2. Medium

Version:

Platform Release:

OS:

Triaged:

Yes

Groomed:

Sprint Candidate:

Tags:

Sprint:

Quarter:

Description

Sequence of events is:

Create, sync, and export centos8 base and appstream
pclean
Create empty repos and importer to import into them
import the export
deadlock (there is no step, 'Profit!')

The scripts used for Step 1 and Step 3 are:

Task-output when deadlock detected:

(pulp) [vagrant@pulp2-nightly-pulp3-source-centos7 import_export]$ http :/pulp/api/v3/tasks/ac6d1903-ef42-4401-b189-14eccfa197a3/
{
    "child_tasks": [],
    "created_resources": [],
    "error": {
        "description": "deadlock detected\nDETAIL:  Process 3133 waits for ShareLock on transaction 39285; blocked by process 3121.\nProcess 3121 waits for ShareLock on transaction 39288; blocked by process 3133.\nHINT:  See server log for query details.\nCONTEXT:  while inserting index tuple (36,4) in relation \"rpm_package_pkgId_key\"\n",
        "traceback": "  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py\", line 975, in perform_job\n    rv = job.perform()\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 692, in perform\n    self._result = self._execute()\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 698, in _execute\n    return self.func(*self.args, **self.kwargs)\n  File \"/home/vagrant/devel/pulpcore/pulpcore/app/tasks/importer.py\", line 150, in import_repository_version\n    a_result = _import_file(os.path.join(rv_path, filename), res_class)\n  File \"/home/vagrant/devel/pulpcore/pulpcore/app/tasks/importer.py\", line 61, in _import_file\n    return resource.import_data(data, raise_errors=True)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py\", line 745, in import_data\n    return self.import_data_inner(dataset, dry_run, raise_errors, using_transactions, collect_failed_rows, **kwargs)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py\", line 792, in import_data_inner\n    raise row_result.errors[-1].error\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py\", line 672, in import_row\n    self.save_instance(instance, using_transactions, dry_run)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py\", line 450, in save_instance\n    instance.save()\n  File \"/home/vagrant/devel/pulpcore/pulpcore/app/models/base.py\", line 115, in save\n    return super().save(*args, **kwargs)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django_lifecycle/mixins.py\", line 129, in save\n    save(*args, **kwargs)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py\", line 744, in save\n    force_update=force_update, update_fields=update_fields)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py\", line 782, in save_base\n    force_update, using, update_fields,\n  File \"/usr/local/lib/pulp/lib64/python3.6/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 \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py\", line 911, in _do_insert\n    using=using, raw=raw)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/manager.py\", line 82, in manager_method\n    return getattr(self.get_queryset(), name)(*args, **kwargs)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/query.py\", line 1186, in _insert\n    return query.get_compiler(using=using).execute_sql(return_id)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/sql/compiler.py\", line 1377, in execute_sql\n    cursor.execute(sql, params)\n  File \"/usr/local/lib/pulp/lib64/python3.6/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 \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py\", line 76, in _execute_with_wrappers\n    return executor(sql, params, many, context)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py\", line 84, in _execute\n    return self.cursor.execute(sql, params)\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/utils.py\", line 89, in __exit__\n    raise dj_exc_value.with_traceback(traceback) from exc_value\n  File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py\", line 84, in _execute\n    return self.cursor.execute(sql, params)\n"
    },
    "finished_at": "2020-11-30T21:52:04.749698Z",
    "name": "pulpcore.app.tasks.importer.import_repository_version",
    "parent_task": "/pulp/api/v3/tasks/6264f228-a93e-4477-9b42-1bd760c50abe/",
    "progress_reports": [],
    "pulp_created": "2020-11-30T21:36:50.180795Z",
    "pulp_href": "/pulp/api/v3/tasks/ac6d1903-ef42-4401-b189-14eccfa197a3/",
    "reserved_resources_record": [
        "/pulp/api/v3/repositories/rpm/rpm/0d5f1f84-183a-4686-a9d3-a0d428e1057d/"
    ],
    "started_at": "2020-11-30T21:36:56.391655Z",
    "state": "failed",
    "task_group": "/pulp/api/v3/task-groups/da6c57c4-5c28-47f1-971c-480e6c2538ec/",
    "worker": "/pulp/api/v3/workers/03c6d158-ea61-48b7-bd73-8888a37b3aac/"
}

journalctl output:

Nov 30 21:46:41 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com gunicorn[2808]: 127.0.0.1 - admin [30/Nov/2020:21:46:41 +0000] "GET /pulp/api/v3/tasks/ac6d1903-ef42-4401-b189-14eccfa197a3/ HTTP/1.1" 200 660 "-" "HTTPie/2.3.0"
Nov 30 21:51:58 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: pulp: pulpcore.app.tasks.importer:INFO: Importing file /tmp/tmp_orxezjs/repository-centos8-base_1/pulp_rpm.app.modelresource.PackageResource.json.
Nov 30 21:51:58 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2805]: pulp: pulpcore.app.tasks.importer:INFO: Importing file /tmp/tmpkaqoodxm/repository-centos8-apps_1/pulp_rpm.app.modelresource.PackageResource.json.
Nov 30 21:51:59 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2805]: pulp: pulpcore.app.tasks.importer:INFO: ...Importing resource PackageResource.
Nov 30 21:52:02 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: pulp: pulpcore.app.tasks.importer:INFO: ...Importing resource PackageResource.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: pulp: rq.worker:ERROR: Traceback (most recent call last):
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: psycopg2.errors.DeadlockDetected: deadlock detected
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: DETAIL:  Process 3133 waits for ShareLock on transaction 39285; blocked by process 3121.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Process 3121 waits for ShareLock on transaction 39288; blocked by process 3133.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: HINT:  See server log for query details.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: CONTEXT:  while inserting index tuple (36,4) in relation "rpm_package_pkgId_key"
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: The above exception was the direct cause of the following exception:
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Traceback (most recent call last):
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 975, in perform_job
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: rv = job.perform()
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 692, in perform
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: self._result = self._execute()
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 698, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.func(*self.args, **self.kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/home/vagrant/devel/pulpcore/pulpcore/app/tasks/importer.py", line 150, in import_repository_version
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: a_result = _import_file(os.path.join(rv_path, filename), res_class)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/home/vagrant/devel/pulpcore/pulpcore/app/tasks/importer.py", line 61, in _import_file
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return resource.import_data(data, raise_errors=True)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 745, in import_data
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.import_data_inner(dataset, dry_run, raise_errors, using_transactions, collect_failed_rows, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 792, in import_data_inner
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: raise row_result.errors[-1].error
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 672, in import_row
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: self.save_instance(instance, using_transactions, dry_run)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 450, in save_instance
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: instance.save()
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/home/vagrant/devel/pulpcore/pulpcore/app/models/base.py", line 115, in save
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return super().save(*args, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django_lifecycle/mixins.py", line 129, in save
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: save(*args, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 744, in save
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: force_update=force_update, update_fields=update_fields)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 782, in save_base
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: force_update, using, update_fields,
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 873, in _save_table
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: result = self._do_insert(cls._base_manager, using, fields, update_pk, raw)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 911, in _do_insert
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: using=using, raw=raw)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return getattr(self.get_queryset(), name)(*args, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/query.py", line 1186, in _insert
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return query.get_compiler(using=using).execute_sql(return_id)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/sql/compiler.py", line 1377, in execute_sql
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 67, in execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 76, in _execute_with_wrappers
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return executor(sql, params, many, context)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/utils.py", line 89, in __exit__
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: raise dj_exc_value.with_traceback(traceback) from exc_value
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: django.db.utils.OperationalError: deadlock detected
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: DETAIL:  Process 3133 waits for ShareLock on transaction 39285; blocked by process 3121.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Process 3121 waits for ShareLock on transaction 39288; blocked by process 3133.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: HINT:  See server log for query details.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: CONTEXT:  while inserting index tuple (36,4) in relation "rpm_package_pkgId_key"
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Traceback (most recent call last):
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: psycopg2.errors.DeadlockDetected: deadlock detected
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: DETAIL:  Process 3133 waits for ShareLock on transaction 39285; blocked by process 3121.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Process 3121 waits for ShareLock on transaction 39288; blocked by process 3133.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: HINT:  See server log for query details.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: CONTEXT:  while inserting index tuple (36,4) in relation "rpm_package_pkgId_key"
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: The above exception was the direct cause of the following exception:
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Traceback (most recent call last):
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 975, in perform_job
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: rv = job.perform()
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 692, in perform
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: self._result = self._execute()
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 698, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.func(*self.args, **self.kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/home/vagrant/devel/pulpcore/pulpcore/app/tasks/importer.py", line 150, in import_repository_version
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: a_result = _import_file(os.path.join(rv_path, filename), res_class)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/home/vagrant/devel/pulpcore/pulpcore/app/tasks/importer.py", line 61, in _import_file
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return resource.import_data(data, raise_errors=True)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 745, in import_data
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.import_data_inner(dataset, dry_run, raise_errors, using_transactions, collect_failed_rows, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 792, in import_data_inner
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: raise row_result.errors[-1].error
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 672, in import_row
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: self.save_instance(instance, using_transactions, dry_run)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/import_export/resources.py", line 450, in save_instance
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: instance.save()
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/home/vagrant/devel/pulpcore/pulpcore/app/models/base.py", line 115, in save
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return super().save(*args, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django_lifecycle/mixins.py", line 129, in save
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: save(*args, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 744, in save
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: force_update=force_update, update_fields=update_fields)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 782, in save_base
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: force_update, using, update_fields,
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 873, in _save_table
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: result = self._do_insert(cls._base_manager, using, fields, update_pk, raw)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/base.py", line 911, in _do_insert
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: using=using, raw=raw)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return getattr(self.get_queryset(), name)(*args, **kwargs)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/query.py", line 1186, in _insert
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return query.get_compiler(using=using).execute_sql(return_id)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/models/sql/compiler.py", line 1377, in execute_sql
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 67, in execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 76, in _execute_with_wrappers
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return executor(sql, params, many, context)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/django/db/backends/utils.py", line 84, in _execute
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: return self.cursor.execute(sql, params)
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: django.db.utils.OperationalError: deadlock detected
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: DETAIL:  Process 3133 waits for ShareLock on transaction 39285; blocked by process 3121.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: Process 3121 waits for ShareLock on transaction 39288; blocked by process 3133.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: HINT:  See server log for query details.
Nov 30 21:52:04 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[2806]: CONTEXT:  while inserting index tuple (36,4) in relation "rpm_package_pkgId_key"

Related issues

Actions

Copy link

Updated by daviddavis over 3 years ago

Related to Issue #7560: Import tests are failing with psycopg2.extensions.TransactionRollbackError: deadlock detected added

Actions

Copy link

Updated by ggainey over 3 years ago

Description updated (diff)

Actions

Copy link

Updated by fao89 over 3 years ago

Triaged changed from No to Yes
Sprint set to Sprint 86

Actions

Copy link

Updated by rchan over 3 years ago

Sprint changed from Sprint 86 to Sprint 87

Actions

Copy link

Updated by rchan over 3 years ago

Sprint changed from Sprint 87 to Sprint 88

Actions

Copy link

Updated by rchan about 3 years ago

Sprint changed from Sprint 88 to Sprint 89

Actions

Copy link

Updated by rchan about 3 years ago

Sprint changed from Sprint 89 to Sprint 90

Actions

Copy link

Updated by daviddavis about 3 years ago

Sprint/Milestone set to 3.12.0
Sprint deleted (~~Sprint 90~~)

Actions

Copy link

Updated by ggainey about 3 years ago

Status changed from NEW to ASSIGNED
Assignee set to ggainey

Actions

Copy link

#10

Updated by ggainey about 3 years ago

Some more context from recent psql-logs :

2021-03-23 19:21:31.988 UTC [25622] ERROR:  deadlock detected
2021-03-23 19:21:31.988 UTC [25622] DETAIL:  Process 25622 waits for ShareLock on transaction 81508; blocked by process 25616.
        Process 25616 waits for ShareLock on transaction 81505; blocked by process 25622.
        Process 25622: INSERT INTO "rpm_package" ("content_ptr_id", "name", "epoch", "version", "release", "arch", "pkgId", "checksum_type", "summary", "description", "url", "changelogs", "files", "requires", "provides", "conflicts", "obsoletes", "suggests", "enhances", "recommends", "supplements", "location_base", "location_href", "rpm_buildhost", "rpm_group", "rpm_license", "rpm_packager", "rpm_sourcerpm", "rpm_vendor", "rpm_header_start", "rpm_header_end", "size_archive", "size_installed", "size_package", "time_build", "time_file", "is_modular") VALUES ('51d5bddb-79ae-44f8-92ea-e9fba85d0cdb'::uuid, 'abrt-libs', '0', '2.10.9', '20.el8', 'x86_64', 'acb61f2512ee8515db63f839967ee4d7b7e8f3ea22a1eac3fcf3a6b5e7d7f857', 'sha256', 'Libraries for abrt', 'Libraries for abrt.', 'https://abrt.readthedocs.org/', '[["Michal Fabik <mfabik@redhat.com> - 2.10.9-11", 1563278400, "- a-a-list-dsos: Fix decoding of strings from rpm\nResolves: rhbz#1694970"], ["Ernestas Kulik <ekulik@redhat.com> - 2.10.9-12", 1583928000, "- Fix #1798494, #1805728, #1
        Process 25616: INSERT INTO "rpm_package" ("content_ptr_id", "name", "epoch", "version", "release", "arch", "pkgId", "checksum_type", "summary", "description", "url", "changelogs", "files", "requires", "provides", "conflicts", "obsoletes", "suggests", "enhances", "recommends", "supplements", "location_base", "location_href", "rpm_buildhost", "rpm_group", "rpm_license", "rpm_packager", "rpm_sourcerpm", "rpm_vendor", "rpm_header_start", "rpm_header_end", "size_archive", "size_installed", "size_package", "time_build", "time_file", "is_modular") VALUES ('afb4974d-ca77-413c-b890-be8a1dd3bb1f'::uuid, 'SDL', '0', '1.2.15', '38.el8', 'x86_64', '6703b1e5b0a6a77df0dac14d37707fe91185c5580f5b79c36a9a0db71cb9a32d', 'sha256', 'A cross-platform multimedia library', 'Simple DirectMedia Layer (SDL) is a cross-platform multimedia library designed
        to provide fast access to the graphics frame buffer and audio device.', 'http://www.libsdl.org/', '[["Petr Pisar <ppisar@redhat.com> - 1.2.15-29", 1505822400, "- Fix vec_perm() usage on little-endia
2021-03-23 19:21:31.988 UTC [25622] HINT:  See server log for query details.
2021-03-23 19:21:31.988 UTC [25622] CONTEXT:  while inserting index tuple (21,2) in relation "rpm_package_pkgId_key"
2021-03-23 19:21:31.988 UTC [25622] STATEMENT:  INSERT INTO "rpm_package" ("content_ptr_id", "name", "epoch", "version", "release", "arch", "pkgId", "checksum_type", "summary", "description", "url", "changelogs", "files", "requires", "provides", "conflicts", "obsoletes", "suggests", "enhances", "recommends", "supplements", "location_base", "location_href", "rpm_buildhost", "rpm_group", "rpm_license", "rpm_packager", "rpm_sourcerpm", "rpm_vendor", "rpm_header_start", "rpm_header_end", "size_archive", "size_installed", "size_package", "time_build", "time_file", "is_modular") VALUES ('51d5bddb-79ae-44f8-92ea-e9fba85d0cdb'::uuid, 'abrt-libs', '0', '2.10.9', '20.el8', 'x86_64', 'acb61f2512ee8515db63f839967ee4d7b7e8f3ea22a1eac3fcf3a6b5e7d7f857', 'sha256', 'Libraries for abrt', 'Libraries for abrt.', 'https://abrt.readthedocs.org/', '[["Michal Fabik <mfabik@redhat.com> - 2.10.9-11", 1563278400, "- a-a-list-dsos: Fix decoding of strings from rpm\nResolves: rhbz#1694970"], ["Ernestas Kulik <ekulik@redhat.com> - 2.10.9-12", 1583928000, "- Fix #1798494, #1805728, #1809949"], ["Michal \u017didek <mzidek@redhat.com> - 2.10.9-13", 1591790400, "- Resolves: rhbz#1658685\n- shellcheck: Use command instead of type\n- shellcheck: Check exit code directly with if mycmd\n- shellcheck: Suppress shellcheck warning SC1090\n- shellcheck: Use $(...) instead of legacy backticked\n- cli: Add a shebang"], ["Ernestas Kulik <ekulik@redhat.com> - 2.10.9-14", 1591876800, "- Add patch for #1846272"], ["Ernestas Kulik <ekulik@redhat.com> - 2.10.9-15", 1591876801, "- Remove unintended line change in abrt_event.conf"], ["- Ernestas Kulik <ekulik@redhat.com> - 2.10.9-16", 1592827200, "- Add another patch for #1846272"], ["- Michal \u017didek <mzidek@redhat.com> - 2.10.9-17", 1593000000, "- Resolves: rhbz#1835388"], ["- Michal \u017didek <mzidek@redhat.com> - 2.10.9-18", 1593432000, "- Resolves: rhbz#1835388\n- This is seccond commit to fix som mess with one missing patch and synchronize\n  the internal gitlab patch numbers with this spec file"], ["- Ernestas Kulik <ekulik@redhat.com> - 2.10.9-19", 1593518400, "- Add another patch for #1846272"], ["- Ernestas Kulik <ekulik@redhat.com> - 2.10.9-20", 1597838400, "- Something something patch for rhbz#1835388"]]', '[["dir", "/etc/", "abrt"], [null, "/etc/abrt/", "abrt.conf"], ["dir", "/etc/abrt/", "plugins"], ["dir", "/usr/lib/", ".build-id"], ["dir", "/usr/lib/.build-id/", "45"], [null, "/usr/lib/.build-id/45/", "2a8a3d6251f3eb7a8c514ff16b5868631acb52"], [null, "/usr/lib64/", "libabrt.so.0"], [null, "/usr/lib64/", "libabrt.so.0.0.1"], ["dir", "/usr/share/", "abrt"], ["dir", "/usr/share/abrt/", "conf.d"], [null, "/usr/share/abrt/conf.d/", "abrt.conf"], ["dir", "/usr/share/abrt/conf.d/", "plugins"], [null, "/usr/share/augeas/lenses/", "abrt.aug"], [null, "/usr/share/man/man5/", "abrt.conf.5.gz"]]', '[["libgio-2.0.so.0()(64bit)", null, null, null, null, false], ["libglib-2.0.so.0()(64bit)", null, null, null, null, false], ["libgobject-2.0.so.0()(64bit)", null, null, null, null, false], ["libreport.so.0()(64bit)", null, null, null, null, false], ["libsatyr.so.3()(64bit)", null, null, null, null, false], ["rtld(GNU_HASH)", null, null, null, null, false], ["libc.so.6(GLIBC_2.4)(64bit)", null, null, null, null, false]]', '[["abrt-libs", "EQ", "0", "2.10.9", "20.el8", false], ["abrt-libs(x86-64)", "EQ", "0", "2.10.9", "20.el8", false], ["config(abrt-libs)", "EQ", "0", "2.10.9", "20.el8", false], ["libabrt.so.0()(64bit)", null, null, null, null, false]]', '[]', '[]', '[]', '[]', '[]', '[]', '', 'Packages/abrt-libs-2.10.9-20.el8.x86_64.rpm', 'x86-02.mbox.centos.org', 'Unspecified', 'GPLv2+', 'CentOS Buildsys <bugs@centos.org>', 'abrt-2.10.9-20.el8.src.rpm', 'CentOS', 5608, 39448, 79088, 76947, 67536, 1598289728, 1598291383, false)

Actions

Copy link

#11

Updated by ggainey about 3 years ago

Related to Issue #7073: import test fails with psycopg2.extensions.TransactionRollbackError: deadlock detected added

Actions

Copy link

#12

Updated by pulpbot about 3 years ago

Status changed from ASSIGNED to POST

Actions

Copy link

#13

Updated by mdellweg about 3 years ago

Sprint/Milestone changed from 3.12.0 to 3.13.0

Actions

Copy link

#14

Updated by ggainey almost 3 years ago

Did a bunch more investigation and experimentation on this today:

Good news: one can avoid the deadlock by enforcing an ordering at export time, in the querysets. This results in rows being imported in a guaranteed order, which alleviates the row-lock-ordering ambiguity that causes the deadlock. Yay.

Bad news: that uncovers another, different (and yet related) issue. In the reproducer-repositories, there is a Package, vt-profile, which is held in both repos. The repos are being imported in parallel threads. Each thread imports the PackageResource at (roughly) the same time. Both threads think they are the 'one' that is instantiating the row for vt-profile. One of them, when it goes to commit its transaction, fails with

Apr 20 17:44:00 pulp3-source-fedora33.padre-fedora.example.com rq[124235]: django.db.utils.IntegrityError: duplicate key value violates unique constraint "rpm_package_pkgId_key"
Apr 20 17:44:00 pulp3-source-fedora33.padre-fedora.example.com rq[124235]: DETAIL:  Key ("pkgId")=(487c0b4ead22f4728cc37d1a470e889bf7bf0f02172561aea406260c197de3bc) already exists.

Good news: the exception happens because we're calling import_data(..., raise_errors=True) , here: https://github.com/pulp/pulpcore/blob/master/pulpcore/app/tasks/importer.py#L65

The default is False - any errors are just recorded in the result. And in this particular case, ignoring the error completely allows the import to succeed!

Bad news: in the general case, we cannot just ignore errors and hope everything works.

Worse news: addressing this particular race condition would require...locking the table before importing into it. Which is what the existing PR is doing. Which is ugly and non-performant.

I need to go think about this problem Even More. @daviddavis , mdellweg , bmbouter , any brilliant insights (or even just mild sympathy) gratefully accepted.

Actions

Copy link

#15

Updated by daviddavis almost 3 years ago

Good findings. I thought that import_data() would update existing records if they exist?

Edit: I dug some into the source code for import_row. Looks like it calls get_or_init_instance before save_instance. I'm guessing this is causing this race condition:

Worker 1 checks database for vt-profile
Worker 2 checks db for vt-profile
Worker 1 inserts vt-profile
Worker 2 attempts to insert vt-profile and fails

We're probably the only people running django-import-export imports in parallel. We could try to open a bug against django-import-export or perhaps override save_instance to handle the IntegrityError.

Actions

Copy link

#16

Updated by ggainey almost 3 years ago

@daviddavis - exactly the race condition I was thinking was happening. Great research!

Will think on it overnight, maybe something will come to me in the shower in the morning...

Actions

Copy link

#17

Updated by ggainey almost 3 years ago

Here's a much faster reproducer than having deal with all of CentOS:

pulp rpm repository create --name one
pulp rpm repository create --name two
pulp rpm remote create --name both --url https://fixtures.pulpproject.org/rpm-signed/
pulp rpm repository sync --name one --remote both
pulp rpm repository sync --name two --remote both
pulp exporter pulp create --name small --path /home/vagrant/devel/exports/small/ --repository one rpm --repository two rpm
# Pay attention to .tar.gz from output_files
pulp export pulp run --exporter small
pclean
prestart
pulp rpm repository create --name new-one
pulp rpm repository create --name new-two
pulp importer pulp create --name small --repo-map one new-one --repo-map two new-two
http POST :IMPORTER-HREF/imports/ path=/home/vagrant/devel/exports/small/EXPORT-FILE.tar.gz

Actions

Copy link

#18

Updated by ggainey almost 3 years ago

Project changed from Pulp to RPM Support
Status changed from POST to ASSIGNED
Sprint/Milestone deleted (~~3.13.0~~)

Moving this issue to pulp_rpm - the fix involves guaranteeing the EXPORT-order of ModelResources, which is owned by the plugin.

Moving to ASSIGNED as the current PR is a Bad Idea(tm) and is being closed.

Actions

Copy link

#19

Updated by ggainey almost 3 years ago

Related to Issue #8633: PulpImport with overlapping content can fail with unique-constraint violation added

Actions

Copy link

#20

Updated by pulpbot almost 3 years ago

Status changed from ASSIGNED to POST

PR: https://github.com/pulp/pulp_rpm/pull/1975

Actions

Copy link

#21

Updated by ggainey almost 3 years ago

Here's a test-scenario involving TEN repositories. With the associated PR in play, this succeeds:

# create and fill repos                                                                      
pulp rpm remote create --name both --url https://fixtures.pulpproject.org/rpm-signed/        
for r in one two three four five six seven eight nine ten                                    
do                                                                                           
  pulp rpm repository create --name ${r}                                                     
  pulp rpm repository sync --name ${r} --remote both                                         
done                                                                                         
                                                                                             
# create exporter                                                                            
pulp exporter pulp create --name ten --path /home/vagrant/devel/exports/ten/ --repository one rpm --repository two rpm --repository three rpm --repository four rpm --repository five rpm --repository six rpm --repository seven rpm --repository eight rpm --repository nine rpm --repository ten rpm
# export                                                                                     
pulp export pulp run --exporter ten                                                          
                                                                                             
# set up for import                                                                          
pclean                                                                                       
prestart                                                                                     
                                                                                             
# create destination-repos                                                                   
for r in one two three four five six seven eight nine ten                                    
do                                                                                           
  pulp rpm repository create --name new-${r}                                                 
done                                                                                         
                                                                                             
# create importer                                                                            
pulp importer pulp create --name ten --repo-map one new-one --repo-map two new-two --repo-map three new-three --repo-map four new-four --repo-map five new-five --repo-map six new-six --repo-map seven new-seven --repo-map eight new-eight --repo-map nine new-nine --repo-map ten new-ten

Actions

Copy link

#22

Updated by wibbit almost 3 years ago

Morning all

Just for reference I'm seeing these symptoms when performing a sync against Dell's DSU OSI repo, upstream is "http://linux.dell.com/repo/hardware/dsu/os_independant/"

The traceback. 'error': {'description': deadlock detected\n' DETAIL: Process 12152 waits for ShareLock on transaction 6639974; blocked by process 12380.\n' Process 12380 waits for ShareLock on transaction 6640227; blocked by process 12152.\n' HINT: See server log for query details.\n' CONTEXT: while inserting index tuple (48079,6) 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'},

Actions

Copy link

#23

Updated by ggainey almost 3 years ago

Hey wibbit - that's a completely different code path/set of entities. Could you open a new issue with this stacktrace? It'll need its own attention. Thhanks!

Added by ggainey almost 3 years ago

Revision e9570a5f | View on GitHub

Ordered querysets in ModelResources for export.

Ordering-on-export insures we won't deadlock at import-time when repo-versions have overlapping content.

Accepting this change without the referenced pulpcore fix will result in fixing the deadlock, but generating unique-constraint violations in the same place at import-time.

fixes #7904

Required PR: https://github.com/pulp/pulpcore/pull/1278

Actions

Copy link

#24

Updated by ggainey almost 3 years ago

Status changed from POST to MODIFIED

Applied in changeset e9570a5fb848c7024d3951d901cc40a11edbb995.

Actions

Copy link

#25

Updated by ttereshc almost 3 years ago

Sprint/Milestone set to 3.12.0

Actions

Copy link

#26

Updated by pulpbot almost 3 years ago

Status changed from MODIFIED to CLOSED - CURRENTRELEASE

Actions

Copy link

#27

Updated by ggainey almost 3 years ago

wibbit wrote:

Morning all

Just for reference I'm seeing these symptoms when performing a sync against Dell's DSU OSI repo, upstream is "http://linux.dell.com/repo/hardware/dsu/os_independant/"

Hey @wibbit - I have had no luck forcing a deadlock w/ this repo, possibly because after a certain number of RPMs downloaded, I get a can't-establish-connection error w/Dell.

Did you open an issue on this specific traceback? I can't seem to find it. Also - are you still seeing a problem with Dell's repos at https://linux.dell.com/repo/hardware/dsu/os_independent ?

Cnx-reset traceback:

pulp rpm remote create --name dell --url https://linux.dell.com/repo/hardware/dsu/os_independent/  --download-concurrency 5 --policy immediate
pulp rpm repository create --name dell --remote dell
pulp rpm repository sync --name dell

Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: pulp [16313dbf40af45ec98a796a31e33d8a9]: rq.worker:ERROR: Traceback (most recent call last):
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/connector.py", line 969, in _wrap_create_connection
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: return await self._loop.create_connection(*args, **kwargs)  # type: ignore  # noqa
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/lib64/python3.6/asyncio/base_events.py", line 820, in create_connection
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: sock, protocol_factory, ssl, server_hostname)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/lib64/python3.6/asyncio/base_events.py", line 846, in _create_connection_transport
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: yield from waiter
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: ConnectionResetError
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: The above exception was the direct cause of the following exception:
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: Traceback (most recent call last):
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 1013, in perform_job
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: rv = job.perform()
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 709, in perform
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: self._result = self._execute()
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 732, in _execute
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: result = self.func(*self.args, **self.kwargs)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulp_rpm/pulp_rpm/app/tasks/synchronizing.py", line 384, in synchronize
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: version = dv.create()
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/plugin/stages/declarative_version.py", line 151, in create
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: loop.run_until_complete(pipeline)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: return future.result()
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/plugin/stages/api.py", line 225, in create_pipeline
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: await asyncio.gather(*futures)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/plugin/stages/api.py", line 43, in __call__
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: await self.run()
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/plugin/stages/artifact_stages.py", line 174, in run
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: pb.done += task.result()  # download_count
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/plugin/stages/artifact_stages.py", line 200, in _handle_content_unit
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: await asyncio.gather(*downloaders_for_content)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/plugin/stages/models.py", line 89, in download
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: download_result = await downloader.run(extra_data=self.extra_data)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulpcore/pulpcore/download/base.py", line 241, in run
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: return await self._run(extra_data=extra_data)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/home/vagrant/devel/pulp_rpm/pulp_rpm/app/downloaders.py", line 91, in _run
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: async with self.session.get(url, proxy=self.proxy, auth=self.auth) as response:
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py", line 1117, in __aenter__
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: self._resp = await self._coro
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py", line 521, in _request
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: req, traces=traces, timeout=real_timeout
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/connector.py", line 535, in connect
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: proto = await self._create_connection(req, traces, timeout)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/connector.py", line 892, in _create_connection
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: _, proto = await self._create_direct_connection(req, traces, timeout)
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/connector.py", line 1051, in _create_direct_connection
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: raise last_exc
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/connector.py", line 1032, in _create_direct_connection
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: client_error=client_error,
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/connector.py", line 975, in _wrap_create_connection
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: raise client_error(req.connection_key, exc) from exc
Jun 11 18:44:35 pulp2-nightly-pulp3-source-centos7.padre-fedora.example.com rq[8731]: aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host linux.dell.com:443 ssl:default [None]

Actions

Send by e-mail Copy link

Also available in: Atom PDF

Project

Profile

Help

RPM Support

Agile boards

Custom queries

Issue #7904

PulpImport can deadlock when importing Centos*-base and app-stream in one import file

Updated by daviddavis over 3 years ago

Updated by ggainey over 3 years ago

Updated by fao89 over 3 years ago

Updated by rchan over 3 years ago

Updated by rchan over 3 years ago

Updated by rchan about 3 years ago

Updated by rchan about 3 years ago

Updated by daviddavis about 3 years ago

Updated by ggainey about 3 years ago

Updated by ggainey about 3 years ago

Updated by ggainey about 3 years ago

Updated by pulpbot about 3 years ago

Updated by mdellweg about 3 years ago

Updated by ggainey almost 3 years ago

Updated by daviddavis almost 3 years ago

Updated by ggainey almost 3 years ago

Updated by ggainey almost 3 years ago

Updated by ggainey almost 3 years ago

Updated by ggainey almost 3 years ago

Updated by pulpbot almost 3 years ago

Updated by ggainey almost 3 years ago

Updated by wibbit almost 3 years ago

Updated by ggainey almost 3 years ago

Added by ggainey almost 3 years ago

Updated by ggainey almost 3 years ago

Updated by ttereshc almost 3 years ago

Updated by pulpbot almost 3 years ago

Updated by ggainey almost 3 years ago