Bug 1341402

Summary: 5.6.0.8 Initial Refresh on Vmware 10k Provider Timing regression
Product: Red Hat CloudForms Management Engine Reporter: Alex Krzos <akrzos>
Component: PerformanceAssignee: Adam Grare <agrare>
Status: CLOSED DUPLICATE QA Contact: Dave Johnson <dajohnso>
Severity: medium Docs Contact:
Priority: high    
Version: 5.6.0CC: jhardy, obarenbo, simaishi
Target Milestone: GAKeywords: ZStream
Target Release: cfme-future   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: vsphere:performance
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1382163 (view as bug list) Environment:
Last Closed: 2016-11-29 18:32:34 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: VMware Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1382163    

Description Alex Krzos 2016-06-01 02:01:30 UTC
Description of problem:
Compared to 5.5.3.4 (99th Percentile timing for an initial refresh was 737s, refresh on same provider now takes 1600s) (Not including the time for the VIMBroker to load data)

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

How reproducible:


Steps to Reproduce:
1. Add xlarge provider
2. Perform a Refresh and measure timing/memory usage
3.

Actual results:
~1600s for the EmsRefresh.refresh message to complete

Expected results:


Additional info:


[----] I, [2016-05-31T21:43:49.642994 #3764:633990]  INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::Refresher#refresh) EMS: [vmware-xlarge], id: [1] Refreshing targets for EMS...Complete - Timings {:server_dequeue=>0.004362583160400391, :get_ems_data=>2.9800798892974854, :get_vc_data=>84.45335388183594, :get_vc_data_ems_customization_specs=>4.1711437702178955, :filter_vc_data=>0.00046706199645996094, :get_vc_data_host_scsi=>513.5504930019379, :collect_inventory_for_targets=>605.1574783325195, :parse_vc_data=>44.3983256816864, :parse_targeted_inventory=>44.398534297943115, :db_save_inventory=>931.6641547679901, :save_inventory=>931.6641728878021, :ems_refresh=>1581.2208054065704}

Comment 3 Adam Grare 2016-10-06 16:53:32 UTC
The a large chunk of the increased time appears to be introduced by code that reduces the memory utilization of the broker, https://github.com/ManageIQ/manageiq/commit/4bbad2141b4ec820b56885584abd67ba94cf5569

(note get_vc_data_total is equivalent to collect_inventory_for_targets)

5.5.5.4:
:get_vc_data_total=>48.140045166015625
:total_time=>336.6637680530548

5.6.2.1:
:collect_inventory_for_targets=>737.8142273426056
:ems_refresh=>1119.3035068511963

5.6.2.1 with 4bbad21 reverted
:collect_inventory_for_targets=>44.61478614807129
:ems_refresh=>517.089364528656

Save inventory performance appears to have regressed as well, more investigation is needed into this

Comment 6 Adam Grare 2016-11-29 18:32:34 UTC

*** This bug has been marked as a duplicate of bug 1378998 ***