Thread: Index not used

Index not used

From
meike.talbach@women-at-work.org
Date:
Hello,
 
I've a basic table with about 100K rows:
 


CREATE TABLE "public"."push_topic" (
 "id" Serial PRIMARY KEY,
 "guid" public.push_guid NOT NULL,
 "authenticatorsending" Varchar(32) NOT NULL,
 "authenticatorsubscription" Varchar(32) NOT NULL,
 "countpushed" Integer NOT NULL,
 "datecreated" timestamp NOT NULL,
 "datelastpush" timestamp
)
CREATE UNIQUE INDEX push_topic_idx_topicguid ON push_topic
  USING btree (guid)


 
When I query this through pgsql, the queries are fast as expected.

This is the query:

select * from push_topic where guid = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'

And the plan:



Index Scan using push_topic_idx_topicguid on push_topic  (cost=0.42..8.44 rows=1 width=103) (actual time=0.117..0.121
rows=1loops=1) 
  Index Cond: ((guid)::bpchar = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::bpchar)
  Buffers: shared hit=3 read=1
Total runtime: 0.191 ms



However when I run the exact query through a different application (CodeSynthesis ORM) the query is very slow (~ 115ms
logged)
I noted this is due to a sequential scan happening on the table instead of an index scan.

This is query plan in the log file:



LOG:  plan:
DETAIL:     {PLANNEDSTMT
       :commandType 1
       :queryId 0
       :hasReturning false
       :hasModifyingCTE false
       :canSetTag true
       :transientPlan false
       :planTree
          {SEQSCAN
          :startup_cost 0.00
          :total_cost 2877.58
          :plan_rows 429
          :plan_width 103
          :targetlist (
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 1
                :vartype 23
                :vartypmod -1
                :varcollid 0
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                :location 7
                }
             :resno 1
             :resname id
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 1
             :resjunk false
             }
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 2
                :vartype 16385
                :vartypmod -1
                :varcollid 100
                :varlevelsup 0
                :varnoold 1
                :varoattno 2
                :location 26
                }
             :resno 2
             :resname guid
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 2
             :resjunk false
             }
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 3
                :vartype 1043
                :vartypmod 36
                :varcollid 100
                :varlevelsup 0
                :varnoold 1
                :varoattno 3
                :location 47
                }
             :resno 3
             :resname authenticatorsending
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 3
             :resjunk false
             }
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 4
                :vartype 1043
                :vartypmod 36
                :varcollid 100
                :varlevelsup 0
                :varnoold 1
                :varoattno 4
                :location 84
                }
             :resno 4
             :resname authenticatorsubscription
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 4
             :resjunk false
             }
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 5
                :vartype 23
                :vartypmod -1
                :varcollid 0
                :varlevelsup 0
                :varnoold 1
                :varoattno 5
                :location 126
                }
             :resno 5
             :resname countpushed
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 5
             :resjunk false
             }
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 6
                :vartype 1114
                :vartypmod -1
                :varcollid 0
                :varlevelsup 0
                :varnoold 1
                :varoattno 6
                :location 154
                }
             :resno 6
             :resname datecreated
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 6
             :resjunk false
             }
             {TARGETENTRY
             :expr
                {VAR
                :varno 1
                :varattno 7
                :vartype 1114
                :vartypmod -1
                :varcollid 0
                :varlevelsup 0
                :varnoold 1
                :varoattno 7
                :location 182
                }
             :resno 7
             :resname datelastpush
             :ressortgroupref 0
             :resorigtbl 16393
             :resorigcol 7
             :resjunk false
             }
          )
          :qual (
             {OPEXPR
             :opno 98
             :opfuncid 67
             :opresulttype 16
             :opretset false
             :opcollid 0
             :inputcollid 100
             :args (
                {FUNCEXPR
                :funcid 401
                :funcresulttype 25
                :funcretset false
                :funcvariadic false
                :funcformat 2
                :funccollid 100
                :inputcollid 100
                :args (
                   {VAR
                   :varno 1
                   :varattno 2
                   :vartype 16385
                   :vartypmod -1
                   :varcollid 100
                   :varlevelsup 0
                   :varnoold 1
                   :varoattno 2
                   :location 234
                   }
                )
                :location -1
                }
                {CONST
                :consttype 25
                :consttypmod -1
                :constcollid 100
                :constlen -1
                :constbyval false
                :constisnull false
                :location -1
                :constvalue 40 [ -96 0 0 0 48 48 53 51 54 49 69 56 45 51 51 69 65
                45 49 70 48 69 45 66 50 49 55 45 67 57 49 66 52 65 67 55 66 67 69
                54 ]
                }
             )
             :location 254
             }
          )
          :lefttree <>
          :righttree <>
          :initPlan <>
          :extParam (b)
          :allParam (b)
          :scanrelid 1
          }
       :rtable (
          {RTE
          :alias <>
          :eref
             {ALIAS
             :aliasname push_topic
             :colnames ("id" "guid" "authenticatorsending" "authenticatorsubscript
             ion" "countpushed" "datecreated" "datelastpush")
             }
          :rtekind 0
          :relid 16393
          :relkind r
          :lateral false
          :inh false
          :inFromCl true
          :requiredPerms 2
          :checkAsUser 0
          :selectedCols (b 9 10 11 12 13 14 15)
          :modifiedCols (b)
          }
       )
       :resultRelations <>
       :utilityStmt <>
       :subplans <>
       :rewindPlanIDs (b)
       :rowMarks <>
       :relationOids (o 16393)
       :invalItems <>
       :nParamExec 0
       }

STATEMENT:  SELECT "push_topic"."id", "push_topic"."guid", "push_topic"."authenticatorsending",
"push_topic"."authenticatorsubscription","push_topic"."countpushed", "push_topic"."datecreated",
"push_topic"."datelastpush"FROM "push_topic" WHERE "push_topic"."guid" = $1 
LOG:  duration: 115.498 ms  execute query_mc_push_database_Topic: SELECT "push_topic"."id", "push_topic"."guid",
"push_topic"."authenticatorsending","push_topic"."authenticatorsubscription", "push_topic"."countpushed",
"push_topic"."datecreated","push_topic"."datelastpush" FROM "push_topic" WHERE "push_topic"."guid" = $1 




Any idea how to solve this ?

Thank you

Meike


Re: Index not used

From
John Gorman
Date:
When you run psql, are you running that on the application server or the database server? Does the application run on
thesame server as the database and how is the application connecting to the database (JDBC, ODBC, etc)?
 

In other words is there a difference in network time between the 2?

Also the queries are not exactly the same. With psql you use "select *" and the application specifies what columns it
wantsreturned and the order to return them. Try running the exact query on both.
 

Regards
John
 
-----Original Message-----
From: pgsql-performance-owner@postgresql.org [mailto:pgsql-performance-owner@postgresql.org] On Behalf Of
meike.talbach@women-at-work.org
Sent: Thursday, June 16, 2016 12:59 AM
To: pgsql-performance@postgresql.org
Subject: [PERFORM] Index not used

Hello,
 
I've a basic table with about 100K rows:
 


CREATE TABLE "public"."push_topic" (
 "id" Serial PRIMARY KEY,
 "guid" public.push_guid NOT NULL,
 "authenticatorsending" Varchar(32) NOT NULL,
 "authenticatorsubscription" Varchar(32) NOT NULL,
 "countpushed" Integer NOT NULL,
 "datecreated" timestamp NOT NULL,
 "datelastpush" timestamp
)
CREATE UNIQUE INDEX push_topic_idx_topicguid ON push_topic
  USING btree (guid)


 
When I query this through pgsql, the queries are fast as expected.

This is the query:

select * from push_topic where guid = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'

And the plan:



Index Scan using push_topic_idx_topicguid on push_topic  (cost=0.42..8.44 rows=1 width=103) (actual time=0.117..0.121
rows=1loops=1)
 
  Index Cond: ((guid)::bpchar = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::bpchar)
  Buffers: shared hit=3 read=1
Total runtime: 0.191 ms



However when I run the exact query through a different application (CodeSynthesis ORM) the query is very slow (~ 115ms
logged)
I noted this is due to a sequential scan happening on the table instead of an index scan.

This is query plan in the log file:



LOG:  plan:
DETAIL:     {PLANNEDSTMT 
       :commandType 1 
       :queryId 0 
       :hasReturning false 
       :hasModifyingCTE false 
       :canSetTag true 
       :transientPlan false 
       :planTree 
          {SEQSCAN 
          :startup_cost 0.00 
          :total_cost 2877.58 
          :plan_rows 429 
          :plan_width 103 
          :targetlist (
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 1 
                :vartype 23 
                :vartypmod -1 
                :varcollid 0 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 1 
                :location 7
                }
             :resno 1 
             :resname id 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 1 
             :resjunk false
             }
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 2 
                :vartype 16385 
                :vartypmod -1 
                :varcollid 100 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 2 
                :location 26
                }
             :resno 2 
             :resname guid 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 2 
             :resjunk false
             }
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 3 
                :vartype 1043 
                :vartypmod 36 
                :varcollid 100 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 3 
                :location 47
                }
             :resno 3 
             :resname authenticatorsending 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 3 
             :resjunk false
             }
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 4 
                :vartype 1043 
                :vartypmod 36 
                :varcollid 100 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 4 
                :location 84
                }
             :resno 4 
             :resname authenticatorsubscription 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 4 
             :resjunk false
             }
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 5 
                :vartype 23 
                :vartypmod -1 
                :varcollid 0 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 5 
                :location 126
                }
             :resno 5 
             :resname countpushed 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 5 
             :resjunk false
             }
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 6 
                :vartype 1114 
                :vartypmod -1 
                :varcollid 0 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 6 
                :location 154
                }
             :resno 6 
             :resname datecreated 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 6 
             :resjunk false
             }
             {TARGETENTRY 
             :expr 
                {VAR 
                :varno 1 
                :varattno 7 
                :vartype 1114 
                :vartypmod -1 
                :varcollid 0 
                :varlevelsup 0 
                :varnoold 1 
                :varoattno 7 
                :location 182
                }
             :resno 7 
             :resname datelastpush 
             :ressortgroupref 0 
             :resorigtbl 16393 
             :resorigcol 7 
             :resjunk false
             }
          )
          :qual (
             {OPEXPR 
             :opno 98 
             :opfuncid 67 
             :opresulttype 16 
             :opretset false 
             :opcollid 0 
             :inputcollid 100 
             :args (
                {FUNCEXPR 
                :funcid 401 
                :funcresulttype 25 
                :funcretset false 
                :funcvariadic false 
                :funcformat 2 
                :funccollid 100 
                :inputcollid 100 
                :args (
                   {VAR 
                   :varno 1 
                   :varattno 2 
                   :vartype 16385 
                   :vartypmod -1 
                   :varcollid 100 
                   :varlevelsup 0 
                   :varnoold 1 
                   :varoattno 2 
                   :location 234
                   }
                )
                :location -1
                }
                {CONST 
                :consttype 25 
                :consttypmod -1 
                :constcollid 100 
                :constlen -1 
                :constbyval false 
                :constisnull false 
                :location -1 
                :constvalue 40 [ -96 0 0 0 48 48 53 51 54 49 69 56 45 51 51 69 65 
                45 49 70 48 69 45 66 50 49 55 45 67 57 49 66 52 65 67 55 66 67 69 
                54 ]
                }
             )
             :location 254
             }
          )
          :lefttree <> 
          :righttree <> 
          :initPlan <> 
          :extParam (b)
          :allParam (b)
          :scanrelid 1
          }
       :rtable (
          {RTE 
          :alias <> 
          :eref 
             {ALIAS 
             :aliasname push_topic 
             :colnames ("id" "guid" "authenticatorsending" "authenticatorsubscript
             ion" "countpushed" "datecreated" "datelastpush")
             }
          :rtekind 0 
          :relid 16393 
          :relkind r 
          :lateral false 
          :inh false 
          :inFromCl true 
          :requiredPerms 2 
          :checkAsUser 0 
          :selectedCols (b 9 10 11 12 13 14 15)
          :modifiedCols (b)
          }
       )
       :resultRelations <> 
       :utilityStmt <> 
       :subplans <> 
       :rewindPlanIDs (b)
       :rowMarks <> 
       :relationOids (o 16393)
       :invalItems <> 
       :nParamExec 0
       }
    
STATEMENT:  SELECT "push_topic"."id", "push_topic"."guid", "push_topic"."authenticatorsending",
"push_topic"."authenticatorsubscription","push_topic"."countpushed", "push_topic"."datecreated",
"push_topic"."datelastpush"FROM "push_topic" WHERE "push_topic"."guid" = $1
 
LOG:  duration: 115.498 ms  execute query_mc_push_database_Topic: SELECT "push_topic"."id", "push_topic"."guid",
"push_topic"."authenticatorsending","push_topic"."authenticatorsubscription", "push_topic"."countpushed",
"push_topic"."datecreated","push_topic"."datelastpush" FROM "push_topic" WHERE "push_topic"."guid" = $1
 




Any idea how to solve this ?

Thank you

Meike


-- 
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance

Re: Index not used

From
Tom Lane
Date:
meike.talbach@women-at-work.org writes:
> When I query this through pgsql, the queries are fast as expected.
> select * from push_topic where guid = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'
> Index Scan using push_topic_idx_topicguid on push_topic  (cost=0.42..8.44 rows=1 width=103) (actual time=0.117..0.121
rows=1loops=1) 
>   Index Cond: ((guid)::bpchar = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::bpchar)
>   Buffers: shared hit=3 read=1
> Total runtime: 0.191 ms

> However when I run the exact query through a different application (CodeSynthesis ORM) the query is very slow (~
115mslogged) 
> I noted this is due to a sequential scan happening on the table instead of an index scan.

It looks like what that app is actually issuing is something different
from what you tested by hand, to wit

select * from push_topic where guid = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::text

which causes the comparison to be resolved as texteq not bpchareq, ie you
effectively have

select * from push_topic where guid::text = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::text

and that doesn't match a bpchar index.  If you can't persuade the app to
label the comparison value as bpchar not text, the easiest fix would be
to create an additional index on "guid::text".

            regards, tom lane


Re: Index not used

From
"David G. Johnston"
Date:
On Thu, Jun 16, 2016 at 11:05 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
meike.talbach@women-at-work.org writes:
> When I query this through pgsql, the queries are fast as expected.
> select * from push_topic where guid = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'
> Index Scan using push_topic_idx_topicguid on push_topic  (cost=0.42..8.44 rows=1 width=103) (actual time=0.117..0.121 rows=1 loops=1)
>   Index Cond: ((guid)::bpchar = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::bpchar)
>   Buffers: shared hit=3 read=1
> Total runtime: 0.191 ms

> However when I run the exact query through a different application (CodeSynthesis ORM) the query is very slow (~ 115ms logged)
> I noted this is due to a sequential scan happening on the table instead of an index scan.

It looks like what that app is actually issuing is something different
from what you tested by hand, to wit

select * from push_topic where guid = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::text

which causes the comparison to be resolved as texteq not bpchareq, ie you
effectively have

select * from push_topic where guid::text = 'DD748CCD-B8A4-3B9F-8F60-67F1F673CFE5'::text

and that doesn't match a bpchar index.  If you can't persuade the app to
label the comparison value as bpchar not text, the easiest fix would be
to create an additional index on "guid::text".

​Or, better, persuade the app to label the value "
public.push_guid
​" since that is the column's type​...a type you haven't defined for us.  If you get to add explicit casts this should be easy...but I'm not familiar with the framework you are using.

David J.

Re: Index not used

From
meike.talbach@women-at-work.org
Date:
<div style="font-family: Verdana;font-size: 12.0px;"><div class="gmail_default" style="font-family: arial , helvetica ,
sans-serif;display:inline;">> ​Or, better, persuade the app to label the value "</div><div class="gmail_default"
style="font-family:arial , helvetica , sans-serif;display: inline;">​</div><div>public.push_guid <div
class="gmail_default"style="font-family: arial , helvetica , sans-serif;display: inline;">​" since that is the column's
type​...atype you haven't defined for us.  If you get to add explicit casts this should be easy...but I'm not familiar
withthe framework you are using.</div><div class="gmail_default" style="font-family: arial , helvetica ,
sans-serif;display:inline;"> </div><div class="gmail_default" style="font-family: arial , helvetica ,
sans-serif;display:inline;"> </div><div class="gmail_default" style="font-family: arial , helvetica ,
sans-serif;display:inline;">push_guid was a CHARACTER(36) column. I ended up converting it to CHARACTER
VARYING(36).</div><divclass="gmail_default" style="font-family: arial , helvetica , sans-serif;display: inline;">Index
isnow being used and performance is as expected.</div><div class="gmail_default" style="font-family: arial , helvetica
,sans-serif;display: inline;"> </div><div class="gmail_default" style="font-family: arial , helvetica ,
sans-serif;display:inline;">Thanks a lot</div><div class="gmail_default" style="font-family: arial , helvetica ,
sans-serif;display:inline;">Meike</div></div></div>