Bug 1566198

Summary:	DRb 'close' error for closed connection
Product:	Red Hat CloudForms Management Engine	Reporter:	Tina Fitzgerald <tfitzger>
Component:	Appliance	Assignee:	Adam Grare <agrare>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Dmitry Misharov <dmisharo>
Severity:	high	Docs Contact:
Priority:	high
Version:	5.8.0	CC:	abellott, cpelland, dmisharo, obarenbo, simaishi
Target Milestone:	GA	Keywords:	TestOnly, ZStream
Target Release:	5.10.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	5.10.0.0	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:
Clones:	1566255 1566256 (view as bug list)		Environment:
Last Closed:	2019-02-11 14:01:01 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	1566255, 1566256

Description Tina Fitzgerald 2018-04-11 18:22:48 UTC

Description of problem:

The following error was discovered while investigating:
https://bugzilla.redhat.com/show_bug.cgi?id=1562401


----] I, [2018-04-03T08:05:57.972011 #105122:8ad130]  INFO -- : Q-task_id([miq_provision_20000000004950]) MIQ(MiqQueue#deliver) Message id: [20000247754617], Delivering...
[----] I, [2018-04-03T08:05:58.013981 #105122:8ad130]  INFO -- : Q-task_id([miq_provision_20000000004950]) MIQ(ManageIQ::Providers::Vmware::InfraManager#with_provider_connection) Connecting through ManageIQ::Providers::Vmware::InfraManager: [SAT NDC vCenter]
[----] I, [2018-04-03T08:05:58.077885 #105122:8ad130]  INFO -- : Q-task_id([miq_provision_20000000004950]) MIQ(MiqFaultTolerantVim._connect) EMS: [SAT NDC vCenter] [Broker] Connecting with address: [tnwg01a-v1945.ad.cbp.dhs.gov], userid: [svc-edmed-cloudforms]...
[----] I, [2018-04-03T08:05:58.102451 #9566:8ad130]  INFO -- : <AutomationEngine> Updated namespace [miqaedb:/System/Event/EmsEvent/EVM/CloneVM_Task_Complete#create  ManageIQ/System/Event/EmsEvent]
[----] E, [2018-04-03T08:05:58.110848 #105122:8ad130] ERROR -- : Q-task_id([miq_provision_20000000004950]) MIQ(MiqQueue#deliver) Message id: [20000247754617], Error: [undefined method `close' for nil:NilClass
Did you mean?  clone]
[----] E, [2018-04-03T08:05:58.111815 #105122:8ad130] ERROR -- : Q-task_id([miq_provision_20000000004950]) [NoMethodError]: undefined method `close' for nil:NilClass
Did you mean?  clone  Method:[rescue in deliver]
[----] E, [2018-04-03T08:05:58.112689 #105122:8ad130] ERROR -- : Q-task_id([miq_provision_20000000004950]) /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1258:in `close'
/opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1237:in `block in open'
/opt/rh/rh-ruby23/root/usr/share/ruby/sync.rb:234:in `block in sync_synchronize'
/opt/rh/rh-ruby23/root/usr/share/ruby/sync.rb:231:in `handle_interrupt'
/opt/rh/rh-ruby23/root/usr/share/ruby/sync.rb:231:in `sync_synchronize'
/opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1235:in `open'
/opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1141:in `block in method_missing'
/opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1160:in `with_friend'
/opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1140:in `method_missing'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/VMwareWebService/MiqVimBroker.rb:419:in `getMiqVim'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/util/miq_fault_tolerant_vim.rb:187:in `_connect_with_broker'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/util/miq_fault_tolerant_vim.rb:173:in `block in _connect'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/util/miq_fault_tolerant_vim.rb:85:in `_execute_with_broker'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/util/miq_fault_tolerant_vim.rb:74:in `_execute'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/util/miq_fault_tolerant_vim.rb:171:in `_connect'
/opt/rh/cfme-gemset/bundler/gems/manageiq-gems-pending-a29aab0471c6/lib/gems/pending/util/miq_fault_tolerant_vim.rb:28:in `initialize'
/var/www/miq/vmdb/app/models/mixins/vim_connect_mixin.rb:23:in `new'
/var/www/miq/vmdb/app/models/mixins/vim_connect_mixin.rb:23:in `connect'
/var/www/miq/vmdb/app/models/mixins/vim_connect_mixin.rb:36:in `with_provider_connection'
/var/www/miq/vmdb/app/models/mixins/provider_object_mixin.rb:5:in `with_provider_connection'
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-vmware-d69f678e3cb3/app/models/manageiq/providers/vmware/infra_manager/provision/cloning.rb:3:in `do_clone_task_check'
/opt/rh/cfme-gemset/bundler/gems/manageiq-providers-vmware-d69f678e3cb3/app/models/manageiq/providers/vmware/infra_manager/provision/state_machine.rb:28:in `poll_clone_complete'
/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'

Comment 2 Tina Fitzgerald 2018-04-11 18:24:07 UTC

Adam created a PR to resolve this issue:
https://github.com/ManageIQ/manageiq/pull/17267

Comment 3 Tina Fitzgerald 2018-04-11 18:24:45 UTC

New commit detected on ManageIQ/manageiq/master:

https://github.com/ManageIQ/manageiq/commit/76309b91e41725be72c5abadb19c0731b07733f7
commit 76309b91e41725be72c5abadb19c0731b07733f7
Author:     Adam Grare <agrare>
AuthorDate: Mon Apr  9 14:37:53 2018 -0400
Commit:     Adam Grare <agrare>
CommitDate: Mon Apr  9 14:37:53 2018 -0400

    Set DRb conn pool to [] after closing connections

    After forking and closing open DRb pooled connections set the pool to []
    to prevent other calls calling `conn.close` on already closed
    connection.  This prevents the following:

    ```
    [NoMethodError]: undefined method `close' for nil:NilClass
    Did you mean?  clone
    /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1258:in `close'
    /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1237:in `block in open'
    /opt/rh/rh-ruby23/root/usr/share/ruby/sync.rb:234:in `block in sync_synchronize'
    /opt/rh/rh-ruby23/root/usr/share/ruby/sync.rb:231:in `handle_interrupt'
    /opt/rh/rh-ruby23/root/usr/share/ruby/sync.rb:231:in `sync_synchronize'
    /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1235:in `open'
    /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1141:in `block in method_missing'
    /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1160:in `with_friend'
    /opt/rh/rh-ruby23/root/usr/share/ruby/drb/drb.rb:1140:in `method_missing'
    lib/gems/pending/VMwareWebService/MiqVimBroker.rb:419:in `getMiqVim'
    ```

    https://bugzilla.redhat.com/show_bug.cgi?id=1562401

 app/models/miq_worker.rb | 1 +
 1 file changed, 1 insertion(+)

Comment 7 Dmitry Misharov 2018-06-26 14:00:00 UTC

Verified in 5.10.0.1.20180619163011_900fdc4.