Project

General

Profile

Actions

Bug #8190

closed

paddles: certain queries take > 500ms

Added by Zack Cerza about 10 years ago. Updated about 10 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
% Done:

0%

Source:
other
Tags:
Backport:
Regression:
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Crash signature (v1):
Crash signature (v2):

Description

I keep forgetting to file this bug. paddles needs to be more efficient in its queries.

I'm actually working on it right now; the changes range from things like being more selective about which columns to have SQLAlchemy query when performing simple checks like "does this job exist already" to having certain columns use deferred loading, to adding more column indexes.

Actions #1

Updated by Zack Cerza about 10 years ago

One example of a query that is nowhere near the worst example of the problem:

paddles=# explain analyze SELECT jobs.id AS jobs_id, jobs.job_id AS jobs_job_id FROM jobs WHERE 7116 = jobs.run_id AND jobs.job_id = '210221';
                                               QUERY PLAN                                               
--------------------------------------------------------------------------------------------------------
 Seq Scan on jobs  (cost=0.00..117937.71 rows=1 width=10) (actual time=215.588..217.084 rows=1 loops=1)
   Filter: ((7116 = run_id) AND ((job_id)::text = '210221'::text))
 Total runtime: 217.125 ms
(3 rows)

After optimizing:

paddles=# explain analyze SELECT jobs.id AS jobs_id, jobs.job_id AS jobs_job_id FROM jobs WHERE 7116 = jobs.run_id AND jobs.job_id = '210221';
                                                       QUERY PLAN                                                       
------------------------------------------------------------------------------------------------------------------------
 Index Scan using ix_jobs_run_id on jobs  (cost=0.00..244.50 rows=1 width=10) (actual time=0.021..0.108 rows=1 loops=1)
   Index Cond: (7116 = run_id)
   Filter: ((job_id)::text = '210221'::text)
 Total runtime: 0.131 ms
(4 rows)

So yeah, ~1700x faster.

Actions #2

Updated by Zack Cerza about 10 years ago

I think is the last one that badly needed to be optimized:

paddles=# explain analyze SELECT nodes.id AS nodes_id, nodes.name AS nodes_name FROM nodes, job_nodes WHERE 306610 = job_nodes.job_id AND nodes.id = job_nodes.node_id;           
                                                  QUERY PLAN                                                   
---------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..13675.23 rows=3 width=33) (actual time=64.384..64.384 rows=0 loops=1)
   ->  Seq Scan on job_nodes  (cost=0.00..13650.39 rows=3 width=4) (actual time=64.382..64.382 rows=0 loops=1) 
         Filter: (306610 = job_id) 
   ->  Index Scan using nodes_pkey on nodes  (cost=0.00..8.27 rows=1 width=33) (never executed)
         Index Cond: (id = job_nodes.node_id)
 Total runtime: 64.416 ms
(6 rows) 

After:

paddles=# explain analyze SELECT nodes.id AS nodes_id, nodes.name AS nodes_name FROM nodes, job_nodes WHERE 306610 = job_nodes.job_id AND nodes.id = job_nodes.node_id;
                                                              QUERY PLAN                                                              
--------------------------------------------------------------------------------------------------------------------------------------
 Nested Loop  (cost=0.00..38.82 rows=3 width=33) (actual time=0.040..0.053 rows=3 loops=1)
   ->  Index Scan using ix_job_nodes_job_id on job_nodes  (cost=0.00..13.98 rows=3 width=4) (actual time=0.029..0.031 rows=3 loops=1)
         Index Cond: (306610 = job_id)
   ->  Index Scan using nodes_pkey on nodes  (cost=0.00..8.27 rows=1 width=33) (actual time=0.004..0.005 rows=1 loops=3)
         Index Cond: (id = job_nodes.node_id)
 Total runtime: 0.097 ms
(6 rows)

Actions

Also available in: Atom PDF