Thread: Weird index scan
I'm getting weird results for one of my queries. The actual time of this
index scan doesn't make any sense:
-> Index Scan using dok_dok_fk_i on dokumendid a (cost=0.00..566.24
rows=184 width=8) (actual time=0.170..420806.563 rows=1 loops=1)
dok_dok_fk_i is index on dokumendid(dok_dok_id). Currently it contains
mostly NULLs:
pos1=# select dok_dok_id, count(1) from dokumendid group by dok_dok_id;
dok_dok_id | count
------------+-------
| 11423
8034 | 76
(2 rows)
If I drop the index, seq scan + sort is used instead and everything is
fast again.
The PostgreSQL version:
pos1=# select version();
version
------------------------------------------------------------------------
------------------------------
PostgreSQL 7.4.5 on i386-pc-linux-gnu, compiled by GCC i386-linux-gcc
(GCC) 3.3.4 (Debian 1:3.3.4-9)
(1 row)
The full EXPLAIN ANALYZE output:
pos1=# explain analyze select * from v_inventuuri_vahed_kaubagrupiti;
QUERY PLAN
------------------------------------------------------------------------
------------------------------------------------------------------------
-------------------------------------------------
Subquery Scan v_inventuuri_vahed_kaubagrupiti (cost=50896.04..50896.61
rows=46 width=128) (actual time=437007.670..437007.817 rows=45 loops=1)
-> Sort (cost=50896.04..50896.15 rows=46 width=42) (actual
time=437007.664..437007.692 rows=45 loops=1)
Sort Key: (COALESCE(sum(ir.summa_kmta), 0::numeric))::raha
-> HashAggregate (cost=50893.85..50894.77 rows=46 width=42)
(actual time=437007.229..437007.488 rows=45 loops=1)
-> Hash Join (cost=5533.44..50807.93 rows=5728
width=42) (actual time=436226.533..436877.499 rows=16271 loops=1)
Hash Cond: ("outer".kau_kau_id = "inner".kau_id)
-> Merge Right Join (cost=4759.52..49858.92
rows=15696 width=26) (actual time=436117.333..436600.653 rows=16271
loops=1)
Merge Cond: (("outer".dok_dok_id =
"inner".dok_id) AND ("outer".kau_kau_id = "inner".kau_kau_id))
-> Index Scan using dor_dok_kau_i on
dokumentide_read ar (cost=0.00..42789.44 rows=480962 width=19) (actual
time=0.023..7873.117 rows=205879 loops=1)
-> Sort (cost=4759.52..4798.76 rows=15696
width=19) (actual time=428381.719..428392.204 rows=16271 loops=1)
Sort Key: a.dok_id, ir.kau_kau_id
-> Merge Left Join
(cost=0.00..3665.65 rows=15696 width=19) (actual time=0.245..428279.595
rows=16258 loops=1)
Merge Cond: ("outer".dok_id =
"inner".dok_dok_id)
-> Nested Loop
(cost=0.00..3620.23 rows=15696 width=19) (actual time=0.063..7243.529
rows=16258 loops=1)
-> Index Scan using dok_pk
on dokumendid i (cost=0.00..3.73 rows=1 width=4) (actual
time=0.030..0.035 rows=1 loops=1)
Index Cond: (dok_id =
8034)
Filter: (tyyp =
'IN'::bpchar)
-> Index Scan using
dor_dok_fk_i on dokumentide_read ir (cost=0.00..3459.55 rows=15696
width=19) (actual time=0.023..7150.257 rows=16258 loops=1)
Index Cond: (8034 =
dok_dok_id)
-> Index Scan using dok_dok_fk_i
on dokumendid a (cost=0.00..566.24 rows=184 width=8) (actual
time=0.170..420806.563 rows=1 loops=1)
Filter: (tyyp =
'IA'::bpchar)
-> Hash (cost=757.71..757.71 rows=6487 width=24)
(actual time=109.178..109.178 rows=0 loops=1)
-> Hash Join (cost=15.56..757.71 rows=6487
width=24) (actual time=1.787..85.554 rows=17752 loops=1)
Hash Cond: ("outer".kag_kag_id =
"inner".a_kag_id)
-> Seq Scan on kaubad k
(cost=0.00..588.52 rows=17752 width=8) (actual time=0.005..30.952
rows=17752 loops=1)
-> Hash (cost=15.35..15.35 rows=83
width=24) (actual time=1.770..1.770 rows=0 loops=1)
-> Hash Join (cost=5.39..15.35
rows=83 width=24) (actual time=0.276..1.491 rows=227 loops=1)
Hash Cond:
("outer".y_kag_id = "inner".kag_id)
-> Seq Scan on
kaubagruppide_kaubagrupid gg (cost=0.00..7.09 rows=409 width=8) (actual
time=0.004..0.405 rows=409 loops=1)
-> Hash (cost=5.27..5.27
rows=46 width=20) (actual time=0.259..0.259 rows=0 loops=1)
-> Seq Scan on
kaubagrupid g (cost=0.00..5.27 rows=46 width=20) (actual
time=0.010..0.206 rows=46 loops=1)
Filter:
(kag_kag_id IS NULL)
Total runtime: 437011.532 ms
(33 rows)
Tambet
Hi,
1) seems that the table is a view, I am wrong? If this is true, please
give a query to that table, and try to guess if there is already a bottleneck there.
2) Add to the query an order by and try to find if it works better.
3) If you drop the index, and no other index exists, it will always use a seqscan or other method to gather the rows.
Noother index is plausible to be used there? (perhaps order by indexedcolumn may help).
A hint, drop that index, identify a usable index, and set enable_seqscan to off; on your session (or as a global value
onthe conf file)
Best wishes,
Guido
>
> I'm getting weird results for one of my queries. The actual time of this
> index scan doesn't make any sense:
>
> -> Index Scan using dok_dok_fk_i on dokumendid a (cost=0.00..566.24
> rows=184 width=8) (actual time=0.170..420806.563 rows=1 loops=1)
>
> dok_dok_fk_i is index on dokumendid(dok_dok_id). Currently it contains
> mostly NULLs:
>
> pos1=# select dok_dok_id, count(1) from dokumendid group by dok_dok_id;
> dok_dok_id | count
> ------------+-------
> | 11423
> 8034 | 76
> (2 rows)
>
> If I drop the index, seq scan + sort is used instead and everything is
> fast again.
>
> The PostgreSQL version:
>
> pos1=# select version();
> version
> ------------------------------------------------------------------------
> ------------------------------
> PostgreSQL 7.4.5 on i386-pc-linux-gnu, compiled by GCC i386-linux-gcc
> (GCC) 3.3.4 (Debian 1:3.3.4-9)
> (1 row)
>
> The full EXPLAIN ANALYZE output:
>
> pos1=# explain analyze select * from v_inventuuri_vahed_kaubagrupiti;
>
> QUERY PLAN
> ------------------------------------------------------------------------
> ------------------------------------------------------------------------
> -------------------------------------------------
> Subquery Scan v_inventuuri_vahed_kaubagrupiti (cost=50896.04..50896.61
> rows=46 width=128) (actual time=437007.670..437007.817 rows=45 loops=1)
> -> Sort (cost=50896.04..50896.15 rows=46 width=42) (actual
> time=437007.664..437007.692 rows=45 loops=1)
> Sort Key: (COALESCE(sum(ir.summa_kmta), 0::numeric))::raha
> -> HashAggregate (cost=50893.85..50894.77 rows=46 width=42)
> (actual time=437007.229..437007.488 rows=45 loops=1)
> -> Hash Join (cost=5533.44..50807.93 rows=5728
> width=42) (actual time=436226.533..436877.499 rows=16271 loops=1)
> Hash Cond: ("outer".kau_kau_id = "inner".kau_id)
> -> Merge Right Join (cost=4759.52..49858.92
> rows=15696 width=26) (actual time=436117.333..436600.653 rows=16271
> loops=1)
> Merge Cond: (("outer".dok_dok_id =
> "inner".dok_id) AND ("outer".kau_kau_id = "inner".kau_kau_id))
> -> Index Scan using dor_dok_kau_i on
> dokumentide_read ar (cost=0.00..42789.44 rows=480962 width=19) (actual
> time=0.023..7873.117 rows=205879 loops=1)
> -> Sort (cost=4759.52..4798.76 rows=15696
> width=19) (actual time=428381.719..428392.204 rows=16271 loops=1)
> Sort Key: a.dok_id, ir.kau_kau_id
> -> Merge Left Join
> (cost=0.00..3665.65 rows=15696 width=19) (actual time=0.245..428279.595
> rows=16258 loops=1)
> Merge Cond: ("outer".dok_id =
> "inner".dok_dok_id)
> -> Nested Loop
> (cost=0.00..3620.23 rows=15696 width=19) (actual time=0.063..7243.529
> rows=16258 loops=1)
> -> Index Scan using dok_pk
> on dokumendid i (cost=0.00..3.73 rows=1 width=4) (actual
> time=0.030..0.035 rows=1 loops=1)
> Index Cond: (dok_id =
> 8034)
> Filter: (tyyp =
> 'IN'::bpchar)
> -> Index Scan using
> dor_dok_fk_i on dokumentide_read ir (cost=0.00..3459.55 rows=15696
> width=19) (actual time=0.023..7150.257 rows=16258 loops=1)
> Index Cond: (8034 =
> dok_dok_id)
> -> Index Scan using dok_dok_fk_i
> on dokumendid a (cost=0.00..566.24 rows=184 width=8) (actual
> time=0.170..420806.563 rows=1 loops=1)
> Filter: (tyyp =
> 'IA'::bpchar)
> -> Hash (cost=757.71..757.71 rows=6487 width=24)
> (actual time=109.178..109.178 rows=0 loops=1)
> -> Hash Join (cost=15.56..757.71 rows=6487
> width=24) (actual time=1.787..85.554 rows=17752 loops=1)
> Hash Cond: ("outer".kag_kag_id =
> "inner".a_kag_id)
> -> Seq Scan on kaubad k
> (cost=0.00..588.52 rows=17752 width=8) (actual time=0.005..30.952
> rows=17752 loops=1)
> -> Hash (cost=15.35..15.35 rows=83
> width=24) (actual time=1.770..1.770 rows=0 loops=1)
> -> Hash Join (cost=5.39..15.35
> rows=83 width=24) (actual time=0.276..1.491 rows=227 loops=1)
> Hash Cond:
> ("outer".y_kag_id = "inner".kag_id)
> -> Seq Scan on
> kaubagruppide_kaubagrupid gg (cost=0.00..7.09 rows=409 width=8) (actual
> time=0.004..0.405 rows=409 loops=1)
> -> Hash (cost=5.27..5.27
> rows=46 width=20) (actual time=0.259..0.259 rows=0 loops=1)
> -> Seq Scan on
> kaubagrupid g (cost=0.00..5.27 rows=46 width=20) (actual
> time=0.010..0.206 rows=46 loops=1)
> Filter:
> (kag_kag_id IS NULL)
> Total runtime: 437011.532 ms
> (33 rows)
>
> Tambet
>
> ---------------------------(end of broadcast)---------------------------
> TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org