You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@manifoldcf.apache.org by "Karl Wright (JIRA)" <ji...@apache.org> on 2014/06/27 15:28:25 UTC

[jira] [Updated] (CONNECTORS-678) Postgresql generating unusual and slow (76 second) plans for stuffer queries

     [ https://issues.apache.org/jira/browse/CONNECTORS-678?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Karl Wright updated CONNECTORS-678:
-----------------------------------

    Fix Version/s:     (was: ManifoldCF 1.7)
                   ManifoldCF 2.0

> Postgresql generating unusual and slow (76 second) plans for stuffer queries
> ----------------------------------------------------------------------------
>
>                 Key: CONNECTORS-678
>                 URL: https://issues.apache.org/jira/browse/CONNECTORS-678
>             Project: ManifoldCF
>          Issue Type: Bug
>          Components: Framework core
>    Affects Versions: ManifoldCF 1.1.1
>            Reporter: Karl Wright
>            Assignee: Karl Wright
>             Fix For: ManifoldCF 2.0
>
>
> Query plans like this seem to be taking place:
> {code}
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan: Limit  (cost=9597.49..9597.49 rows=1 width=155)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:   ->  Sort  (cost=9597.49..9597.49 rows=1 width=155)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:         Sort Key: t0.docpriority
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:         ->  Nested Loop Anti Join  (cost=17.68..9597.48 rows=1 width=155)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:               Join Filter: (t2.jobid <> t0.jobid)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:               ->  Nested Loop Semi Join  (cost=17.68..9588.87 rows=1 width=155)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                     Join Filter: (t0.jobid = t1.id)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                     ->  Nested Loop Anti Join  (cost=17.68..9586.81 rows=1 width=155)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                           Join Filter: (t0.id = t3.owner)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                           ->  Bitmap Heap Scan on jobqueue t0  (cost=4.53..6.54 rows=1 width=155)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                 Recheck Cond: (status = ANY ('{P,G}'::bpchar[]))
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                 Filter: ((checktime <= 1366628406182::bigint) AND (checkaction = 'R'::bpchar))
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                 ->  Bitmap Index Scan on i1362584563122  (cost=0.00..4.53 rows=1 width=0)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                       Index Cond: (status = ANY ('{P,G}'::bpchar[]))
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                           ->  Hash Join  (cost=13.15..7635.56 rows=231554 width=8)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                 Hash Cond: ((t3.eventname)::text = (t4.name)::text)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                 ->  Seq Scan on prereqevents t3  (cost=0.00..4438.54 rows=231554 width=37)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                 ->  Hash  (cost=11.40..11.40 rows=140 width=516)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                                       ->  Seq Scan on events t4  (cost=0.00..11.40 rows=140 width=516)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                     ->  Seq Scan on jobs t1  (cost=0.00..2.03 rows=2 width=8)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                           Filter: ((status = ANY ('{A,a}'::bpchar[])) AND (priority = 5::bigint))
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:               ->  Index Scan using i1362584563120 on jobqueue t2  (cost=0.00..4.30 rows=1 width=49)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                     Index Cond: ((dochash)::text = (t0.dochash)::text)
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) -  Plan:                     Filter: (status = ANY ('{A,F,a,f,D,d}'::bpchar[]))
>  WARN 2013-04-22 13:01:20,414 (Stuffer thread) - 
> {code}
> Here's the query:
> {code}
> EXPLAIN SELECT t0.id,t0.jobid,t0.dochash,t0.docid,t0.status,t0.failtime,t0.failcount,t0.priorityset FROM jobqueue t0  WHERE t0.status IN ('P','G') AND t0.checkaction='R' AND t0.checktime<=1366628406182 AND
>     EXISTS(SELECT 'x' FROM jobs t1 WHERE t1.status IN ('A','a') AND t1.id=t0.jobid AND t1.priority=5) AND
>     NOT EXISTS(SELECT 'x' FROM jobqueue t2 WHERE t2.dochash=t0.dochash AND t2.status IN ('A','F','a','f','D','d') AND t2.jobid!=t0.jobid) AND
>     NOT EXISTS(SELECT 'x' FROM prereqevents t3,events t4 WHERE t0.id=t3.owner AND t3.eventname=t4.name) ORDER BY t0.docpriority ASC LIMIT 100;
> {code}
> This query was noted in the log as taking 76 seconds to execute.



--
This message was sent by Atlassian JIRA
(v6.2#6252)