Bug 1271160

Summary: API Listing products slow, 36 products takes 50+ seconds
Product: Red Hat Satellite Reporter: Peter Vreman <peter.vreman>
Component: PerformanceAssignee: Adam Price <adprice>
Status: CLOSED DUPLICATE QA Contact:
Severity: medium Docs Contact:
Priority: unspecified    
Version: 6.1.2CC: bbuckingham, bkearney, cduryee, peter.vreman, sthirugn
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-05-26 18:28:58 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: 1122832    
Attachments:
Description Flags
products index response none

Description Peter Vreman 2015-10-13 09:43:55 UTC
Description of problem:
Using the API to list products is slow. Rendering the view of 36 products takes 50 seconds:

[crash] root@li-lc-1578:~# time curl -K /opt/hoici/etc/sat6/curl-hoici.conf "-HContent-Type: application/json" "-d{\"per_page\":9999}" -XGET https://localhost/katello/api/v2/organizations/3/products > p.json

real    0m52.593s
user    0m0.191s
sys     0m0.054s

[crash] root@li-lc-1578:~# ls -l p.json
-rw-r--r--. 1 root root 19371 Oct 13 09:33 p.json

[crash] root@li-lc-1578:~# hoi-json --get p.json results.id | wc -l
36

[crash] root@li-lc-1578:~# hoi-json --get p.json ALL | wc -l
816


2015-10-13 09:32:23 [I] Processing by Katello::Api::V2::ProductsController#index as */*
2015-10-13 09:32:23 [I]   Parameters: {"per_page"=>9999, "api_version"=>"v2", "organization_id"=>"3", "product"=>{}}
2015-10-13 09:32:23 [I] Expire fragment views/tabs_and_title_records-4 (0.9ms)
2015-10-13 09:32:23 [I] Authorized user hoici(hoici )
2015-10-13 09:33:15 [I]   Rendered /opt/rh/ruby193/root/usr/share/gems/gems/katello-2.2.0.67/app/views/katello/api/v2/products/index.json.rabl within katell
o/api/v2/layouts/collection (51673.8ms)
2015-10-13 09:33:15 [I] Completed 200 OK in 52143ms (Views: 50202.0ms | ActiveRecord: 1525.1ms)


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


How reproducible:


Steps to Reproduce:
1. Enabled 20 RedHat products
2. Add 10 Custom products
3. List the products with the API

Actual results:
Slow response

Expected results:
Response <5 seconds to list the 30 products

Additional info:

Comment 1 Peter Vreman 2015-10-13 09:46:42 UTC
Sync plans are not used, as mentioned in the a related BZ1253802

Comment 2 Peter Vreman 2015-10-13 09:47:02 UTC
Created attachment 1082314 [details]
products index response

Comment 4 Chris Duryee 2016-03-10 23:17:49 UTC
I get about 100ms per product when making a similar call, on both Satellite 6.1 (katello 2.2) and Katello 3.0. For example, 134 products takes 10 seconds, and on a different machine, 126 products takes 13 seconds.

Can you confirm that this is still happening, and also that the system load is not high?

Comment 5 Chris Duryee 2016-03-10 23:40:46 UTC
clearing needsinfo, I was able to repro this after enabling repos on products.

Comment 6 Chris Duryee 2016-03-17 20:37:13 UTC
I was not able to reproduce this issue this on 6.2, I believe my other test was flawed since it was on a development VM.

How I tested:

* in one org, create 10 products with 10 repos each (100 repo total). Sync all repos a few times, to create a basis of prior syncs that will be reported in the product call.
* in same org, import manifest and enable 43 repos across various products. Sync all 143 repos.

After this, I get about 12-16 seconds per call to list all 122 products. When enabling pagination, the time goes down significantly.

I believe the 12-16 second number is the time it takes to render the JSON output, given that the activerecord time is low.

Comment 7 Peter Vreman 2016-03-18 07:37:15 UTC
The 12-16 for 143 repos on 10 products does not meet the <5 seconds without pagination.

For automation processes to do things frequently having 16sec is still not good enough.
E.g. in a Continuous Intergration process to having 10x 15sec delays is 150 seconds = 2,5 minutes just to list data.

Like mentioned the 'complex' activerecord is quick, but the rendering is slow. Then this rendering process needs to be looked how it can be improved. needing 10seconds to output JSON from data already in memory is not good.

Comment 8 Chris Duryee 2016-05-26 18:28:58 UTC

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