While creating a function, I kept getting a large variance in runtime between the raw query vs. using the
function/preparedstatement. After talking with folks on #postgresql, specifically David Fetter, he thought I should
mentionit here.
VERSION: PostgreSQL 8.3.7 on i486-pc-linux-gnu, compiled by GCC gcc-4.3.real(Debian 4.3.2-1.1)4.3.2
==============================
DOING A PREPARE, EXPLAIN ANALYZE EXECUTE
==============================
Group (cost=26857.96..37572.40 rows=40000 width=32) (actual time=6234.328..7015.498 rows=2185 loops=1) -> Sort
(cost=26857.96..27036.57rows=71444 width=32) (actual time=6230.165..6232.030 rows=5164 loops=1) Sort Key:
gen_ts_by_scope_extra.thets,gen_ts_by_scope_extra.theinterval, dcdo.contact_output_id Sort Method: quicksort
Memory:492kB -> Nested Loop Left Join (cost=1443.96..19386.46 rows=71444 width=32) (actual
time=14.061..6226.787rows=5164 loops=1) Join Filter: ((dcdo.created >= gen_ts_by_scope_extra.thets) AND
(dcdo.created< (gen_ts_by_scope_extra.thets + gen_ts_by_scope_extra.theinterval))) -> Function Scan on
gen_ts_by_scope_extra (cost=0.00..260.00 rows=1000 width=24) (actual time=2.646..3.377 rows=2185 loops=1)
-> Materialize (cost=1443.96..1450.39 rows=643 width=16) (actual time=0.000..1.046 rows=3603 loops=2185)
-> Append (cost=0.00..1443.32 rows=643 width=16) (actual time=0.086..5.810 rows=3603 loops=1)
-> Seq Scan on data_contact_output dcdo (cost=0.00..1.20 rows=3 width=16) (actual time=0.011..0.011 rows=0 loops=1)
Filter: (contact_output_id = $1) -> Bitmap Heap Scan on
data_contact_output_200904dcdo (cost=4.96..197.97 rows=91 width=16) (actual time=0.013..0.013 rows=0 loops=1)
Recheck Cond: (contact_output_id = $1) -> Bitmap Index Scan on
data_contact_output_200904_contact_output_idx (cost=0.00..4.94 rows=91 width=0) (actual time=0.011..0.011 rows=0
loops=1) Index Cond: (contact_output_id = $1) -> Bitmap
HeapScan on data_contact_output_200905 dcdo (cost=9.57..364.27 rows=169 width=16) (actual time=0.060..0.242 rows=202
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_200905_contact_output_idx (cost=0.00..9.53 rows=169 width=0) (actual
time=0.049..0.049rows=202 loops=1) Index Cond: (contact_output_id = $1)
-> Bitmap Heap Scan on data_contact_output_200906 dcdo (cost=9.81..381.47 rows=199 width=16) (actual
time=0.528..2.600rows=2548 loops=1) Recheck Cond: (contact_output_id = $1)
-> Bitmap Index Scan on data_contact_output_200906_contact_output_idx (cost=0.00..9.76 rows=199
width=0)(actual time=0.463..0.463 rows=2548 loops=1) Index Cond: (contact_output_id
=$1) -> Bitmap Heap Scan on data_contact_output_200907 dcdo (cost=5.27..304.93 rows=130
width=16)(actual time=0.225..1.076 rows=853 loops=1) Recheck Cond: (contact_output_id =
$1) -> Bitmap Index Scan on data_contact_output_200907_contact_output_idx
(cost=0.00..5.24rows=130 width=0) (actual time=0.177..0.177 rows=853 loops=1) Index
Cond:(contact_output_id = $1) -> Bitmap Heap Scan on data_contact_output_200908 dcdo
(cost=4.27..11.38rows=3 width=16) (actual time=0.005..0.005 rows=0 loops=1) Recheck Cond:
(contact_output_id= $1) -> Bitmap Index Scan on
data_contact_output_200908_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.003..0.003 rows=0
loops=1) Index Cond: (contact_output_id = $1) -> Bitmap
HeapScan on data_contact_output_200909 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_200909_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.003..0.003
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_200910 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_200910_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_200911 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_200911_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_200912 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.002..0.002 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_200912_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201001 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.002..0.002 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201001_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201002 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.002..0.002 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201002_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201003 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201003_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201004 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201004_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201005 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.002..0.002 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201005_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201006 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201006_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.003..0.003
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201007 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201007_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201008 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.004..0.004 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201008_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201009 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201009_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201010 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201010_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.003..0.003
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201011 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201011_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.002..0.002
rows=0loops=1) Index Cond: (contact_output_id = $1) ->
BitmapHeap Scan on data_contact_output_201012 dcdo (cost=4.27..11.38 rows=3 width=16) (actual time=0.003..0.003 rows=0
loops=1) Recheck Cond: (contact_output_id = $1) -> Bitmap
IndexScan on data_contact_output_201012_contact_output_idx (cost=0.00..4.27 rows=3 width=0) (actual time=0.003..0.003
rows=0loops=1) Index Cond: (contact_output_id = $1)
Total runtime: 7017.096 ms
==============================
DOING AN EXPLAIN ANALYZE query
==============================
Group (cost=90863.24..104733.24 rows=40000 width=32) (actual time=188.712..730.063 rows=2185 loops=1) -> Sort
(cost=90863.24..91830.74rows=387000 width=32) (actual time=185.074..186.704 rows=5164 loops=1) Sort Key:
gen_ts_by_scope_extra.thets,gen_ts_by_scope_extra.theinterval, dcdo.contact_output_id Sort Method: quicksort
Memory:492kB -> Nested Loop Left Join (cost=0.00..36423.82 rows=387000 width=32) (actual time=2.779..181.244
rows=5164loops=1) Join Filter: ((dcdo.created >= gen_ts_by_scope_extra.thets) AND (dcdo.created <
(gen_ts_by_scope_extra.thets+ gen_ts_by_scope_extra.theinterval))) -> Function Scan on
gen_ts_by_scope_extra (cost=0.00..260.00 rows=1000 width=24) (actual time=2.652..3.473 rows=2185 loops=1)
-> Append (cost=0.00..29.20 rows=398 width=16) (actual time=0.051..0.065 rows=2 loops=2185) -> Seq
Scanon data_contact_output dcdo (cost=0.00..1.20 rows=1 width=16) (actual time=0.005..0.005 rows=0 loops=2185)
Filter: (dcdo.contact_output_id = 3103) -> Index Scan using
data_contact_output_200904_contact_output_idxon data_contact_output_200904 dcdo (cost=0.00..2.33 rows=7 width=16)
(actualtime=0.004..0.004 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200905_contact_output_idxon data_contact_output_200905 dcdo (cost=0.00..4.16 rows=15 width=16)
(actualtime=0.005..0.005 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200906_contact_output_idxon data_contact_output_200906 dcdo (cost=0.00..9.92 rows=258 width=16)
(actualtime=0.005..0.006 rows=1 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200907_contact_output_idxon data_contact_output_200907 dcdo (cost=0.00..6.12 rows=100 width=16)
(actualtime=0.005..0.005 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200908_contact_output_idxon data_contact_output_200908 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200909_contact_output_idxon data_contact_output_200909 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200910_contact_output_idxon data_contact_output_200910 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200911_contact_output_idxon data_contact_output_200911 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_200912_contact_output_idxon data_contact_output_200912 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201001_contact_output_idxon data_contact_output_201001 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201002_contact_output_idxon data_contact_output_201002 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201003_contact_output_idxon data_contact_output_201003 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201004_contact_output_idxon data_contact_output_201004 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201005_contact_output_idxon data_contact_output_201005 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201006_contact_output_idxon data_contact_output_201006 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201007_contact_output_idxon data_contact_output_201007 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201008_contact_output_idxon data_contact_output_201008 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201009_contact_output_idxon data_contact_output_201009 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201010_contact_output_idxon data_contact_output_201010 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201011_contact_output_idxon data_contact_output_201011 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval))) -> Index Scan using
data_contact_output_201012_contact_output_idxon data_contact_output_201012 dcdo (cost=0.00..0.32 rows=1 width=16)
(actualtime=0.002..0.002 rows=0 loops=2185) Index Cond: ((dcdo.contact_output_id = 3103) AND
(dcdo.created>= gen_ts_by_scope_extra.thets) AND (dcdo.created < (gen_ts_by_scope_extra.thets +
gen_ts_by_scope_extra.theinterval)))
Total runtime: 731.399 ms
--
Sincerely,
Zach Conrad
Digitec Incorporated
zach.conrad@digitecinc.com
