Project

General

Profile

Actions

Bug #15306

closed

Orchestration does not roll back queued actions if DB error occurs

Added by Shimon Shtein over 8 years ago. Updated about 6 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Orchestration
Target version:
Difficulty:
Triaged:
Fixed in Releases:
Found in Releases:

Description

Cloned from https://bugzilla.redhat.com/show_bug.cgi?id=1343058
Description of problem:

If an SQL error occurs upon saving a host, the orchestration actions will still occur.

How reproducible:

Create a host with a missing foreign key (for example environment_id = 999), observe an exception thrown and orchestration leftovers.

Steps to Reproduce:

# hammer host create --name my-cli-host-1 --partition-table-id 61 --domain-id 1 --operatingsystem-id 3 --architecture-id 1 --compute-resource-id 1 --environment-id 999 --puppet-proxy-id 1 --location-id 1 --organization-id 1 --root-password changeme --medium-id 9
[Foreman] Password for admin: 
Could not create the host:
  ERROR:  insert or update on table "hosts" violates foreign key constraint "hosts_environment_id_fk" 
  DETAIL:  Key (environment_id)=(999) is not present in table "environments".
[root@sat6 dhcp]# 
[root@sat6 dhcp]# 
[root@sat6 dhcp]# hammer host create --name my-cli-host-1 --partition-table-id 61 --domain-id 1 --operatingsystem-id 3 --architecture-id 1 --compute-resource-id 1 --environment-id 999 --puppet-proxy-id 1 --location-id 1 --organization-id 1 --root-password changeme --medium-id 9
[Foreman] Password for admin: 
Could not create the host:
  Failed to create a compute my_libvirt_cr_1 (Libvirt) instance my-cli-host-1.domain.com: Error saving the server: Call to virDomainDefineXML failed: operation failed: domain 'my-cli-host-1.domain.com' already exists with uuid 3d1ac10d-fb73-fb16-a3a3-503d7625e042

Expected results:

The second request succeeds.


Related issues 5 (0 open5 closed)

Related to Foreman - Bug #15644: import_facts assumes orchestration is availableClosedDaniel Lobato Garcia07/11/2016Actions
Related to Discovery - Bug #15645: Change in core leads to undefined method `enable_orchestration!'Duplicate07/11/2016Actions
Related to Foreman - Bug #17041: Orchestration not skipped when importing factsClosedTimo Goebel10/20/2016Actions
Related to Foreman - Bug #16866: Facts import doesn't work with unattended=falseClosedDominic Cleal10/11/2016Actions
Related to Foreman - Bug #12425: Fact import triggers ip conflicts checks, which drives cpu utilization to 100% on smart-proxyClosedTimo GoebelActions
Actions #1

Updated by Dominic Cleal over 8 years ago

  • Description updated (diff)
  • Category set to Orchestration
  • Status changed from New to Assigned

Please include server logs when filing tickets and fill in the category.

Actions #2

Updated by Dominic Cleal over 8 years ago

  • Status changed from Assigned to Need more information

This looks like a possible duplicate of #14004 assuming the FK failure happens during commit, but there's not enough information in this ticket without corresponding error logs.

Actions #3

Updated by Shimon Shtein over 8 years ago

Not exactly a dup: #14004 talks about actions in post_commit queue.

This one talks about the ones in the before_save queue.

The production log is not very informative, it records the FK failure during save and then it records a failure from libvirt provider that fails to create a VM with the same name:

2016-06-05 18:44:08 [app] [I] Started POST "/api/hosts" for ::1 at 2016-06-05 18:44:08 +0000
2016-06-05 18:44:08 [app] [I] Processing by Api::V2::HostsController#create as JSON
2016-06-05 18:44:08 [app] [I]   Parameters: {"host"=>{"name"=>"my-cli-host-1", "location_id"=>2, "organization_id"=>1, "environment_id"=>999, "architecture_id"=>1, "domain_i
d"=>2, "puppet_proxy_id"=>1, "operatingsystem_id"=>3, "medium_id"=>1, "ptable_id"=>61, "compute_resource_id"=>1, "build"=>true, "enabled"=>true, "managed"=>true, "compute_at
tributes"=>{"volumes_attributes"=>{}}, "content_facet_attributes"=>{}, "subscription_facet_attributes"=>{}, "overwrite"=>true, "host_parameters_attributes"=>{}, "interfaces_
attributes"=>{}, "root_pass"=>"[FILTERED]"}, "apiv"=>"v2"}
2016-06-05 18:44:08 [app] [I] Authorized user admin(Admin User)
2016-06-05 18:44:08 [app] [W] Action failed
 | PG::Error: ERROR:  insert or update on table "hosts" violates foreign key constraint "hosts_environment_id_fk" 
 | DETAIL:  Key (environment_id)=(999) is not present in table "environments".
 | 
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql_adapter.rb:834:in `get_last_result'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql_adapter.rb:834:in `block in exec_cache'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract_adapter.rb:373:in `block in log'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract_adapter.rb:367:in `log'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql_adapter.rb:831:in `exec_cache'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:138:in `exec_query'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:177:in `exec_insert'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:95:in `insert'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/query_cache.rb:14:in `insert'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation.rb:64:in `insert'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/persistence.rb:502:in `_create_record'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods/dirty.rb:87:in `_create_record'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/callbacks.rb:306:in `block in _create_record'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:113:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:113:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:215:in `block in halting_and_conditional'
...
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/callbacks.rb:302:in `create_or_update'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/persistence.rb:103:in `save'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/validations.rb:51:in `save'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods/dirty.rb:21:in `save'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:268:in `block (2 levels) in save'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:329:in `block in with_transaction_returning_status'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:201:in `block in transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:209:in `within_new_transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/connection_adapters/abstract/database_statements.rb:201:in `transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:208:in `transaction'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:326:in `with_transaction_returning_status'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:268:in `block in save'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:283:in `rollback_active_record_state!'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/transactions.rb:267:in `save'
...
2016-06-05 18:45:48 [app] [I] Processing by Api::V2::HostsController#create as JSON
2016-06-05 18:45:48 [app] [I]   Parameters: {"host"=>{"name"=>"my-cli-host-1", "location_id"=>2, "organization_id"=>1, "environment_id"=>1, "architecture_id"=>1, "domain_id"=>2, "puppet_proxy_id"=>1, "operatingsystem_id"=>3, "medium_id"=>1, "ptable_id"=>61, "compute_resource_id"=>1, "build"=>true, "enabled"=>true, "managed"=>true, "compute_attributes"=>{"volumes_attributes"=>{}}, "content_facet_attributes"=>{}, "subscription_facet_attributes"=>{}, "overwrite"=>true, "host_parameters_attributes"=>{}, "interfaces_attributes"=>{}, "root_pass"=>"[FILTERED]"}, "apiv"=>"v2"}
2016-06-05 18:45:48 [app] [I] Authorized user admin(Admin User)
2016-06-05 18:45:48 [app] [W] Unhandled Libvirt error
 | Fog::Errors::Error: Error saving the server: Call to virDomainDefineXML failed: operation failed: domain 'my-cli-host-1.inner' already exists with uuid dc6adce1-00ff-4abb-a96f-65a0ce0e3ec1
 | /opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.0.2/lib/fog/libvirt/models/compute/server.rb:68:in `rescue in save'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.0.2/lib/fog/libvirt/models/compute/server.rb:61:in `save'
 | /usr/share/foreman/app/models/compute_resources/foreman/model/libvirt.rb:143:in `create_vm'
 | /usr/share/foreman/app/models/concerns/orchestration/compute.rb:82:in `setCompute'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:162:in `execute'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:107:in `block in process'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:99:in `each'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:99:in `process'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `on_save'

Actions #4

Updated by Shimon Shtein over 8 years ago

  • Status changed from Need more information to Assigned
Actions #5

Updated by Dominic Cleal over 8 years ago

Not exactly a dup: #14004 talks about actions in post_commit queue.
This one talks about the ones in the before_save queue.

It's not before_save triggering the FK exception, it's the save itself. The same thing is happening - the save or post_commit is failing, but the items in before_save are not rolled back.

Actions #6

Updated by Shimon Shtein over 8 years ago

#14004 is by far more complicated. We can simplify our orchestration to three stages:
1. before_save orchestration queue
2. ActiveRecord's save action
3. after_commit orchestration queue

Right now the system handles a rollback only in stage 1. My bug is about exceptions in stage 2, here the ActiveRecord is rolled back by the DB, but we need to take care of all actions inside stage 2. #14004 is talking about a failure in stage 3, this is far more complicated, since we need to compensate both stage 1 and 2. In this case we don't even know what was the previous state of the record to run some kind of compensation update to it.

Probably the solution to this issue would be easier and could be used as a part of the more general problem.

Actions #7

Updated by The Foreman Bot over 8 years ago

  • Status changed from Assigned to Ready For Testing
  • Pull request https://github.com/theforeman/foreman/pull/3574 added
Actions #8

Updated by Shimon Shtein over 8 years ago

  • Status changed from Ready For Testing to Closed
  • % Done changed from 0 to 100
Actions #9

Updated by Dominic Cleal over 8 years ago

  • Translation missing: en.field_release set to 161
Actions #10

Updated by Daniel Lobato Garcia about 8 years ago

  • Related to Bug #15644: import_facts assumes orchestration is available added
Actions #11

Updated by Lukas Zapletal about 8 years ago

  • Related to Bug #15645: Change in core leads to undefined method `enable_orchestration!' added
Actions #12

Updated by Dominic Cleal about 8 years ago

  • Translation missing: en.field_release changed from 161 to 160

Too many API changes between this and #15644, bumping to major release.

Actions #13

Updated by Timo Goebel almost 8 years ago

  • Related to Bug #17041: Orchestration not skipped when importing facts added
Actions #14

Updated by Dominic Cleal almost 8 years ago

  • Related to Bug #16866: Facts import doesn't work with unattended=false added
Actions #15

Updated by Lukas Zapletal over 4 years ago

  • Related to Bug #12425: Fact import triggers ip conflicts checks, which drives cpu utilization to 100% on smart-proxy added
Actions

Also available in: Atom PDF