Bug #35025
closedEvery CV Publish+Promote action followed by an automated Capsule sync task generates a huge traceback "(ActiveRecord::RecordNotFound): Couldn't find ForemanTasks::Task::DynflowTask" in Satellite 6.11
Description
Cloned from https://bugzilla.redhat.com/show_bug.cgi?id=2093884
Description of problem:
In Satellite 6.11, We get a very nice feature to Publish a CV and then promote it as the same time at once in just one click.
While doing so, Even if the task gets completed without any issues and then automatically initiates the related Actions::Katello::ContentView::CapsuleSync tasks, At some point dynflow raises a huge traceback which could easily flood the production.log
Version-Release number of selected component (if applicable):
satellite-6.11.0-1.el8sat.noarch
rubygem-dynflow-1.6.4-1.el8sat.noarch
katello-4.3.0-2.el8sat.noarch
How reproducible:
Always in latest snap of 6.11
Steps to Reproduce:
1. INstall a Satellite and Capsule 6.11 on RHEL 8
2. Import a manifest, Enable and sync some repos.
3. Create a Lifecycle called QA, after Library and add both of the Environments to the external capsule for content syncing.
4. Add those two repos in a CV --> Publish a new version and also select the promote option to promote the CV version to QA at the same time.
5. Monitor /var/log/foreman/production.log file while the task executes and then initiates the related capsule sync tasks.
Actual results:
2022-06-04T17:43:18 [I|bac|c3da4261] Task {label: Actions::Katello::ContentView::CapsuleSync, id: 0c79aac5-b798-4457-b848-0fd258dbc6fb, execution_plan_id: fd8833cf-1298-4b8d-b8de-98c37d4628fe} state changed: planning
2022-06-04T17:43:18 [I|bac|c3da4261] Task {label: Actions::Katello::ContentView::CapsuleSync, id: 0c79aac5-b798-4457-b848-0fd258dbc6fb, execution_plan_id: fd8833cf-1298-4b8d-b8de-98c37d4628fe} state changed: planned
2022-06-04T17:43:18 [I|bac|c3da4261] Task {label: Actions::Katello::ContentView::CapsuleSync, execution_plan_id: fd8833cf-1298-4b8d-b8de-98c37d4628fe} state changed: running
2022-06-04T17:43:18 [I|bac|c3da4261] Task {label: , id: 64303b6d-b56e-49fd-bde4-c79a2f70d61f, execution_plan_id: 0157df0c-2200-4340-9e55-48e86246d729} state changed: pending
2022-06-04T17:43:18 [W|dyn|c3da4261] Error on on_execution_plan_save event
2022-06-04T17:43:18 [I|dyn|c3da4261] Backtrace for 'Error on on_execution_plan_save event' error (ActiveRecord::RecordNotFound): Couldn't find ForemanTasks::Task::DynflowTask with [WHERE "foreman_tasks_tasks"."type" = $1 AND "foreman_tasks_tasks"."external_id" = $2]
c3da4261 | /usr/share/gems/gems/activerecord-6.0.4.7/lib/active_record/relation/finder_methods.rb:336:in `raise_record_not_found_exception!'
c3da4261 | /usr/share/gems/gems/activerecord-6.0.4.7/lib/active_record/relation/finder_methods.rb:127:in `first!'
c3da4261 | /usr/share/gems/gems/foreman-tasks-5.2.3/app/models/foreman_tasks/task/dynflow_task.rb:19:in `update_from_dynflow'
c3da4261 | /usr/share/gems/gems/foreman-tasks-5.2.3/lib/foreman_tasks/dynflow/persistence.rb:36:in `on_execution_plan_save'
c3da4261 | /usr/share/gems/gems/foreman-tasks-5.2.3/lib/foreman_tasks/dynflow/persistence.rb:11:in `block in save_execution_plan'
c3da4261 | /usr/share/gems/gems/foreman-tasks-5.2.3/lib/foreman_tasks/dynflow/persistence.rb:10:in `tap'
c3da4261 | /usr/share/gems/gems/foreman-tasks-5.2.3/lib/foreman_tasks/dynflow/persistence.rb:10:in `save_execution_plan'
c3da4261 | /usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/persistence.rb:84:in `save_execution_plan'
c3da4261 | /usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan.rb:450:in `save'
c3da4261 | /usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan.rb:145:in `update_state'
c3da4261 | /usr/share/gems/gems/dynflow-1.6.4/lib/dynflow/execution_plan.rb:286:in `plan'
..
..
c3da4261 | /usr/share/gems/gems/sidekiq-5.2.10/lib/sidekiq/util.rb:25:in `block in safe_thread'
c3da4261 | /usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2022-06-04T17:43:18 [I|bac|c3da4261] Task {label: Actions::Katello::CapsuleContent::Sync, id: 64303b6d-b56e-49fd-bde4-c79a2f70d61f, execution_plan_id: 0157df0c-2200-4340-9e55-48e86246d729} state changed: planning
Expected results:
Even if the task actually gets processed, the traceback should not be there. Dynflow should be able to handle the traceback or the root cause behind it carefully.
Additional info:
Related logs will be attached to the BZ soon.
I am setting the severity to high as if this continues to happen, It can easily flood the production.log file.