Skip to content

Instantly share code, notes, and snippets.

@robbat2

robbat2/gist:c44677ee4d425947af1b

Created July 14, 2015 22:29
Show Gist options

  • Select an option

    Learn more about clone URLs
  • Save robbat2/c44677ee4d425947af1b to your computer and use it in GitHub Desktop.

Select an option

Learn more about clone URLs
Save robbat2/c44677ee4d425947af1b to your computer and use it in GitHub Desktop.
Download ZIP
postgres explain problems
Raw
gistfile1.sql
2015-07-14 22:21:55 GMT LOG: duration: 103068.100 ms plan:
Query Text:
SELECT DISTINCT
x.value,
x.id,
x.push,
x.restrict,
x.weight,
x.ts_rank_cd,
x.buoyant,
TS_HEADLINE(value, $7, $3)
FROM (SELECT DISTINCT
mbe.value,
cmf.id,
cmc.buoyant AND _registered.field_class IS NOT NULL AS push,
_registered.field = cmf.id AS restrict,
cmf.weight,
TS_RANK_CD(mbe.index_vector, $1, $6),
cmc.buoyant,
mbedm.source
FROM metabib.browse_entry_def_map mbedm
JOIN (SELECT * FROM metabib.browse_entry WHERE index_vector @@ $1 LIMIT 10000) mbe ON (mbe.id = mbedm.entry)
JOIN config.metabib_field cmf ON (cmf.id = mbedm.def)
JOIN config.metabib_class cmc ON (cmf.field_class = cmc.name)
LEFT JOIN
metabib.search_class_to_registered_components($2)
AS _registered (field_class TEXT, field INT) ON (
_registered.field_class = cmc.name
)
ORDER BY 3 DESC, 4 DESC NULLS LAST, 5 DESC, 6 DESC, 7 DESC, 1 ASC
LIMIT 1000) AS x
JOIN asset.opac_visible_copies aovc ON (
aovc.record = x.source AND
aovc.circ_lib IN (SELECT id FROM actor.org_unit_descendants($4))
)
ORDER BY 3 DESC, 4 DESC NULLS LAST, 5 DESC, 6 DESC, 7 DESC, 1 ASC
LIMIT $5
Limit (cost=521023.02..521023.25 rows=10 width=52) (actual time=103068.054..103068.089 rows=10 loops=1)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, (ts_headline(mbe.value, '''empir'':*'::pg_catalog.tsquery, 'StartSel="<span class=''oils_AS''>", StopSel=</span>'::text))
-> Unique (cost=521023.02..521024.75 rows=77 width=52) (actual time=103068.053..103068.086 rows=10 loops=1)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, (ts_headline(mbe.value, '''empir'':*'::pg_catalog.tsquery, 'StartSel="<span class=''oils_AS''>", StopSel=</span>'::text))
-> Sort (cost=521023.02..521023.21 rows=77 width=52) (actual time=103068.052..103068.056 rows=47 loops=1)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, (ts_headline(mbe.value, '''empir'':*'::pg_catalog.tsquery, 'StartSel="<span class=''oils_AS''>", StopSel=</span>'::text))
Sort Key: ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, mbe.value, cmf.id, (ts_headline(mbe.value, '''empir'':*'::pg_catalog.tsquery, 'StartSel="<span class=''oils_AS''>", StopSel=</span>'::text))
Sort Method: quicksort Memory: 38kB
-> Nested Loop (cost=514513.34..521020.61 rows=77 width=52) (actual time=12115.994..103067.615 rows=95 loops=1)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, ts_headline(mbe.value, '''empir'':*'::pg_catalog.tsquery, 'StartSel="<span class=''oils_AS''>", StopSel=</span>'::text)
-> HashAggregate (cost=0.26..0.27 rows=1 width=4) (actual time=3.154..3.209 rows=17 loops=1)
Output: org_unit_descendants.id
Group Key: org_unit_descendants.id
-> Function Scan on actor.org_unit_descendants (cost=0.25..0.26 rows=1 width=4) (actual time=3.138..3.139 rows=17 loops=1)
Output: org_unit_descendants.id, org_unit_descendants.parent_ou, org_unit_descendants.ou_type, org_unit_descendants.ill_address, org_unit_descendants.holds_address, org_unit_descendants.mailing_address, org_unit_descendants.billing_address, org_unit_descendants.shortname, org_unit_descendants.name, org_unit_descendants.email, org_unit_descendants.phone, org_unit_descendants.opac_visible, org_unit_descendants.fiscal_calendar
Function Call: actor.org_unit_descendants(75)
-> Nested Loop (cost=514513.07..521010.14 rows=1000 width=56) (actual time=6059.705..6062.317 rows=6 loops=17)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, aovc.circ_lib
-> Limit (cost=514512.64..514535.14 rows=1000 width=164) (actual time=6056.211..6057.006 rows=1000 loops=17)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, mbedm.source
-> Unique (cost=514512.64..531181.36 rows=740832 width=164) (actual time=6056.209..6056.839 rows=1000 loops=17)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, mbedm.source
-> Sort (cost=514512.64..516364.72 rows=740832 width=164) (actual time=6056.196..6056.405 rows=1021 loops=17)
Output: mbe.value, cmf.id, ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, mbedm.source
Sort Key: ((cmc.buoyant AND (_registered.field_class IS NOT NULL))), ((_registered.field = cmf.id)), cmf.weight, (ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14)), cmc.buoyant, mbe.value, cmf.id, mbedm.source
Sort Method: quicksort Memory: 1365kB
-> Hash Join (cost=12142.03..390194.02 rows=740832 width=164) (actual time=3.631..5993.286 rows=7980 loops=17)
Output: mbe.value, cmf.id, (cmc.buoyant AND (_registered.field_class IS NOT NULL)), (_registered.field = cmf.id), cmf.weight, ts_rank_cd(mbe.index_vector, '''empir'':*'::pg_catalog.tsquery, 14), cmc.buoyant, mbedm.source
Hash Cond: (mbedm.def = cmf.id)
-> Hash Join (cost=12136.14..376297.53 rows=740832 width=123) (actual time=3.596..5976.643 rows=7980 loops=17)
Output: mbedm.source, mbedm.def, mbe.value, mbe.index_vector
Hash Cond: (mbedm.entry = mbe.id)
-> Seq Scan on metabib.browse_entry_def_map mbedm (cost=0.00..268025.35 rows=14196435 width=20) (actual time=0.013..2572.036 rows=14232004 loops=17)
Output: mbedm.id, mbedm.entry, mbedm.def, mbedm.source, mbedm.authority
-> Hash (cost=12097.67..12097.67 rows=3077 width=119) (actual time=59.246..59.246 rows=4753 loops=1)
Output: mbe.value, mbe.index_vector, mbe.id
Buckets: 1024 Batches: 1 Memory Usage: 1033kB
-> Subquery Scan on mbe (cost=4007.85..12097.67 rows=3077 width=119) (actual time=43.491..55.508 rows=4753 loops=1)
Output: mbe.value, mbe.index_vector, mbe.id
-> Limit (cost=4007.85..12066.90 rows=3077 width=153) (actual time=43.487..53.429 rows=4753 loops=1)
Output: browse_entry.id, browse_entry.value, browse_entry.index_vector, browse_entry.sort_value
-> Bitmap Heap Scan on metabib.browse_entry (cost=4007.85..12066.90 rows=3077 width=153) (actual time=43.486..52.637 rows=4753 loops=1)
Output: browse_entry.id, browse_entry.value, browse_entry.index_vector, browse_entry.sort_value
Recheck Cond: (browse_entry.index_vector @@ '''empir'':*'::pg_catalog.tsquery)
Heap Blocks: exact=3914
-> Bitmap Index Scan on metabib_browse_entry_index_vector_idx (cost=0.00..4007.08 rows=3077 width=0) (actual time=42.874..42.874 rows=4753 loops=1)
Index Cond: (browse_entry.index_vector @@ '''empir'':*'::pg_catalog.tsquery)
-> Hash (cost=5.39..5.39 rows=40 width=45) (actual time=0.387..0.387 rows=40 loops=1)
Output: cmf.id, cmf.weight, cmc.buoyant, _registered.field_class, _registered.field
Buckets: 1024 Batches: 1 Memory Usage: 2kB
-> Hash Join (cost=1.44..5.39 rows=40 width=45) (actual time=0.331..0.375 rows=40 loops=1)
Output: cmf.id, cmf.weight, cmc.buoyant, _registered.field_class, _registered.field
Hash Cond: (cmf.field_class = cmc.name)
-> Seq Scan on config.metabib_field cmf (cost=0.00..3.40 rows=40 width=16) (actual time=0.005..0.020 rows=40 loops=1)
Output: cmf.id, cmf.field_class, cmf.name, cmf.xpath, cmf.weight, cmf.format, cmf.search_field, cmf.facet_field, cmf.label, cmf.facet_xpath, cmf.browse_field, cmf.browse_xpath, cmf.restrict, cmf.authority_xpath, cmf.browse_sort_xpath, cmf.joiner
-> Hash (cost=1.36..1.36 rows=6 width=44) (actual time=0.317..0.317 rows=6 loops=1)
Output: cmc.buoyant, cmc.name, _registered.field_class, _registered.field
Buckets: 1024 Batches: 1 Memory Usage: 1kB
-> Hash Left Join (cost=0.27..1.36 rows=6 width=44) (actual time=0.307..0.310 rows=6 loops=1)
Output: cmc.buoyant, cmc.name, _registered.field_class, _registered.field
Hash Cond: (cmc.name = _registered.field_class)
-> Seq Scan on config.metabib_class cmc (cost=0.00..1.06 rows=6 width=8) (actual time=0.002..0.004 rows=6 loops=1)
Output: cmc.buoyant, cmc.name
-> Hash (cost=0.26..0.26 rows=1 width=36) (actual time=0.300..0.300 rows=1 loops=1)
Output: _registered.field_class, _registered.field
Buckets: 1024 Batches: 1 Memory Usage: 1kB
-> Function Scan on metabib.search_class_to_registered_components _registered (cost=0.25..0.26 rows=1 width=36) (actual time=0.298..0.298 rows=1 loops=1)
Output: _registered.field_class, _registered.field
Function Call: metabib.search_class_to_registered_components('keyword'::text)
-> Index Only Scan using opac_visible_copies_idx1 on asset.opac_visible_copies aovc (cost=0.43..6.45 rows=1 width=12) (actual time=0.005..0.005 rows=0 loops=17000)
Output: aovc.record, aovc.circ_lib
Index Cond: ((aovc.record = mbedm.source) AND (aovc.circ_lib = org_unit_descendants.id))
Heap Fetches: 95
2015-07-14 22:21:55 GMT CONTEXT: PL/pgSQL function metabib.suggest_browse_entries(text,text,text,integer,integer,integer) line 67 at RETURN QUERY
2015-07-14 22:21:55 GMT LOG: duration: 103078.199 ms plan:
Query Text: EXPLAIN ANALYZE VERBOSE SELECT * FROM metabib.suggest_browse_entries( 'empires', 'keyword', 'StartSel="<span class=''oils_AS''>", StopSel=</span>', '75', '10', '14' ) AS "metabib.suggest_browse_entries" ;
Function Scan on metabib.suggest_browse_entries "metabib.suggest_browse_entries" (cost=0.25..10.25 rows=1000 width=79) (actual time=103078.194..103078.195 rows=10 loops=1)
Output: value, field, buoyant_and_class_match, field_match, field_weight, rank, buoyant, match
Function Call: metabib.suggest_browse_entries('empires'::text, 'keyword'::text, 'StartSel="<span class=''oils_AS''>", StopSel=</span>'::text, 75, 10, 14)
2015-07-14 22:21:55 GMT LOG: duration: 103078.779 ms
2015-07-14 22:23:20 GMT LOG: statement: SET auto_explain.log_nested_statements = true;
2015-07-14 22:23:20 GMT LOG: duration: 0.220 ms
2015-07-14 22:24:03 GMT LOG: statement: SET auto_explain.log_analyze = false;
2015-07-14 22:24:03 GMT LOG: duration: 0.229 ms
2015-07-14 22:24:43 GMT LOG: statement: SELECT count(*)
FROM pg_class, pg_index
WHERE oid = indrelid AND indisunique;
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment