Bug 1486384

Summary: Add db index on logs result
Product: Red Hat Satellite Reporter: Justin Sherrill <jsherril>
Component: SCAP PluginAssignee: Ivan Necas <inecas>
Status: CLOSED ERRATA QA Contact: Ales Dujicek <adujicek>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.2.12CC: adujicek, bbuckingham, inecas, jsherril, kabbott, mhulan, oprazak, sjagtap
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: foreman_openscap-0.7.5 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-02-21 16:54:37 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:

Description Justin Sherrill 2017-08-29 15:45:24 UTC
User was seeing slow requests due to this query:

SELECT COUNT("logs"."id") FROM "logs" INNER JOIN reports ON reports.id = report_id WHERE "logs"."result" IN ('error', 'unknown', 'notapplicable', 'notchecked', 'notselected', 'informational', 'fixed');


Explain plan:

foreman=# EXPLAIN ANALYSE SELECT COUNT("logs"."id") FROM "logs" INNER JOIN reports ON reports.id = report_id WHERE "logs"."result" IN ('error', 'unknown', 'notapplicable', 'notchecked', 'notselected', 'informational', 'fixed');
                                                            QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=221925.53..221925.54 rows=1 width=4) (actual time=608.178..608.178 rows=1 loops=1)
   ->  Nested Loop  (cost=0.00..221925.53 rows=1 width=4) (actual time=608.176..608.176 rows=0 loops=1)
         ->  Seq Scan on logs  (cost=0.00..221916.83 rows=1 width=8) (actual time=608.174..608.174 rows=0 loops=1)
               Filter: ((result)::text = ANY ('{error,unknown,notapplicable,notchecked,notselected,informational,fixed}'::text[]))
               Rows Removed by Filter: 6805345
         ->  Index Only Scan using reports_pkey on reports  (cost=0.00..8.69 rows=1 width=4) (never executed)
               Index Cond: (id = logs.report_id)
               Heap Fetches: 0
 Total runtime: 608.219 ms
(9 rows)

foreman=# \d logs
                                     Table "public.logs"
   Column   |            Type             |                     Modifiers
------------+-----------------------------+---------------------------------------------------
 id         | integer                     | not null default nextval('logs_id_seq'::regclass)
 source_id  | integer                     |
 message_id | integer                     |
 report_id  | integer                     |
 level_id   | integer                     |
 created_at | timestamp without time zone |
 updated_at | timestamp without time zone |
 result     | character varying(255)      |
Indexes:
    "logs_pkey" PRIMARY KEY, btree (id)
    "index_logs_on_level_id" btree (level_id)
    "index_logs_on_message_id" btree (message_id)
    "index_logs_on_report_id" btree (report_id)
    "index_logs_on_source_id" btree (source_id)


Adding an index sped this up quite a bit.

foreman=# create index index_logs_on_result on logs using btree(result);
CREATE INDEX
foreman=# EXPLAIN ANALYSE SELECT COUNT("logs"."id") FROM "logs" INNER JOIN reports ON reports.id = report_id WHERE "logs"."result" IN ('error', 'unknown', 'notapplicable', 'notchecked', 'notselected', 'informational', 'fixed');
                                                               QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=43.26..43.27 rows=1 width=4) (actual time=0.044..0.044 rows=1 loops=1)
   ->  Nested Loop  (cost=0.01..43.26 rows=1 width=4) (actual time=0.041..0.041 rows=0 loops=1)
         ->  Index Scan using index_logs_on_result on logs  (cost=0.01..34.57 rows=1 width=8) (actual time=0.040..0.040 rows=0 loops=1)
               Index Cond: ((result)::text = ANY ('{error,unknown,notapplicable,notchecked,notselected,informational,fixed}'::text[]))
         ->  Index Only Scan using reports_pkey on reports  (cost=0.00..8.69 rows=1 width=4) (never executed)
               Index Cond: (id = logs.report_id)
               Heap Fetches: 0
 Total runtime: 0.106 ms
(8 rows)


More info:

This customer has about 6,000 puppet clients checking every ~30 minutes.

Comment 2 Ivan Necas 2017-08-30 20:34:46 UTC
Created redmine issue http://projects.theforeman.org/issues/20811 from this bug

Comment 3 Satellite Program 2017-08-30 22:03:10 UTC
Upstream bug assigned to inecas

Comment 4 Satellite Program 2017-08-30 22:03:14 UTC
Upstream bug assigned to inecas

Comment 5 Satellite Program 2017-08-31 06:03:03 UTC
Moving this bug to POST for triage into Satellite 6 since the upstream issue http://projects.theforeman.org/issues/20811 has been resolved.

Comment 8 Tomer Brisker 2017-12-11 14:32:44 UTC
Connecting redmine issue http://projects.theforeman.org/issues/20811 from this bug

Comment 9 Tomer Brisker 2017-12-11 14:34:40 UTC
*** Bug 1518705 has been marked as a duplicate of this bug. ***

Comment 11 Satellite Program 2018-02-21 16:54:37 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/RHSA-2018:0336