Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Rare deadlock when importing and creating repos on the fly #3873

Open
ggainey opened this issue Jan 30, 2025 · 0 comments
Open

Rare deadlock when importing and creating repos on the fly #3873

ggainey opened this issue Jan 30, 2025 · 0 comments
Labels
Issue

Comments

@ggainey
Copy link
Contributor

ggainey commented Jan 30, 2025

Version
main

Describe the bug
See failures in https://github.com/pulp/pulp_rpm/actions/workflows/nightly.yml

The test_pulpimport.py::test_create_missing_repos test will occasionally fail with a deadlock while attempting to import Package content. This was a very common failure until #3830 , which we believed had addressed the issue. However, we still see it occasionally - it's just much less frequent now (e.g., 3 times in 91 runs of CI) The "S3" test is the "preferred" failure-mode (although we also see it even more rarely happen in the "lowerbounds" test scenario) - my assumption is the timing-window involved is exacerbated by the storage being somewhat slower going through minio.

We currently have no reports of this happening "in the wild".

Stacktrace from the failure is generally something like this one:

2025-01-30T03:24:56.2382589Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Starting task 0194b53c-485c-79fa-810c-058569ce221a in domain: default
2025-01-30T03:24:56.2383272Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Task completed 0194b53c-485c-79fa-810c-058569ce221a in domain: default
2025-01-30T03:24:56.2383979Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Starting task 0194b53c-4e31-7f2a-b62d-e450694e6d88 in domain: default
2025-01-30T03:24:56.2385005Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing /tmp/a02af805-70f9-45db-9ab3-b43bcea188cd/export-0194b53c-3bb6-778a-bf7a-c638f526d20b-20250130_0323.tar.
2025-01-30T03:24:56.2386643Z /usr/lib64/python3.9/tarfile.py:2268: RuntimeWarning: The default behavior of tarfile extraction has been changed to disallow common exploits (including CVE-2007-4559). By default, absolute/parent paths are disallowed and some mode bits are cleared. See https://access.redhat.com/articles/7004769 for more details.
2025-01-30T03:24:56.2386783Z   warnings.warn(
2025-01-30T03:24:56.2387639Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpaqn86z05/pulpcore.app.modelresource.ArtifactResource.json.
2025-01-30T03:24:56.2388726Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...Importing resource ArtifactResource.
2025-01-30T03:24:56.2389653Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Task completed 0194b53c-4e31-7f2a-b62d-e450694e6d88 in domain: default
2025-01-30T03:24:56.2390375Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Starting task 0194b53c-523f-7df6-8046-a816504f47db in domain: default
2025-01-30T03:24:56.2391988Z /usr/lib64/python3.9/tarfile.py:2268: RuntimeWarning: The default behavior of tarfile extraction has been changed to disallow common exploits (including CVE-2007-4559). By default, absolute/parent paths are disallowed and some mode bits are cleared. See https://access.redhat.com/articles/7004769 for more details.
2025-01-30T03:24:56.2392122Z   warnings.warn(
2025-01-30T03:24:56.2392842Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Starting task 0194b53c-524f-7de2-b3b0-30acd20b8d82 in domain: default
2025-01-30T03:24:56.2394478Z /usr/lib64/python3.9/tarfile.py:2268: RuntimeWarning: The default behavior of tarfile extraction has been changed to disallow common exploits (including CVE-2007-4559). By default, absolute/parent paths are disallowed and some mode bits are cleared. See https://access.redhat.com/articles/7004769 for more details.
2025-01-30T03:24:56.2394618Z   warnings.warn(
2025-01-30T03:24:56.2395809Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpyhnhnvbs/repository-c576dc79-369c-4234-be27-d9c3e5beb370_1/pulp_rpm.app.modelresource.RpmRepositoryResource.json.
2025-01-30T03:24:56.2396418Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...Importing resource RpmRepositoryResource.
2025-01-30T03:24:56.2397580Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpdp3tzx9b/repository-de218b8b-7db6-4e58-9591-4a49a77be49a_1/pulp_rpm.app.modelresource.RpmRepositoryResource.json.
2025-01-30T03:24:56.2398183Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...Importing resource RpmRepositoryResource.
2025-01-30T03:24:56.2399506Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpyhnhnvbs/repository-c576dc79-369c-4234-be27-d9c3e5beb370_1/pulp_rpm.app.modelresource.PackageResource.json.
2025-01-30T03:24:56.2400059Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...Importing resource PackageResource.
2025-01-30T03:24:56.2401178Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpdp3tzx9b/repository-de218b8b-7db6-4e58-9591-4a49a77be49a_1/pulp_rpm.app.modelresource.PackageResource.json.
2025-01-30T03:24:56.2401729Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...Importing resource PackageResource.
2025-01-30T03:24:56.2403050Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...3 import-errors encountered importing ./tmpyhnhnvbs/repository-c576dc79-369c-4234-be27-d9c3e5beb370_1/pulp_rpm.app.modelresource.PackageResource.json, attempt 2, retrying
2025-01-30T03:24:56.2404462Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...2 import-errors encountered importing ./tmpdp3tzx9b/repository-de218b8b-7db6-4e58-9591-4a49a77be49a_1/pulp_rpm.app.modelresource.PackageResource.json, attempt 2, retrying
2025-01-30T03:24:56.2405880Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...3 import-errors encountered importing ./tmpyhnhnvbs/repository-c576dc79-369c-4234-be27-d9c3e5beb370_1/pulp_rpm.app.modelresource.PackageResource.json, attempt 3, retrying
2025-01-30T03:24:56.2407262Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...2 import-errors encountered importing ./tmpdp3tzx9b/repository-de218b8b-7db6-4e58-9591-4a49a77be49a_1/pulp_rpm.app.modelresource.PackageResource.json, attempt 3, retrying
2025-01-30T03:24:56.2409040Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:ERROR: FATAL import-failure importing ./tmpyhnhnvbs/repository-c576dc79-369c-4234-be27-d9c3e5beb370_1/pulp_rpm.app.modelresource.PackageResource.json
2025-01-30T03:24:56.2410210Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO: Task[pulpcore.app.tasks.importer.import_repository_version] 0194b53c-523f-7df6-8046-a816504f47db failed (OperationalError: deadlock detected
2025-01-30T03:24:56.2410611Z DETAIL:  Process 12512 waits for ShareLock on transaction 114422; blocked by process 12514.
2025-01-30T03:24:56.2410964Z Process 12514 waits for ShareLock on transaction 114411; blocked by process 12512.
2025-01-30T03:24:56.2411127Z HINT:  See server log for query details.
2025-01-30T03:24:56.2411465Z CONTEXT:  while updating tuple (0,45) in relation "core_content") in domain: default
2025-01-30T03:24:56.2412355Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.tasking.tasks:INFO:   File "/usr/local/lib/python3.9/site-packages/pulpcore/tasking/tasks.py", line 68, in _execute_task
2025-01-30T03:24:56.2412515Z     result = func(*args, **kwargs)
2025-01-30T03:24:56.2412526Z 
2025-01-30T03:24:56.2413345Z   File "/usr/local/lib/python3.9/site-packages/pulpcore/app/tasks/importer.py", line 380, in import_repository_version
2025-01-30T03:24:56.2413712Z     for a_result in _import_file(os.path.join(rv_path, filename), res_class, retry=True):
2025-01-30T03:24:56.2413722Z 
2025-01-30T03:24:56.2414264Z   File "/usr/local/lib/python3.9/site-packages/pulpcore/app/tasks/importer.py", line 268, in _import_file
2025-01-30T03:24:56.2414501Z     a_result = resource.import_data(data, raise_errors=True)
2025-01-30T03:24:56.2414509Z 
2025-01-30T03:24:56.2414999Z   File "/usr/local/lib/python3.9/site-packages/import_export/resources.py", line 900, in import_data
2025-01-30T03:24:56.2415152Z     result = self.import_data_inner(
2025-01-30T03:24:56.2415160Z 
2025-01-30T03:24:56.2415709Z   File "/usr/local/lib/python3.9/site-packages/import_export/resources.py", line 1005, in import_data_inner
2025-01-30T03:24:56.2415895Z     raise row_result.errors[-1].error
2025-01-30T03:24:56.2415904Z 
2025-01-30T03:24:56.2416411Z   File "/usr/local/lib/python3.9/site-packages/import_export/resources.py", line 817, in import_row
2025-01-30T03:24:56.2416678Z     self.save_instance(instance, new, using_transactions, dry_run)
2025-01-30T03:24:56.2416694Z 
2025-01-30T03:24:56.2417203Z   File "/usr/local/lib/python3.9/site-packages/import_export/resources.py", line 528, in save_instance
2025-01-30T03:24:56.2417332Z     instance.save()
2025-01-30T03:24:56.2417340Z 
2025-01-30T03:24:56.2417608Z   File "/usr/lib64/python3.9/contextlib.py", line 79, in inner
2025-01-30T03:24:56.2417745Z     return func(*args, **kwds)
2025-01-30T03:24:56.2417753Z 
2025-01-30T03:24:56.2418209Z   File "/usr/local/lib/python3.9/site-packages/django_lifecycle/mixins.py", line 139, in save
2025-01-30T03:24:56.2418344Z     save(*args, **kwargs)
2025-01-30T03:24:56.2418352Z 
2025-01-30T03:24:56.2418790Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/base.py", line 814, in save
2025-01-30T03:24:56.2419116Z     self.save_base(
2025-01-30T03:24:56.2419125Z 
2025-01-30T03:24:56.2419588Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/base.py", line 876, in save_base
2025-01-30T03:24:56.2419868Z     parent_inserted = self._save_parents(cls, using, update_fields)
2025-01-30T03:24:56.2419877Z 
2025-01-30T03:24:56.2420381Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/base.py", line 918, in _save_parents
2025-01-30T03:24:56.2420530Z     updated = self._save_table(
2025-01-30T03:24:56.2420538Z 
2025-01-30T03:24:56.2421012Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/base.py", line 990, in _save_table
2025-01-30T03:24:56.2421161Z     updated = self._do_update(
2025-01-30T03:24:56.2421168Z 
2025-01-30T03:24:56.2421646Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/base.py", line 1054, in _do_update
2025-01-30T03:24:56.2422037Z     return filtered._update(values) > 0
2025-01-30T03:24:56.2422053Z 
2025-01-30T03:24:56.2422707Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/query.py", line 1231, in _update
2025-01-30T03:24:56.2422967Z     return query.get_compiler(self.db).execute_sql(CURSOR)
2025-01-30T03:24:56.2422977Z 
2025-01-30T03:24:56.2423661Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/sql/compiler.py", line 1984, in execute_sql
2025-01-30T03:24:56.2423823Z     cursor = super().execute_sql(result_type)
2025-01-30T03:24:56.2423831Z 
2025-01-30T03:24:56.2424375Z   File "/usr/local/lib/python3.9/site-packages/django/db/models/sql/compiler.py", line 1562, in execute_sql
2025-01-30T03:24:56.2424518Z     cursor.execute(sql, params)
2025-01-30T03:24:56.2424527Z 
2025-01-30T03:24:56.2424977Z   File "/usr/local/lib/python3.9/site-packages/django/db/backends/utils.py", line 67, in execute
2025-01-30T03:24:56.2425134Z     return self._execute_with_wrappers(
2025-01-30T03:24:56.2425142Z 
2025-01-30T03:24:56.2425713Z   File "/usr/local/lib/python3.9/site-packages/django/db/backends/utils.py", line 80, in _execute_with_wrappers
2025-01-30T03:24:56.2425887Z     return executor(sql, params, many, context)
2025-01-30T03:24:56.2425893Z 
2025-01-30T03:24:56.2426347Z   File "/usr/local/lib/python3.9/site-packages/django/db/backends/utils.py", line 89, in _execute
2025-01-30T03:24:56.2426522Z     return self.cursor.execute(sql, params)
2025-01-30T03:24:56.2426529Z 
2025-01-30T03:24:56.2426938Z   File "/usr/local/lib/python3.9/site-packages/django/db/utils.py", line 91, in __exit__
2025-01-30T03:24:56.2427252Z     raise dj_exc_value.with_traceback(traceback) from exc_value
2025-01-30T03:24:56.2427261Z 
2025-01-30T03:24:56.2427727Z   File "/usr/local/lib/python3.9/site-packages/django/db/backends/utils.py", line 89, in _execute
2025-01-30T03:24:56.2427910Z     return self.cursor.execute(sql, params)
2025-01-30T03:24:56.2427919Z 
2025-01-30T03:24:56.2428338Z   File "/usr/local/lib/python3.9/site-packages/psycopg/cursor.py", line 97, in execute
2025-01-30T03:24:56.2428519Z     raise ex.with_traceback(None)
2025-01-30T03:24:56.2428528Z 
2025-01-30T03:24:56.2429880Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpdp3tzx9b/repository-de218b8b-7db6-4e58-9591-4a49a77be49a_1/pulp_rpm.app.modelresource.ModulemdResource.json.
2025-01-30T03:24:56.2430471Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: ...Importing resource ModulemdResource.
2025-01-30T03:24:56.2431664Z pulp [ac63b862-5899-412f-9c27-5d2f7bec44e5]: pulpcore.app.tasks.importer:INFO: Importing file ./tmpdp3tzx9b/repository-de218b8b-7db6-4e58-9591-4a49a77be49a_1/pulp_rpm.app.modelresource.ModulemdDefaultsResource.json.

To Reproduce
No consistent reproducer. Happens "occasionally" during nightly CI runs.

Expected behavior
Don't deadlock.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Issue
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dralley @ggainey