Bug 1372073 - loading task takes 10+ seconds, makes 16K sql queries
Summary: loading task takes 10+ seconds, makes 16K sql queries
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Content Views
Version: 6.2.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: Unspecified
Assignee: Ivan Necas
QA Contact: Renzo Nuccitelli
URL:
Whiteboard:
: 1260141 1291507 (view as bug list)
Depends On:
Blocks: 1353215 1386429 1386449
TreeView+ depends on / blocked
 
Reported: 2016-08-31 20:22 UTC by Chris Duryee
Modified: 2019-12-16 06:35 UTC (History)
16 users (show)

Fixed In Version: rubygem-katello-3.0.0.80-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-10-04 06:44:59 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
clean_update_repos.rb (3.10 KB, text/plain)
2016-09-09 13:53 UTC, Ivan Necas
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Foreman Issue Tracker 15201 0 Normal Closed using `foreman_tasks/api/tasks/show` takes 100-150msec per call 2020-09-02 15:20:59 UTC
Foreman Issue Tracker 16499 0 Normal Closed At certain cirucumsatnces, the CV publish produeces 100 000s steps with repos update 2020-09-02 15:20:59 UTC
Red Hat Knowledge Base (Solution) 2755731 0 None None None 2016-11-07 17:30:53 UTC
Red Hat Product Errata RHBA-2016:1993 0 normal SHIPPED_LIVE Satellite 6.2.2 Async Bug Release 2016-10-04 10:43:20 UTC

Description Chris Duryee 2016-08-31 20:22:18 UTC
Description of problem:

Some users have reported that the CV version page is excessively slow. Querying certain attributes of a task can generate a large number of SQL queries. The queries themselves are very fast, but buildup and teardown can take some time given the # of queries.

Version-Release number of selected component (if applicable): 6.2.1, dynflow 0.8.11


How reproducible: every time, given correct initial data set


Steps to Reproduce:
1. in terminal #1, foreman-rake console
2. in terminal #2, strace -tt -s999 -e trace=network -f -p <console pid> 2>&1 | grep 'SELECT \* FROM'
3. in terminal #1, run: ForemanTasks::Task.find('<id>').progress

Actual results: 10+ seconds to load progress, and many queries 

Expected results: < 1 sec to load the task, ideally less than 100msec


Additional info:

example query output:

[pid 12404] 13:13:41.079970 sendto(14, "Q\0\0\0\202SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 1)) LIMIT 1\0", 131, MSG_NOSIGNAL, NULL, 0) = 131
[pid 12404] 13:13:41.081277 sendto(14, "Q\0\0\0\202SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 2)) LIMIT 1\0", 131, MSG_NOSIGNAL, NULL, 0) = 131
[pid 12404] 13:13:41.082095 sendto(14, "Q\0\0\0\202SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 3)) LIMIT 1\0", 131, MSG_NOSIGNAL, NULL, 0) = 131
[pid 12404] 13:13:41.082863 sendto(14, "Q\0\0\0\202SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 4)) LIMIT 1\0", 131, MSG_NOSIGNAL, NULL, 0) = 131

*snip*

[pid 12404] 13:13:54.914686 sendto(14, "Q\0\0\0\206SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 16410)) LIMIT 1\0", 135, MSG_NOSIGNAL, NULL, 0) = 135
[pid 12404] 13:13:54.915411 sendto(14, "Q\0\0\0\206SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 16411)) LIMIT 1\0", 135, MSG_NOSIGNAL, NULL, 0) = 135
[pid 12404] 13:13:54.916185 sendto(14, "Q\0\0\0\206SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 16412)) LIMIT 1\0", 135, MSG_NOSIGNAL, NULL, 0) = 135
[pid 12404] 13:13:54.916917 sendto(14, "Q\0\0\0\206SELECT * FROM \"dynflow_steps\" WHERE ((\"execution_plan_uuid\" = '4c601f6d-0e4c-4725-8131-cd5fd2686558') AND (\"id\" = 16413)) LIMIT 1\0", 135, MSG_NOSIGNAL, NULL, 0) = 135

Comment 7 Waldirio M Pinheiro 2016-09-02 14:50:31 UTC
Created attachment 1197232 [details]
enable repo list

Comment 9 Ivan Necas 2016-09-09 13:48:30 UTC
After more digging, it also turned out the content view publish process was generating many unnecessary steps, which lead to more more that 100x bigger execution plans, which lead to more time for the task to run, as well as to show details. More detail, as well as proposed fix at http://projects.theforeman.org/issues/16499

Comment 10 Ivan Necas 2016-09-09 13:50:09 UTC
The fix for Dynflow loading proposed at https://github.com/Dynflow/dynflow/pull/200

The fix for the Katello issue proposed at https://github.com/Katello/katello/pull/6305

Comment 11 Ivan Necas 2016-09-09 13:53:59 UTC
Created attachment 1199470 [details]
clean_update_repos.rb

The script removes unnecessary steps from tasks, caused by http://projects.theforeman.org/issues/16499, to reduce its size

Comment 15 Chris Roberts 2016-09-12 18:39:53 UTC
*** Bug 1291507 has been marked as a duplicate of this bug. ***

Comment 16 Bryan Kearney 2016-09-14 12:18:35 UTC
Upstream bug component is Content Management

Comment 17 Bryan Kearney 2016-09-14 20:19:33 UTC
Upstream bug component is Content Views

Comment 18 Mike McCune 2016-09-15 19:22:39 UTC
RHEL7 Hotfix RPMs available for Satellite 6.2.1 only:

http://people.redhat.com/~mmccune/1372073/1372073-hotfix.tar

Installation instructions:

1) download tar above to your Satellite 6.2.1 RHEL7 server

2) extract and 'rpm -Uvh <rpms in archive>'

3) katello-service restart

4) Download cleanup script from this bug to your Satellite

curl https://bugzilla.redhat.com/attachment.cgi?id=1199470 > cleanup_repos.rb

5) foreman-rake console < ~/clean_update_repos.rb

6) proceed with normal operations

Comment 19 Bryan Kearney 2016-09-21 00:18:30 UTC
Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/16499 has been resolved.

Comment 21 Renzo Nuccitelli 2016-09-29 15:42:18 UTC
Verified on 6.2.2

Comment 23 errata-xmlrpc 2016-10-04 06:44:59 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-2016:1993

Comment 24 Zach Huntington-Meath 2016-10-28 14:28:51 UTC
*** Bug 1260141 has been marked as a duplicate of this bug. ***


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