Problem:
Since the latest of our main server and content proxy
Upgrade python39-pulpcore-3.22.14-1.el8.noarch @ORG_katello_pulpcore_3_22_el8_x86_64
Upgraded python39-pulpcore-3.22.12-1.el8.noarch @@System
Upgrade python39-pulp-deb-2.20.4-1.el8.noarch @ORG_katello_pulpcore_3_22_el8_x86_64
Upgraded python39-pulp-deb-2.20.2-1.el8.noarch @@System
I occasionally have content proxy syncs after a new cv publish taking 2 hours or longer instead of 10 minutes or less as usually.
I can see that a postmaster process is running at 100% and pg_stat_activity shows a specific type of query running a couple of minutes, like the following one. The following is on the postgresql database on the content proxy.
pulpcore=# select state, query_start, current_timestamp, query from pg_stat_activity where state <> 'idle';
state | query_start | current_timestamp |
query
--------+-------------------------------+-------------------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
active | 2023-09-19 06:42:21.677564+02 | 2023-09-19 06:42:21.677564+02 | select state, query_start, current_timestamp, query from pg_stat_activity where state <> 'idle';
active | 2023-09-19 06:36:26.901377+02 | 2023-09-19 06:42:21.677564+02 | SELECT "core_content"."pulp_id" FROM "core_content" WHERE ("core_content"."pulp_id" IN ('496440d4-1388-4ba5-a1fc-16cbdc29da89'::uuid, 'f28544f0-b8f4-42b4-806b-b09b2f0eaa7a'::uuid, 'f5c40092-0c30-47f1-a213-acd7b25df32a'::u
uid, 'a327d603-7c42-4243-96c8-6d0a0f422c78'::uuid) AND NOT ("core_content"."pulp_id" IN (SELECT V0."pulp_id" FROM "core_content" V0 WHERE V0."pulp_id" IN (SELECT U0."content_id" FROM "core_repositorycontent" U0 INNER JOIN "core_repositoryversion" U2 ON (U0."version_added_id" = U2."pulp_id") LEF
T OUTER JOIN "core_repositoryversion" U3 ON (U0."version_removed_id" = U3."pulp_id") WHERE (U0."repository_id" = '43e7b651-8399-4bda-b54e-900dea17af7e'::uuid AND U2."number" <= 235 AND NOT (U3."number" <= 235 AND U3."number" IS NOT NULL))))))
(2 rows)
pulpcore=# EXPLAIN SELECT "core_content"."pulp_id" FROM "core_content" WHERE ("core_content"."pulp_id" IN ('496440d4-1388-4ba5-a1fc-16cbdc29da89'::uuid, 'f28544f0-b8f4-42b4-806b-b09b2f0eaa7a'::uuid, 'f5c40092-0c30-47f1-a213-acd7b25df32a'::uuid, 'a327d603-7c42-4243-96c8-6d0a0f422c78'::uuid) AND NOT ("core_content"."pulp_id" IN (SELECT V0."pulp_id" FROM "core_content" V0 WHERE V0."pulp_id" IN (SELECT U0."content_id" FROM "core_repositorycontent" U0 INNER JOIN "core_repositoryversion" U2 ON (U0."version_added_id" = U2."pulp_id") LEFT OUTER JOIN "core_repositoryversion" U3 ON (U0."version_removed_id" = U3."pulp_id") WHERE (U0."repository_id" = '43e7b651-8399-4bda-b54e-900dea17af7e'::uuid AND U2."number" <= 235 AND NOT (U3."number" <= 235 AND U3."number" IS NOT NULL))))));
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Index Only Scan using core_content_pkey on core_content (cost=48176.71..48202.06 rows=2 width=16)
Index Cond: (pulp_id = ANY ('{496440d4-1388-4ba5-a1fc-16cbdc29da89,f28544f0-b8f4-42b4-806b-b09b2f0eaa7a,f5c40092-0c30-47f1-a213-acd7b25df32a,a327d603-7c42-4243-96c8-6d0a0f422c78}'::uuid[]))
Filter: (NOT (hashed SubPlan 1))
SubPlan 1
-> Nested Loop Semi Join (cost=4009.00..48176.29 rows=1 width=16)
Join Filter: (v0.pulp_id = u0.content_id)
-> Seq Scan on core_content v0 (cost=0.00..7129.81 rows=278881 width=16)
-> Materialize (cost=4009.00..36863.27 rows=1 width=16)
-> Nested Loop (cost=4009.00..36863.26 rows=1 width=16)
Join Filter: (u0.version_added_id = u2.pulp_id)
-> Hash Left Join (cost=4009.00..36793.66 rows=1 width=32)
Hash Cond: (u0.version_removed_id = u3.pulp_id)
Filter: ((u3.number > 235) OR (u3.number IS NULL))
-> Bitmap Heap Scan on core_repositorycontent u0 (cost=3943.86..36617.66 rows=42233 width=48)
Recheck Cond: (repository_id = '43e7b651-8399-4bda-b54e-900dea17af7e'::uuid)
-> Bitmap Index Scan on core_repositorycontent_repository_id_1946e61b (cost=0.00..3933.30 rows=42233 width=0)
Index Cond: (repository_id = '43e7b651-8399-4bda-b54e-900dea17af7e'::uuid)
-> Hash (cost=42.84..42.84 rows=1784 width=20)
-> Seq Scan on core_repositoryversion u3 (cost=0.00..42.84 rows=1784 width=20)
-> Seq Scan on core_repositoryversion u2 (cost=0.00..47.30 rows=1784 width=16)
Filter: (number <= 235)
(21 rows)
As you can see the query is already running for 6 minutes.
The task running is this:
Actions::Pulp3::CapsuleContent::Sync
State:suspended
Input:
{"repository_id"=>2181,
"smart_proxy_id"=>5,
"options"=>{"skip_metadata_check"=>false},
"remote_user"=>"admin",
"remote_cp_user"=>"admin",
"current_request_id"=>"4b49a750-94cf-4c62-8f87-e610ce5472d9",
"current_timezone"=>"UTC",
"current_organization_id"=>nil,
"current_location_id"=>nil,
"current_user_id"=>4}
Output:
{"smart_proxy_history_id"=>26672,
"pulp_tasks"=>
[{"pulp_href"=>"/pulp/api/v3/tasks/b6356c1e-4054-4c41-ba79-889c0e204173/",
"pulp_created"=>"2023-09-19T02:35:51.384+00:00",
"state"=>"running",
"name"=>"pulp_rpm.app.tasks.synchronizing.synchronize",
"logging_cid"=>"4b49a750-94cf-4c62-8f87-e610ce5472d9",
"started_at"=>"2023-09-19T02:36:00.450+00:00",
"worker"=>"/pulp/api/v3/workers/71e5e226-b611-4070-a047-4ed932c493eb/",
"child_tasks"=>[],
"progress_reports"=>
[{"message"=>"Parsed Comps",
"code"=>"sync.parsing.comps",
"state"=>"completed",
"total"=>22,
"done"=>22},
{"message"=>"Downloading Metadata Files",
"code"=>"sync.downloading.metadata",
"state"=>"completed",
"done"=>6},
{"message"=>"Downloading Artifacts",
"code"=>"sync.downloading.artifacts",
"state"=>"running",
"done"=>0},
{"message"=>"Associating Content",
"code"=>"associating.content",
"state"=>"running",
"done"=>51},
{"message"=>"Skipping Packages",
"code"=>"sync.skipped.packages",
"state"=>"completed",
"total"=>0,
"done"=>0},
{"message"=>"Parsed Packages",
"code"=>"sync.parsing.packages",
"state"=>"completed",
"total"=>37217,
"done"=>37217},
{"message"=>"Parsed Advisories",
"code"=>"sync.parsing.advisories",
"state"=>"completed",
"total"=>6356,
"done"=>6356}],
"created_resources"=>[""],
"reserved_resources_record"=>
["/pulp/api/v3/repositories/rpm/rpm/43e7b651-8399-4bda-b54e-900dea17af7e/",
"shared:/pulp/api/v3/remotes/rpm/rpm/6732d168-717d-47d1-9406-5fbb1fb52efd/"]}],
"task_groups"=>[],
"poll_attempts"=>{"total"=>479, "failed"=>0}}
Expected outcome:
Faster content proxy sync.
Foreman and Proxy versions:
Main server and content proxy are running
katello-4.8.4-1.el8.noarch
foreman-3.6.2-1.el8.noarch
with the latest updates.
These are the installed rpms on the content proxy:
# rpm -qa *foreman* *katello* *pulp* | sort -d
foreman-debug-3.6.2-1.el8.noarch
foreman-installer-3.6.2-1.el8.noarch
foreman-installer-katello-3.6.2-1.el8.noarch
foreman-proxy-3.6.2-1.el8.noarch
foreman-proxy-content-4.8.4-1.el8.noarch
katello-certs-tools-2.9.0-1.el8.noarch
katello-client-bootstrap-1.7.9-1.el8.noarch
katello-common-4.8.4-1.el8.noarch
katello-debug-4.8.4-1.el8.noarch
katello-host-tools-3.5.7-5.el8.noarch
katello-host-tools-tracer-3.5.7-5.el8.noarch
pulpcore-selinux-1.3.2-1.el8.x86_64
python39-pulp-ansible-0.16.0-1.el8.noarch
python39-pulp-certguard-1.5.6-1.el8.noarch
python39-pulp-container-2.14.7-1.el8.noarch
python39-pulpcore-3.22.14-1.el8.noarch
python39-pulp-deb-2.20.4-1.el8.noarch
python39-pulp-file-1.12.0-1.el8.noarch
python39-pulp-python-3.8.0-1.el8.noarch
python39-pulp-rpm-3.19.9-1.el8.noarch
rubygem-foreman_maintain-1.3.5-1.el8.noarch
rubygem-smart_proxy_pulp-3.2.0-3.fm3_3.el8.noarch
Distribution and version:
AlmaLinux 8.8
Other relevant data:
