2263315 – Restarting dynflow services when Sync Plan is being scheduled leads to hung task in planning/pending state

This bug has been migrated to another issue tracking site. It has been closed here and may no longer be being monitored.

If you would like to get updates for this issue, or to participate in it, you may do so at Red Hat Issue Tracker .

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.

Bug 2263315 - Restarting dynflow services when Sync Plan is being scheduled leads to hung task in planning/pending state

Summary: Restarting dynflow services when Sync Plan is being scheduled leads to hung t...

Keywords:
Status:	CLOSED MIGRATED
Alias:	None
Product:	Red Hat Satellite
Classification:	Red Hat
Component:	Tasks Plugin
Sub Component:
Version:	6.14.1
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	medium
Target Milestone:	stream
Assignee:	Adam Ruzicka
QA Contact:	Satellite QE Team
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2024-02-08 09:50 UTC by Pavel Moravec
Modified:	2024-06-06 17:02 UTC (History)
CC List:	4 users (show)
Fixed In Version:	rubygem-dynflow-1.8.4
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2024-06-06 17:02:17 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Github	Dynflow dynflow pull 443/files	0	None	None	None	2024-02-12 16:42:46 UTC
Red Hat Issue Tracker	SAT-23124	0	None	Migrated	None	2024-06-06 17:02:16 UTC

Description Pavel Moravec 2024-02-08 09:50:10 UTC

Description of problem:
When a Sync Plan is triggered to spawn tasks when dynflow services restart happens, there is a chance some spawned task for a repo sync will hang forever in planning/pending state, while it acquired a lock for the repo.

That leaves a hung task and also prevents the repo sync.


Version-Release number of selected component (if applicable):
Sat 6.12 (very evident and frequent)
Sat 6.14 (still sometimes seen, below reproducer is against this version)


How reproducible:
100% in a few iterations


Steps to Reproduce:
Idea: have 5 Sync Plans, each for 1 product containing 20 repos each. When Sync Plan is scheduled / triggered, restart dynflow services.

1. Set up Sync Plans, Products and repos:

datestamp=$(date "+%F")
for i in $(seq 1 5); do
	echo "sync-plan create --organization-id 1 --name sync_plan_${i} --interval 'custom cron' --sync-date ${datestamp} --enabled true --cron-expression '*/5 * * * *'"
	echo "product create --organization-id 1 --name zoo_product_${i} --sync-plan sync_plan_${i}"
	for j in $(seq 0 9); do
		echo "repository create --organization-id 1 --product zoo_product_${i} --name zoo_repo_${i}_${j} --content-type yum --url https://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/"
	done
done | hammer shell

2. Wait for time "*/5 * * * *" and monitor production.log

3. Once repos are synced, add more repos to the products:

for i in $(seq 1 5); do
	for j in $(seq 10 19); do
		echo "repository create --organization-id 1 --product zoo_product_${i} --name zoo_repo_${i}_${j} --content-type yum --url https://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/"
	done
done | hammer shell

.. and wait for a new Sync time.

4. Whenever you notice logs like:
2024-02-08T09:50:04 [I|bac|b0c09bbd] Task {label: , execution_plan_id: 94732150-b654-444e-a82f-e8b84c5ef88b} state changed: pending 
2024-02-08T09:50:04 [I|bac|b0c09bbd] Task {label: Actions::Katello::Repository::Sync, id: af1a6769-7b57-423b-8485-fa242876bb6e, execution_plan_id: 94732150-b654-444e-a82f-e8b84c5ef88b} state changed: planning 

restart dynflow services:

systemctl restart dynflow-sidekiq@*.service

(I recommend having the command prepared in 2nd terminal)

5. Wait until dynflow is restarted, tasks kicked off and repos synced - check if some hung task appears, in WebUI task search:

state != stopped and state != scheduled

6. If no task found, go to 2.

7. If task hung, wait for next Sync Plan execution and notice a sync fails with "Required lock is already taken by other running tasks." due to the hung task.


Actual results:
5. can show tasks in planning/pending state. An attempt to open dynflow console usually fails with NoMethodError : undefined method `state' for nil:NilClass

and backtrace in /var/log/messages:

Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: 2024-02-08 10:02:21 - NoMethodError - undefined method `state' for nil:NilClass:
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/lib/dynflow/web/console_helpers.rb:130:in `step_css_class'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/web/views/plan_step.erb:4:in `__tilt_603220'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `bind_call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `evaluate'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:109:in `render'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:863:in `render'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:711:in `erb'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/web/views/plan_step.erb:14:in `block in __tilt_603220'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/web/views/plan_step.erb:13:in `each'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/web/views/plan_step.erb:13:in `__tilt_603220'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `bind_call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `evaluate'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:109:in `render'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:863:in `render'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:711:in `erb'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/web/views/show.erb:56:in `__tilt_603220'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `bind_call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:191:in `evaluate'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/tilt-2.1.0/lib/tilt/template.rb:109:in `render'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:863:in `render'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:711:in `erb'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/dynflow-1.7.0/lib/dynflow/web/console.rb:64:in `block in <class:Console>'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1696:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1696:in `block in compile!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1030:in `block (3 levels) in route!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1049:in `route_eval'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1030:in `block (2 levels) in route!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1078:in `block in process_route'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1076:in `catch'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1076:in `process_route'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1028:in `block in route!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1025:in `each'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1025:in `route!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1040:in `route!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1147:in `block in dispatch!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `block in invoke'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `catch'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `invoke'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1142:in `dispatch!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:956:in `block in call!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `block in invoke'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `catch'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1119:in `invoke'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:956:in `call!'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:945:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/xss_header.rb:18:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/path_traversal.rb:16:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/json_csrf.rb:26:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/base.rb:50:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-protection-2.2.4/lib/rack/protection/frame_options.rb:31:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/null_logger.rb:11:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/head.rb:12:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/show_exceptions.rb:22:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:218:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:2004:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1564:in `block in call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1780:in `synchronize'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sinatra-2.2.4/lib/sinatra/base.rb:1564:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/urlmap.rb:74:in `block in call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/urlmap.rb:58:in `each'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/urlmap.rb:58:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/routing/mapper.rb:20:in `block in <class:Constraints>'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/routing/mapper.rb:49:in `serve'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/journey/router.rb:50:in `block in serve'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/journey/router.rb:32:in `each'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/journey/router.rb:32:in `serve'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/routing/route_set.rb:842:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/katello-4.9.0.16/lib/katello/middleware/organization_created_enforcer.rb:18:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/katello-4.9.0.16/lib/katello/middleware/event_daemon.rb:10:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/static.rb:24:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/apipie-dsl-2.5.0/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/apipie-rails-1.1.0/lib/apipie/static_dispatcher.rb:68:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/apipie-rails-1.1.0/lib/apipie/extractor/recorder.rb:139:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/static.rb:24:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/foreman/lib/foreman/middleware/libvirt_connection_cleaner.rb:9:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/apipie-rails-1.1.0/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/tempfile_reaper.rb:15:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/etag.rb:27:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/conditional_get.rb:27:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/head.rb:12:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/http/permissions_policy.rb:22:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/http/content_security_policy.rb:19:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/session/abstract/id.rb:266:in `context'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/session/abstract/id.rb:260:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/cookies.rb:697:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:98:in `run_callbacks'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/railties-6.1.7.3/lib/rails/rack/logger.rb:37:in `call_app'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/railties-6.1.7.3/lib/rails/rack/logger.rb:28:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/sprockets-rails-3.4.2/lib/sprockets/rails/quiet_assets.rb:13:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/request_id.rb:26:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/katello-4.9.0.16/lib/katello/prevent_json_parsing.rb:12:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/method_override.rb:24:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/runtime.rb:22:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/activesupport-6.1.7.3/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/executor.rb:14:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/sendfile.rb:110:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/ssl.rb:77:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/secure_headers-6.5.0/lib/secure_headers/middleware.rb:11:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/railties-6.1.7.3/lib/rails/engine.rb:539:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/railties-6.1.7.3/lib/rails/railtie.rb:207:in `public_send'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/railties-6.1.7.3/lib/rails/railtie.rb:207:in `method_missing'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/urlmap.rb:74:in `block in call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/urlmap.rb:58:in `each'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/rack-2.2.7/lib/rack/urlmap.rb:58:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/configuration.rb:270:in `call'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/request.rb:98:in `block in handle_request'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/thread_pool.rb:340:in `with_force_shutdown'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/request.rb:97:in `handle_request'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/server.rb:431:in `process_client'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/server.rb:233:in `block in run'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/puma-6.2.2/lib/puma/thread_pool.rb:147:in `block in spawn_thread'
Feb  8 10:02:21 pmoravec-sat614 foreman[2298]: #011/usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'


7. Some repo sync task fails with error "Required lock is already taken by other running tasks." - until we get rid of the hung task.


Expected results:
5. No such hung tasks. Failed tasks are OK (it makes a little sense to schedule or kick off tasks when stopping tasking service - and assume they will surely succeed)


Additional info:
In Sat6.12, the hung tasks were quite frequent and dynflow console showed either an exception or some empty task (with 1 dynflow step instead of expected 10-ish).  In 6.14, I see improvements / less stuck tasks and so far just the exception and no other variant of hung task.

Comment 1 Adam Ruzicka 2024-02-09 10:05:29 UTC

Maybe a dead end, but can you still reproduce if you replace "systemctl restart dynflow-sidekiq@*.service" with "systemctl stop dynflow-sidekiq@{orchestrator,worker-1,worker-hosts-queue-1}.service; sleep 60; systemctl start dynflow-sidekiq@{orchestrator,worker-1,worker-hosts-queue-1}.service"?

Comment 2 Pavel Moravec 2024-02-09 17:51:46 UTC

(In reply to Adam Ruzicka from comment #1)
> Maybe a dead end, but can you still reproduce if you replace "systemctl
> restart dynflow-sidekiq@*.service" with "systemctl stop
> dynflow-sidekiq@{orchestrator,worker-1,worker-hosts-queue-1}.service; sleep
> 60; systemctl start
> dynflow-sidekiq@{orchestrator,worker-1,worker-hosts-queue-1}.service"?

Yes I can.

When trying to reproduce in *either* way, I realized I need to first let the Sync plan running, *then* add more repos to the products in sync plans, and even *then* play(*) with services during Sync Plan triggering time. I updated the BZ description accordingly (and dont ask me for the amount of time spent on failing attempts to reproduce *without* this extra step of adding repos.. :) ).

(*) either restart them (systemctl restart dynflow-sidekiq@*.service) or also the stop-wait-start (systemctl stop dynflow-sidekiq@{orchestrator,worker-1,worker-hosts-queue-1}.service; sleep 60; systemctl start dynflow-sidekiq@{orchestrator,worker-1,worker-hosts-queue-1}.service).

Comment 4 Eric Helms 2024-06-06 17:02:17 UTC

This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.

Due to differences in account names between systems, some fields were not replicated.  Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.

To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "SAT-" followed by an integer.  You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:

"Bugzilla Bug" = 1234567

In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.

Note You need to log in before you can comment on or make changes to this bug.