Bug 1396642

Summary:	It takes more than 12 minutes to load an edit Organization page for an Org with large number of hosts
Product:	Red Hat Satellite	Reporter:	sthirugn <sthirugn>
Component:	Organizations and Locations	Assignee:	Tomer Brisker <tbrisker>
Status:	CLOSED ERRATA	QA Contact:	sthirugn <sthirugn>
Severity:	high	Docs Contact:
Priority:	high
Version:	6.2.4	CC:	bbuckingham, bkearney, chrobert, ehelms, mhulan, mmccune, ohadlevy, oshtaier, sthirugn
Target Milestone:	Unspecified	Keywords:	Performance, Regression, Triaged
Target Release:	Unused
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	foreman-1.11.0.62-1	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:
Clones:	1405517 (view as bug list)		Environment:
Last Closed:	2017-01-26 10:45:45 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:
Bug Depends On:
Bug Blocks:	1405517

Description sthirugn@redhat.com 2016-11-18 19:33:34 UTC

Description of problem:
It takes a long time to load an edit Organization page for an Org with 9k hosts

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

How reproducible:
Always

Steps to Reproduce:
1. Make sure to have a large number of hosts in an Organization.  This test was performed at a customer site who had more than 9k hosts.
2. Navigate to Administer -> Organizations -> Click 'Edit' on the Organization which had large number of hosts.

Actual results:
It takes forever to load the Edit Org page.

In a 32 GB inhouse VM - it took more than 12 minutes.
In a 64 GB customer VM - it took almost the same time but don't know the exact time.

Note: Our recommended RAM for Satellite6 is 16 GB.


Expected results:
9000 records is not so huge in today's world.  This loading time is unacceptable and needs query optimization


Additional info:
Severity - High. since this is reported by a customer and this impacts them.

Comment 4 Ohad Levy 2016-11-28 07:54:41 UTC

can we turn on debug mode? its hard to follow which part of the UI took the most amount of time?

Comment 5 Mike McCune 2016-11-29 16:04:15 UTC

It becomes obvious fairly quickly when you run it with debug mode on:

http://paste.fedoraproject.org/493203/80435386/

2016-11-29 10:57:12 [app] [I] Started GET "/organizations/5-example/edit" for 10.3.116.87 at 2016-11-29 10:57:12 -0500
2016-11-29 10:57:12 [app] [I] Processing by OrganizationsController#edit as HTML
....
2016-11-29 10:57:12 [sql] [D]   Location Load (0.3ms)  SELECT "taxonomies".* FROM "taxonomies" INNER JOIN "locations_organizations" ON "taxonomies"."id" = "locations_organizations"."location_id" WHERE "taxonomies"."type" IN ('Location') AND "locations_organizations"."organization_id" = $1  ORDER BY "taxonomies"."title" ASC  [["organization_id", 5]]
2016-11-29 10:57:12 [sql] [D]   Host::Managed Load (45.3ms)  SELECT "hosts".* FROM "hosts"  WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."organization_id" = $1  [["organization_id", 5]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.4ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 6172]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.3ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4293]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4295]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.3ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 110]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.3ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4308]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.3ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4309]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4313]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4314]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 1019]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4320]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4325]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4330]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4333]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4339]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4345]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4349]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4350]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4351]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4352]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4356]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4359]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.2ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4362]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4367]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4369]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4371]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4372]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4373]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4374]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4376]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4380]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4381]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4382]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4391]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4405]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4410]]
2016-11-29 10:57:13 [sql] [D]   Nic::Base Load (0.1ms)  SELECT "nics".* FROM "nics"  WHERE "nics"."host_id" = $1  ORDER BY "nics"."identifier" ASC  [["host_id", 4412]]
....

Comment 6 Marek Hulan 2016-11-30 10:07:06 UTC

Hello, this was fixed in upstream in 1.12. I've linked the upstream issue with the patch.

Comment 8 Bryan Kearney 2016-11-30 11:00:32 UTC

Upstream bug assigned to tbrisker

Comment 9 Bryan Kearney 2016-11-30 11:00:37 UTC

Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/14924 has been resolved.

Comment 13 sthirugn@redhat.com 2017-01-09 20:05:00 UTC

Verified in Satellite 6.2.7 Snap 1.0

I tested this wiath an org which contained 5840 hosts. Time taken to load the Edit Organization page is as follows:

Before fix: 7 minutes 30 seconds
After fix: 13 seconds

Satellite 6.3 may give even better performance as per Comment 11.

Comment 15 errata-xmlrpc 2017-01-26 10:45:45 UTC

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-2017:0197