Repository disable bug explanation

gistfile1.md

With dynflow actions, the disable repository tasks are run concurrently, and there are race conditions. I used the following to debug:

diff --git a/app/lib/actions/candlepin/environment/set_content.rb b/app/lib/actions/candlepin/environment/set_content.rb
index e78fcd7..87659ba 100644
--- a/app/lib/actions/candlepin/environment/set_content.rb
+++ b/app/lib/actions/candlepin/environment/set_content.rb
@@ -12,7 +12,9 @@ module Actions
         def finalize
           content_view = ::Katello::ContentView.find(input[:content_view_id])
           environment = ::Katello::KTEnvironment.find(input[:environment_id])
+          Rails.logger.debug "jomitsch debug - Getting all repos for content view #{content_view.id}"
           content_ids = content_view.repos(environment).map(&:content_id).uniq.compact
+          Rails.logger.debug "jomitsch debug - Got repos for content view repos: #{content_view.repos(environment).map(&:id)} cv_id: #{content_view.id}"
           # in case we create new custom repository that doesn't have the
           # content_id set yet in the plan phase, we allow to pass it as
           # additional argument
diff --git a/app/lib/actions/katello/repository/destroy.rb b/app/lib/actions/katello/repository/destroy.rb
index e48960c..6056d9c 100644
--- a/app/lib/actions/katello/repository/destroy.rb
+++ b/app/lib/actions/katello/repository/destroy.rb
@@ -12,6 +12,8 @@ module Actions
               options.fetch(:organization_destroy, false)
           action_subject(repository)
 
+          Rails.logger.debug "#" * 100
+          Rails.logger.debug "jomitsch debug - Planning action with repo #{repository.id} associated with root repo #{repository.root.id}"
           unless repository.destroyable?
             # The repository is going to be deleted in finalize, but it cannot be deleted.
             # Stop now and inform the user.
@@ -53,8 +55,13 @@ module Actions
         end
 
         def delete_record(repository)
-          repository.destroy!
-          repository.root.destroy! if repository.root.repositories.empty?
+          repository.with_lock do
+            Rails.logger.debug "jomitsch debug - Destroying repo #{repository.id} associated with root repo #{repository.root.id}"
+            repository.destroy!
+            Rails.logger.debug "jomitsch debug - Destroying root repo #{repository.root.id}"
+            repository.root.destroy! if repository.root.repositories.empty?
+            Rails.logger.debug "jomitsch debug - Destroyed all repos for #{repository.id}" if repository.root.repositories.empty?
+          end
         end

And I reproduced the issue by disabling many repositories, seeing this error:

Task b8f35be2-6084-4430-bb8d-8ce978bb1a22: Module::DelegationError: Katello::Repository#content_id delegated to root.content_id, but root is nil: #<Katello::Repository id: 197, pulp_id: "817e879b-0023-4fb6-9bec-b8d1ec28460f", library_instance_id: nil, content_view_version_id: 1, relative_path: "Default_Organization/Library/content/dist/rhel/ser...", environment_id: 1, saved_checksum_type: nil, distribution_version: nil, distribution_arch: nil, distribution_bootable: nil, distribution_family: nil, distribution_variant: nil, distribution_uuid: nil, container_repository_name: nil, root_id: 184, remote_href: nil, publication_href: nil, version_href: nil>

Notice the repo has an id of 197

Here is the debug output for one single action

One, single action:
2019-09-10T19:18:15 [D|app|] jomitsch debug - Planning action with repo 194 associated with root repo 182
2019-09-10T19:18:22 [D|app|] jomitsch debug - Destroying repo 194 associated with root repo 182
2019-09-10T19:18:24 [D|app|] jomitsch debug - Destroying root repo 182
2019-09-10T19:18:28 [D|app|] jomitsch debug - Destroyed all repos for 194
2019-09-10T19:18:28 [D|app|] jomitsch debug - Getting all repos for content view 1
2019-09-10T19:18:29 [D|app|] jomitsch debug - Got repos for content view repos: [1, 2, 3, 195, 196, 197, 198, 199, 200] cv_id: 1

Here is the debug for many concurrent actions:

jomitsch debug - Planning action with repo 196 associated with root repo 181
jomitsch debug - Planning action with repo 198 associated with root repo 185
jomitsch debug - Planning action with repo 199 associated with root repo 186
jomitsch debug - Planning action with repo 197 associated with root repo 184
jomitsch debug - Planning action with repo 200 associated with root repo 187
jomitsch debug - Destroying repo 198 associated with root repo 185
jomitsch debug - Destroying root repo 185
jomitsch debug - Destroyed all repos for 198
jomitsch debug - Destroying repo 197 associated with root repo 184
jomitsch debug - Destroying repo 196 associated with root repo 181
jomitsch debug - Getting all repos for content view 1
jomitsch debug - Destroying root repo 184
jomitsch debug - Got repos for content view repos: [1, 2, 3, 196, 197, 199, 200] cv_id: 1
jomitsch debug - Destroying repo 199 associated with root repo 186
jomitsch debug - Destroyed all repos for 197
jomitsch debug - Destroying root repo 181
jomitsch debug - Destroying repo 200 associated with root repo 187
jomitsch debug - Getting all repos for content view 1
jomitsch debug - Destroyed all repos for 196
jomitsch debug - Got repos for content view repos: [1, 2, 3, 196, 199, 200] cv_id: 1
jomitsch debug - Getting all repos for content view 1
jomitsch debug - Destroying root repo 186
jomitsch debug - Destroying root repo 187
jomitsch debug - Destroyed all repos for 199
jomitsch debug - Destroyed all repos for 200
jomitsch debug - Getting all repos for content view 1
jomitsch debug - Got repos for content view repos: [1, 2, 3, 196, 200] cv_id: 1
jomitsch debug - Getting all repos for content view 1
jomitsch debug - Got repos for content view repos: [1, 2, 3, 196, 199] cv_id: 1

Notice these lines:

     jomitsch debug - Planning action with repo 197 associated with root repo 184
     <snip>
     jomitsch debug - Destroying repo 197 associated with root repo 184 **<-- destroying the repo**
     jomitsch debug - Destroying repo 196 associated with root repo 181
     jomitsch debug - Getting all repos for content view 1
     jomitsch debug - Destroying root repo 184 **<-- destroying the root repo**
     jomitsch debug - Got repos for content view repos: [1, 2, 3, 196, 197, 199, 200] cv_id: 1 **<- querying the repos, repo 197 is not destroyed here so it shows up**
     **Root repository is destroyed but repo still exists, this is where the error happens**
     jomitsch debug - Destroying repo 199 associated with root repo 186
     jomitsch debug - Destroyed all repos for 197 **<-- confirmed repo 197 and its root repo is destroyed**

Note that these lines are debug statements located near the action so it can only indicate if the action has started or completed and its not a fully sequential output. We know the deletions have started but as we can see from querying the repos, they haven't been deleted yet and assumptions are made about the existence of a root repository.