Bugzilla will be upgraded to version 5.0. The upgrade date is tentatively scheduled for 2 December 2018, pending final testing and feedback.
Bug 1284573 - Intermittent "RangeError: 0xnnnnnnn is recycled object" errors when running automation scripts
Intermittent "RangeError: 0xnnnnnnn is recycled object" errors when running a...
Status: CLOSED ERRATA
Product: Red Hat CloudForms Management Engine
Classification: Red Hat
Component: Automate (Show other bugs)
5.4.0
x86_64 Linux
medium Severity medium
: GA
: 5.5.2
Assigned To: mkanoor
Jan Krocil
: ZStream
Depends On:
Blocks: 1286863 1286864
  Show dependency treegraph
 
Reported: 2015-11-23 10:42 EST by Peter McGowan
Modified: 2016-02-10 10:20 EST (History)
8 users (show)

See Also:
Fixed In Version: 5.5.2.1
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1286863 1286864 (view as bug list)
Environment:
Last Closed: 2016-02-10 10:20:14 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Script to reproduce the problem (1.37 KB, text/plain)
2015-11-23 10:42 EST, Peter McGowan
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2016:0159 normal SHIPPED_LIVE CFME 5.5.2 bug fixes and enhancement update 2016-02-10 15:19:02 EST

  None (edit)
Description Peter McGowan 2015-11-23 10:42:06 EST
Created attachment 1097724 [details]
Script to reproduce the problem

Description of problem:
We get occasional "RangeError: 0xnnnnnnn is recycled object" errors when running any of several automation scripts. The error seems to be related to stale association references, i.e. 

ems = $evm.vmdb('ems').find(:first)
hosts = ems.hosts

# at some stage later...

hosts.each do |host|

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

How reproducible:

The attached script can reproduce the problem for me around 1 in 5 times of running it.

Each of the loops exercises the automation engine more or less. With:

loops = [3,4]

I get the recycled object error fairly frequently. If you add in the other loops:

loops = [1,2,3,4]

the execution takes much longer, and other symptoms of failure occur, generally looking like memory corruption/re-use, i.e.

[----] I, [2015-11-19T14:39:29.055237 #2692:a81f204]  INFO -- : <AEMethod test_pemcg> First loop...
[----] I, [2015-11-19T14:41:57.197517 #2692:a81f204]  INFO -- : <AEMethod test_pemcg> Second loop...
[----] I, [2015-11-19T14:43:33.635100 #2692:a81f204]  INFO -- : <AEMethod test_pemcg> Third loop...
[----] I, [2015-11-19T14:43:33.635827 #2692:a81f204]  INFO -- : <AEMethod test_pemcg> Fourth loop...
[----] E, [2015-11-19T14:43:33.637500 #2692:a85d798] ERROR -- : <AEMethod test_pemcg> The following error occurred during method evaluation:
[----] E, [2015-11-19T14:43:33.637865 #2692:a85d798] ERROR -- : <AEMethod test_pemcg>   NoMethodError: undefined method `each' for "2015-11-10 15:59:32.79544":String
[----] E, [2015-11-19T14:43:33.638485 #2692:a85d798] ERROR -- : <AEMethod test_pemcg>   (druby://127.0.0.1:41919) /opt/rh/ruby200/root/usr/share/ruby/drb/invokemethod.rb:14:in `perform_with_block'


Steps to Reproduce:
1. Run the attached script through simulation
2.
3.

Actual results:


Expected results:


Additional info:
Comment 3 CFME Bot 2015-11-24 18:35:26 EST
New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/5e05ff17373f0cc9c2bfd5c81eb636dbfad9f250

commit 5e05ff17373f0cc9c2bfd5c81eb636dbfad9f250
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Tue Nov 24 16:04:19 2015 -0500
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Tue Nov 24 17:29:29 2015 -0500

    Array object was not being cached
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1284573
    
    The Array object that is sent back to the Automate Method via Drb
    is not being cached, leading to intermittent Recycled Object error
    The individual objects in the Array were cached but not the Array
    itself.

 lib/miq_automation_engine/engine/miq_ae_service_model_base.rb | 4 ++--
 spec/lib/miq_automation_engine/miq_ae_service_spec.rb         | 9 +++++++++
 2 files changed, 11 insertions(+), 2 deletions(-)
Comment 4 Peter McGowan 2015-11-26 03:27:00 EST
Could we have this back-ported to CFME 5.4 please?
Comment 5 mkanoor 2015-11-30 18:00:53 EST
5.4.z bugzilla is https://bugzilla.redhat.com/show_bug.cgi?id=1286864
Comment 9 CFME Bot 2015-12-02 15:22:20 EST
New commit detected on cfme/5.4.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=3a195ee826c4aa84555a9c809b5a8d81c662cc52

commit 3a195ee826c4aa84555a9c809b5a8d81c662cc52
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Mon Nov 30 11:01:52 2015 -0500
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Mon Nov 30 11:01:52 2015 -0500

    Array object was not being cached, Drb Recycled Object error
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1284573
    
    The Array object that is sent back to the Automate Method via Drb
    is not being cached, leading to intermittent Recycled Object error
    The individual objects in the Array were cached but not the Array
    itself.

 .../engine/miq_ae_service_model_base.rb                   |  2 +-
 .../spec/lib/miq_automation_engine/miq_ae_service_spec.rb | 15 +++++++++++++++
 2 files changed, 16 insertions(+), 1 deletion(-)
Comment 10 CFME Bot 2015-12-02 15:22:32 EST
New commit detected on cfme/5.4.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=c52a301636783c97acea0a3353471e1bb51866ac

commit c52a301636783c97acea0a3353471e1bb51866ac
Merge: 89a28ce 3a195ee
Author:     Greg McCullough <gmccullo@redhat.com>
AuthorDate: Mon Nov 30 17:42:47 2015 -0500
Commit:     Greg McCullough <gmccullo@redhat.com>
CommitDate: Mon Nov 30 17:42:47 2015 -0500

    Merge branch 'bugzilla_1284573_5_4_z' into '5.4.z'
    
    Array object was not being cached, Drb Recycled Object error
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1284573
    
    The Array object that is sent back to the Automate Method via Drb
    is not being cached, leading to intermittent Recycled Object error
    The individual objects in the Array were cached but not the Array
    itself.
    
    Original PR https://github.com/ManageIQ/manageiq/pull/5590
    
    Manual changes made to the 2 files.
    
    See merge request !554

 .../engine/miq_ae_service_model_base.rb                   |  2 +-
 .../spec/lib/miq_automation_engine/miq_ae_service_spec.rb | 15 +++++++++++++++
 2 files changed, 16 insertions(+), 1 deletion(-)
Comment 11 mkanoor 2015-12-03 16:49:59 EST
Waiting on MR
http://gitlab.cloudforms.lab.eng.rdu2.redhat.com/cloudforms/cfme/merge_requests/536
to get merged
Comment 12 CFME Bot 2015-12-07 13:51:10 EST
New commit detected on cfme/5.5.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=d1694299ff35428d9117d309d7d637b90ece5d68

commit d1694299ff35428d9117d309d7d637b90ece5d68
Author:     Madhu Kanoor <mkanoor@redhat.com>
AuthorDate: Tue Nov 24 16:04:19 2015 -0500
Commit:     Madhu Kanoor <mkanoor@redhat.com>
CommitDate: Wed Nov 25 09:24:57 2015 -0500

    Array object was not being cached
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1284573
    
    The Array object that is sent back to the Automate Method via Drb
    is not being cached, leading to intermittent Recycled Object error
    The individual objects in the Array were cached but not the Array
    itself.

 lib/miq_automation_engine/engine/miq_ae_service_model_base.rb | 4 ++--
 spec/lib/miq_automation_engine/miq_ae_service_spec.rb         | 9 +++++++++
 2 files changed, 11 insertions(+), 2 deletions(-)
Comment 13 CFME Bot 2015-12-07 13:51:52 EST
New commit detected on cfme/5.5.z:
https://code.engineering.redhat.com/gerrit/gitweb?p=cfme.git;a=commitdiff;h=c2fd5e17c30d16f416a35fc485a7cf5a444af63f

commit c2fd5e17c30d16f416a35fc485a7cf5a444af63f
Merge: 3a76459 d169429
Author:     Greg McCullough <gmccullo@redhat.com>
AuthorDate: Mon Dec 7 13:44:49 2015 -0500
Commit:     Greg McCullough <gmccullo@redhat.com>
CommitDate: Mon Dec 7 13:44:49 2015 -0500

    Merge branch 'bugzilla_1284573_5_5_z' into '5.5.z'
    
    Array object was not being cached
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1284573
    
    The Array object that is sent back to the Automate Method via Drb
    is not being cached, leading to intermittent Recycled Object error
    The individual objects in the Array were cached but not the Array
    itself.
    
    Clean Cherry Pick from Original PR https://github.com/ManageIQ/manageiq/pull/5590
    
    See merge request !536

 lib/miq_automation_engine/engine/miq_ae_service_model_base.rb | 4 ++--
 spec/lib/miq_automation_engine/miq_ae_service_spec.rb         | 9 +++++++++
 2 files changed, 11 insertions(+), 2 deletions(-)
Comment 15 Jan Krocil 2016-01-19 05:59:01 EST
Verified fixed in 5.2.2.1 - 5.5.2.1.20160114044944_395c086.

Tested multiple times with 'loops' set to both [3,4] and [1,2,3,4] and I wasn't able to reproduce the issue anymore.
Comment 16 errata-xmlrpc 2016-02-10 10:20:14 EST
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:0159

Note You need to log in before you can comment on or make changes to this bug.