Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
Red Hat Satellite engineering is moving the tracking of its product development work on Satellite to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "Satellite project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs will be migrated starting at the end of May. If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "Satellite project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/SAT-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
"ERF12-9562 [ProxyAPI::ProxyException]: Unable to update the repository list for Capsule https://capsule1.example.com:9090/container_gateway/repository_list" during docker type content sync in Capsule 6.10.6
Description of problem:
Not always but sometimes very randomly, the Capsule sync task fails with the following error:
ERF12-9562 [ProxyAPI::ProxyException]: Unable to update the repository list ([RestClient::InternalServerError]: 500 Internal Server Error) for Capsule https://capsule1.example.com:9090/container_gateway/repository_listERF12-9562 [ProxyAPI::ProxyException]: Unable to update the repository list ([RestClient::InternalServerError]: 500 Internal Server Error) for Capsule https://capsule1.example.com:9090/container_gateway/repository_list
Version-Release number of selected component (if applicable):
Satellite Capsule 6.10.6
How reproducible:
In the customer environment ( not always but sometimes )
Steps to Reproduce:
NA at this moment
Actual results:
In production.log of the satellite:
~~~
2022-06-15T05:49:52 [I|aud|770eab6b] Katello::Repository (84060) update event on last_indexed 1970-01-01 00:00:00 UTC, 2022-06-15 03:49:52 UTC
2022-06-15T05:50:00 [I|aud|770eab6b] Katello::Repository (4534) update event on publication_href /pulp/api/v3/publications/rpm/rpm/8f405032-3eb5-49fe-a8c1-68619cb04463/, /pulp/api/v3/publications/rpm/rpm/2eff3b29-5951-4be3-91b2-b73f630d8749/
2022-06-15T05:50:13 [I|aud|770eab6b] Katello::Repository (4534) update event on last_indexed 2022-06-14 03:52:08 UTC, 2022-06-15 03:50:13 UTC
2022-06-15T05:52:14 [I|app|770eab6b] CONTENT_INDEX type=Katello::Rpm success=true duration=190249.76
2022-06-15T05:52:15 [I|app|770eab6b] CONTENT_INDEX type=Katello::ModuleStream success=true duration=333.59
2022-06-15T05:53:31 [I|app|770eab6b] CONTENT_INDEX type=Katello::Erratum success=true duration=76267.65
2022-06-15T05:53:31 [I|app|770eab6b] CONTENT_INDEX type=Katello::PackageGroup success=true duration=415.51
2022-06-15T05:53:32 [I|app|770eab6b] CONTENT_INDEX type=Katello::Srpm success=true duration=237.61
2022-06-15T05:53:32 [I|aud|770eab6b] Katello::Repository (84073) update event on last_indexed 1970-01-01 00:00:00 UTC, 2022-06-15 03:53:32 UTC
2022-06-15T05:53:42 [I|aud|770eab6b] Katello::Repository (4511) update event on publication_href /pulp/api/v3/publications/rpm/rpm/0678f692-610c-4947-a426-77b13a724f06/, /pulp/api/v3/publications/rpm/rpm/5881a659-f82b-4f31-9ee1-d08b6c4ebe8e/
2022-06-15T05:54:03 [I|aud|770eab6b] Katello::Repository (4511) update event on last_indexed 2022-06-14 04:04:40 UTC, 2022-06-15 03:54:03 UTC
2022-06-15T05:54:05 [I|app|770eab6b] Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/views/katello/errata_mailer/promote_errata.html.erb within layouts/application_mailer
2022-06-15T05:54:05 [I|app|770eab6b] Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/views/katello/errata_mailer/_host_dashboard.html.erb (Duration: 3.3ms | Allocations: 1454)
2022-06-15T05:54:05 [I|app|770eab6b] Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/views/katello/errata_mailer/promote_errata.html.erb within layouts/application_mailer (Duration: 6.1ms | Allocations: 3051)
2022-06-15T05:54:05 [I|app|770eab6b] Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/views/katello/errata_mailer/promote_errata.text.erb
2022-06-15T05:54:05 [I|app|770eab6b] Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/views/katello/errata_mailer/promote_errata.text.erb (Duration: 1.3ms | Allocations: 1423)
2022-06-15T05:54:05 [W|app|770eab6b] Scoped order is ignored, it's forced to be batch order.
(33.2ms)
2022-06-15T05:54:09 [I|aud|770eab6b] Katello::ContentViewVersion (10696) update event on content_counts , {"ansible collection"=>0, "docker_manifest"=>0, "docker_manifest_list"=>0, "docker_tag"=>0, "file"=>0, "rpm"=>69761, "modulemd"=>0, "erratum"=>4523, "package_group"=>79, "srpm"=>0}
2022-06-15T05:54:09 [I|bac|770eab6b] Task {label: Actions::Katello::ContentView::CapsuleSync, id: 9343d1bc-bc12-4f5c-9ed8-a8718f39758b, execution_plan_id: f71ce9b4-e9e7-490c-b7a9-48fae99bcc83} state changed: planning
2022-06-15T05:54:09 [I|bac|770eab6b] Task {label: Actions::Katello::ContentView::CapsuleSync, id: 9343d1bc-bc12-4f5c-9ed8-a8718f39758b, execution_plan_id: f71ce9b4-e9e7-490c-b7a9-48fae99bcc83} state changed: planned
2022-06-15T05:54:10 [I|bac|770eab6b] Task {label: Actions::Katello::ContentView::Publish, id: eb616392-fb7f-45a6-8784-f6dbcddc609f, execution_plan_id: f4a69cbc-8759-4a7c-85e5-3d087b7182ad} state changed: stopped result: success
2022-06-15T05:54:10 [I|bac|770eab6b] Task {label: Actions::Katello::ContentView::Publish, id: eb616392-fb7f-45a6-8784-f6dbcddc609f, execution_plan_id: f4a69cbc-8759-4a7c-85e5-3d087b7182ad} state changed: stopped result: success
2022-06-15T05:54:10 [I|bac|770eab6b] Task {label: Actions::Katello::ContentView::CapsuleSync, id: 9343d1bc-bc12-4f5c-9ed8-a8718f39758b, execution_plan_id: f71ce9b4-e9e7-490c-b7a9-48fae99bcc83} state changed: running
2022-06-15T05:54:12 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: f6d55e44-100a-4aac-b88e-b6c09c74ff7b, execution_plan_id: b42e4c25-a5cd-4f59-9c87-ce2c029ee0c6} state changed: planning
2022-06-15T05:54:43 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: f6d55e44-100a-4aac-b88e-b6c09c74ff7b, execution_plan_id: b42e4c25-a5cd-4f59-9c87-ce2c029ee0c6} state changed: planned
2022-06-15T05:54:43 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: f6d55e44-100a-4aac-b88e-b6c09c74ff7b, execution_plan_id: b42e4c25-a5cd-4f59-9c87-ce2c029ee0c6} state changed: running
2022-06-15T05:54:43 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: 79d01289-a6a3-4d18-97eb-74930ec6ce8b, execution_plan_id: a51f9e34-20cf-4be0-9c77-d4ef6bfa74ee} state changed: planning
2022-06-15T05:55:08 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: 79d01289-a6a3-4d18-97eb-74930ec6ce8b, execution_plan_id: a51f9e34-20cf-4be0-9c77-d4ef6bfa74ee} state changed: planned
2022-06-15T05:55:08 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: a0d3d929-b0b6-4a11-ba0b-2d89e2e2d481, execution_plan_id: e1fbe852-5221-4585-8982-44512d71ff46} state changed: planning
2022-06-15T05:55:08 [I|bac|770eab6b] Task {label: Actions::Katello::CapsuleContent::Sync, id: 79d01289-a6a3-4d18-97eb-74930ec6ce8b, execution_plan_id: a51f9e34-20cf-4be0-9c77-d4ef6bfa74ee} state changed: running
2022-06-15T05:55:22 [E|bac|770eab6b] ERF12-9562 [ProxyAPI::ProxyException]: Unable to update the repository list ([RestClient::InternalServerError]: 500 Internal Server Error) for Capsule https://capsule1.example.com:9090/container_gateway/repository_list (ProxyAPI::ProxyException)
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/lib/proxy_api/container_gateway.rb:13:in `rescue in repository_list'
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/lib/proxy_api/container_gateway.rb:8:in `repository_list'
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/models/katello/concerns/smart_proxy_extensions.rb:118:in `update_container_repo_list'
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/lib/actions/katello/capsule_content/sync_capsule.rb:63:in `update_container_repo_list'
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/lib/actions/katello/capsule_content/sync_capsule.rb:44:in `sync_container_gateway'
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/app/lib/actions/katello/capsule_content/sync_capsule.rb:39:in `plan'
..
..
2022-06-15T05:55:22 [E|bac|770eab6b] ERF12-9562 [ProxyAPI::ProxyException]: Unable to update the repository list ([RestClient::InternalServerError]: 500 Internal Server Error) for Capsule https://capsule1.example.com:9090/container_gateway/repository_list (ProxyAPI::ProxyException)
770eab6b | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.1.1.57/lib/proxy_api/container_gateway.rb:13:in `rescue in repository_list'
~~~
In proxy.log of capsule [ the time stamps won't match as the capsule logs are from a different failed task ]
~~~
2022-07-04T15:55:29 645743e1 [I] Finished PUT /container_gateway/repository_list/ with 200 (4264.87 ms)
2022-07-04T15:55:29 645743e1 [I] Started GET /container_gateway/users
2022-07-04T15:55:29 645743e1 [I] Finished GET /container_gateway/users with 200 (2.99 ms)
2022-07-04T15:57:26 645743e1 [I] Started PUT /container_gateway/repository_list/
2022-07-04T15:57:35 645743e1 [I] Finished PUT /container_gateway/repository_list/ with 200 (8318.3 ms)
2022-07-04T15:57:35 645743e1 [I] Started GET /container_gateway/users
2022-07-04T15:57:35 645743e1 [I] Finished GET /container_gateway/users with 200 (0.64 ms)
2022-07-04T16:00:41 645743e1 [I] Started PUT /container_gateway/repository_list/
2022-07-04T16:00:49 645743e1 [I] Started PUT /container_gateway/repository_list/
2022-07-04T16:00:56 645743e1 [W] Error processing request '645743e1-7a7d-4156-8fd5-d782b748bba2: <Sequel::DatabaseError>: SQLite3::BusyException: database is locked
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/statement.rb:108:in `step'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/statement.rb:108:in `block in each'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/statement.rb:107:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/statement.rb:107:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/database.rb:156:in `to_a'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/database.rb:156:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/database.rb:95:in `prepare'
/opt/theforeman/tfm/root/usr/share/gems/gems/sqlite3-1.3.13/lib/sqlite3/database.rb:137:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/adapters/sqlite.rb:202:in `block (2 levels) in _execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/database/logging.rb:38:in `log_connection_yield'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/adapters/sqlite.rb:202:in `block in _execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/connection_pool/threaded.rb:88:in `hold'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/database/connecting.rb:269:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/adapters/sqlite.rb:193:in `_execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/adapters/sqlite.rb:159:in `execute_insert'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/dataset/actions.rb:1109:in `execute_insert'
..
..
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/model/base.rb:1488:in `block in save'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/model/base.rb:1930:in `checked_save_failure'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/model/base.rb:1488:in `save'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/model/base.rb:254:in `create'
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.42.0/lib/sequel/model/base.rb:425:in `find_or_create'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_container_gateway-1.0.6/lib/smart_proxy_container_gateway/container_gateway_main.rb:82:in `block in update_repository_list'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_container_gateway-1.0.6/lib/smart_proxy_container_gateway/container_gateway_main.rb:81:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_container_gateway-1.0.6/lib/smart_proxy_container_gateway/container_gateway_main.rb:81:in `update_repository_list'
/opt/theforeman/tfm/root/usr/share/gems/gems/smart_proxy_container_gateway-1.0.6/lib/smart_proxy_container_gateway/container_gateway_api.rb:131:in `block in <class:Api>'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.1.0/lib/sinatra/base.rb:1675:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.1.0/lib/sinatra/base.rb:1675:in `block in compile!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.1.0/lib/sinatra/base.rb:1013:in `block (3 levels) in route!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.1.0/lib/sinatra/base.rb:1032:in `route_eval'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.1.0/lib/sinatra/base.rb:1013:in `block (2 levels) in route!'
..
..
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/builder.rb:244:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/handler/webrick.rb:95:in `service'
/opt/rh/rh-ruby27/root/usr/share/ruby/webrick/httpserver.rb:140:in `service'
/opt/rh/rh-ruby27/root/usr/share/ruby/webrick/httpserver.rb:96:in `run'
/opt/rh/rh-ruby27/root/usr/share/ruby/webrick/server.rb:307:in `block in start_thread'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2022-07-04T16:00:56 645743e1 [I] Finished PUT /container_gateway/repository_list/ with 500 (15334.02 ms)
2022-07-04T16:01:04 645743e1 [I] Finished PUT /container_gateway/repository_list/ with 200 (15027.93 ms)
2022-07-04T16:01:05 645743e1 [I] Started GET /container_gateway/users
2022-07-04T16:01:05 645743e1 [I] Finished GET /container_gateway/users with 200 (0.8 ms)
~~~
Expected results:
No such transaction locks and clean\uninterrputed capsule syncs.
Additional info:
Even in the customer's own infra, this issue is not always reproducible:
A) I noticed that usually most of the auto-generated capsule sync tasks are completed fine.
B) I tried a manual "Optimized Sync" of the same capsule but it was completed successfully without any issues.
So no idea how and why that transaction lock is getting created in the sqlite DB that is used by the container_gateway plugin on capsule.