Bug 1496486

Summary: error while syncing openstack tenants : failed to save the new source_tenant
Product: Red Hat CloudForms Management Engine Reporter: Felix Dewaleyne <fdewaley>
Component: ProvidersAssignee: Gregg Tanzillo <gtanzill>
Status: CLOSED CURRENTRELEASE QA Contact: Ido Ovadia <iovadia>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 5.8.0CC: cpelland, fdewaley, gblomqui, gtanzill, igortiunov, iovadia, jfrey, jhardy, obarenbo, sacpatil, simaishi
Target Milestone: GAKeywords: TestOnly, ZStream
Target Release: 5.9.0   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 5.9.0.4 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1510564 (view as bug list) Environment:
Last Closed: 2018-03-06 14:52:56 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: Openstack Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1510564    

Description Felix Dewaleyne 2017-09-27 14:45:40 UTC 
Description of problem:
while syncing against openstack, the tenant syncing part fails with "Error: Failed to save the new associated source_tenant"

Version-Release number of selected component (if applicable):
5.8.1.5

How reproducible:
all the time in customer environment

Steps to Reproduce:
1.uncertain. issues were noticed too late
2.
3.

Actual results:
2617915:[----] I, [2017-09-26T12:27:00.640771 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) Syncing CloudTenant with Tenants...
2617916:[----] I, [2017-09-26T12:27:00.645289 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) CloudTenant admin has no tenant
2617917:[----] I, [2017-09-26T12:27:00.645366 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) Creating Tenant with parameters: {:name=>"admin", :description=>"admin tenant"}
2617918:[----] I, [2017-09-26T12:27:00.647564 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) and with parent OpenStack Cloud Provider Cloud_MEF
2617919:[----] E, [2017-09-26T12:27:00.651443 #19080:e47140] ERROR -- : MIQ(MiqQueue#deliver) Message id: [20000023215788], Error: [Failed to save the new associated source_tenant.]
2617920:[----] E, [2017-09-26T12:27:00.651612 #19080:e47140] ERROR -- : [ActiveRecord::RecordNotSaved]: Failed to save the new associated source_tenant.  Method:[rescue in deliver]
2617921:[----] E, [2017-09-26T12:27:00.651711 #19080:e47140] ERROR -- : /opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/has_one_association.rb:51:in `block in replace'


Expected results:
the operation continues with no error

Additional info:
a copy of the database is available for internal use
an attempt to remove the infrastructure provider was made
there is also an ongoing memory threshold issue with the mispriorityworker and the metrics collector
Comment 4 Gregg Tanzillo 2017-09-29 19:29:32 UTC 
This is the full set of log messages output while attempting to sync cloud tenants -
(from evm_current_c1v-ops-cfcp00.mgmt.tesoro.it_20170926_191911.tar/log/evm.log)

[----] I, [2017-09-26T11:15:23.502280 #19080:e47140]  INFO -- : MIQ(MiqGenericWorker::Runner#get_message_via_drb) Message id: [20000023211121], MiqWorker id: [20000002263752], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [20000000000015], Task id: [], Command: [ManageIQ::Providers::Openstack::CloudManager.sync_cloud_tenants_with_tenants], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [3.22873398] seconds
[----] I, [2017-09-26T11:15:23.502405 #19080:e47140]  INFO -- : MIQ(MiqQueue#deliver) Message id: [20000023211121], Delivering...
[----] I, [2017-09-26T11:15:23.519872 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) Syncing CloudTenant with Tenants...
[fog][WARNING] Unrecognized arguments: provider
[----] I, [2017-09-26T11:15:23.587621 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) CloudTenant admin has no tenant
[----] I, [2017-09-26T11:15:23.587715 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) Creating Tenant with parameters: {:name=>"admin", :description=>"admin tenant"}
[----] I, [2017-09-26T11:15:23.590493 #19080:e47140]  INFO -- : MIQ(ManageIQ::Providers::Openstack::CloudManager#sync_tenants) and with parent OpenStack Cloud Provider Cloud_MEF
[----] E, [2017-09-26T11:15:23.596349 #19080:e47140] ERROR -- : MIQ(MiqQueue#deliver) Message id: [20000023211121], Error: [Failed to save the new associated source_tenant.]
[----] E, [2017-09-26T11:15:23.596590 #19080:e47140] ERROR -- : [ActiveRecord::RecordNotSaved]: Failed to save the new associated source_tenant.  Method:[rescue in deliver]
[----] E, [2017-09-26T11:15:23.596672 #19080:e47140] ERROR -- : /opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/has_one_association.rb:51:in `block in replace'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/has_one_association.rb:106:in `block in transaction_if'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `block in transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/connection_adapters/abstract/transaction.rb:189:in `within_new_transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/connection_adapters/abstract/database_statements.rb:232:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/transactions.rb:211:in `transaction'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/has_one_association.rb:106:in `transaction_if'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/has_one_association.rb:41:in `replace'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/singular_association.rb:22:in `writer'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/associations/builder/association.rb:119:in `source_tenant='
/var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager.rb:96:in `block in sync_tenants'
/opt/rh/cfme-gemset/gems/acts_as_tree-2.1.0/lib/acts_as_tree.rb:205:in `walk_tree'
/opt/rh/cfme-gemset/gems/acts_as_tree-2.1.0/lib/acts_as_tree.rb:202:in `block in walk_tree'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/relation/delegation.rb:40:in `each'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/relation/delegation.rb:40:in `each'
/opt/rh/cfme-gemset/gems/acts_as_tree-2.1.0/lib/acts_as_tree.rb:201:in `walk_tree'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/relation/delegation.rb:91:in `public_send'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/relation/delegation.rb:91:in `block in method_missing'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/relation.rb:351:in `scoping'
/opt/rh/cfme-gemset/gems/activerecord-5.0.3/lib/active_record/relation/delegation.rb:91:in `method_missing'
/var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager.rb:75:in `sync_tenants'
/var/www/miq/vmdb/app/models/manageiq/providers/cloud_manager.rb:66:in `sync_cloud_tenants_with_tenants'
/var/www/miq/vmdb/app/models/miq_queue.rb:347:in `block in deliver'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:91:in `block in timeout'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `block in catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:33:in `catch'
/opt/rh/rh-ruby23/root/usr/share/ruby/timeout.rb:106:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:343:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:107:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:135:in `deliver_message'
ar/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:153:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:147:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:147:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:340:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:337:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:337:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:160:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:134:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:21:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:339:in `block in start_runner'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.3/lib/nakayoshi_fork.rb:24:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:337:in `start_runner'
/var/www/miq/vmdb/app/models/miq_worker.rb:348:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:266:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:150:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:53:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:22:in `monitor_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:349:in `block in monitor'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-8f7d63f441d5/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-8f7d63f441d5/lib/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:349:in `monitor'
/var/www/miq/vmdb/app/models/miq_server.rb:371:in `block (2 levels) in monitor_loop'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-8f7d63f441d5/lib/gems/pending/util/extensions/miq-benchmark.rb:11:in `realtime_store'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-8f7d63f441d5/lib/gems/pending/util/extensions/miq-benchmark.rb:30:in `realtime_block'
/var/www/miq/vmdb/app/models/miq_server.rb:371:in `block in monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:370:in `loop'
/var/www/miq/vmdb/app/models/miq_server.rb:370:in `monitor_loop'
/var/www/miq/vmdb/app/models/miq_server.rb:253:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:65:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:91:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] I, [2017-09-26T11:15:23.596810 #19080:e47140]  INFO -- : MIQ(MiqQueue#delivered) Message id: [20000023211121], State: [error], Delivered in [0.094429865] seconds
Comment 5 Gregg Tanzillo 2017-10-06 19:29:47 UTC 
https://github.com/ManageIQ/manageiq/pull/16144
Comment 6 CFME Bot 2017-10-20 15:36:54 UTC 
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/c0b820cd8ecde347f19bb7b27075d20dba7db2b3

commit c0b820cd8ecde347f19bb7b27075d20dba7db2b3
Author:     Gregg Tanzillo <gtanzill>
AuthorDate: Fri Oct 6 14:45:31 2017 -0400
Commit:     Gregg Tanzillo <gtanzill>
CommitDate: Fri Oct 6 14:45:31 2017 -0400

    Check for existing source tenant of cloud tenant before attempting to create a new one
    
    - Handles an edge case where there is an existing tenant with the same name and ancestry
    - That was causing ActiveRecord::RecordNotSaved error because validation of Tenant#name uniqueness failed
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1496486

 app/models/manageiq/providers/cloud_manager.rb       |  3 ++-
 spec/models/manageiq/providers/cloud_manager_spec.rb | 17 +++++++++++++++++
 2 files changed, 19 insertions(+), 1 deletion(-)
Comment 7 CFME Bot 2017-10-20 15:36:59 UTC 
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/97abf82806377315911691604255d1d6b647959a

commit 97abf82806377315911691604255d1d6b647959a
Author:     Gregg Tanzillo <gtanzill>
AuthorDate: Fri Oct 6 14:51:53 2017 -0400
Commit:     Gregg Tanzillo <gtanzill>
CommitDate: Fri Oct 6 14:51:53 2017 -0400

    Allow existing, orphaned source tenant to be updated during synchronization
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1496486

 app/models/manageiq/providers/cloud_manager.rb       | 14 +++++++++++---
 spec/models/manageiq/providers/cloud_manager_spec.rb |  3 +++
 2 files changed, 14 insertions(+), 3 deletions(-)
Comment 8 CFME Bot 2017-10-20 15:37:04 UTC 
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/f4c8c3fe6076ca621d9f8a0d83c3979f1815bc7c

commit f4c8c3fe6076ca621d9f8a0d83c3979f1815bc7c
Author:     Gregg Tanzillo <gtanzill>
AuthorDate: Fri Oct 6 15:14:48 2017 -0400
Commit:     Gregg Tanzillo <gtanzill>
CommitDate: Fri Oct 6 15:14:48 2017 -0400

    DRY'd up code around finding, creating and updating cloud tenant source tenant.
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1496486

 app/models/cloud_tenant.rb                     |  6 ++++++
 app/models/manageiq/providers/cloud_manager.rb | 27 ++++++++++----------------
 2 files changed, 16 insertions(+), 17 deletions(-)
Comment 13 Ido Ovadia 2017-12-12 12:27:16 UTC 
Verified
========
5.9.0.12