explain.depesz.com

PostgreSQL's explain analyze made readable

Result: 3Js9 : 3.0.9

Settings
# exclusive inclusive rows x rows loops node
1. 0.090 14,633.530 ↑ 1.0 1,001 1

Append (cost=191,295.98..191,393.27 rows=1,001 width=112) (actual time=14,617.457..14,633.530 rows=1,001 loops=1)

2.          

CTE w

3. 6.154 14,626.091 ↓ 6.3 15,515 1

Subquery Scan on core_query (cost=191,253.18..191,295.98 rows=2,446 width=116) (actual time=14,617.448..14,626.091 rows=15,515 loops=1)

4.          

CTE xe408548_keyword_xq

5. 0.707 0.707 ↑ 1.0 1 1

Result (cost=0.00..1.02 rows=1 width=0) (actual time=0.706..0.707 rows=1 loops=1)

6.          

CTE lang_with

7. 0.122 0.205 ↑ 1.0 1 1

Bitmap Heap Scan on coded_value_map (cost=9.93..51.22 rows=1 width=4) (actual time=0.124..0.205 rows=1 loops=1)

  • Recheck Cond: (ctype = 'item_lang'::text)
  • Filter: (code = 'eng'::text)
  • Rows Removed by Filter: 485
  • Heap Blocks: exact=5
8. 0.083 0.083 ↑ 1.0 486 1

Bitmap Index Scan on config_coded_value_map_ctype_idx (cost=0.00..9.92 rows=486 width=0) (actual time=0.083..0.083 rows=486 loops=1)

  • Index Cond: (ctype = 'item_lang'::text)
9.          

CTE pop_with

10. 15.105 17.361 ↑ 1.0 6,248 1

HashAggregate (cost=346.55..471.51 rows=6,248 width=20) (actual time=10.654..17.361 rows=6,248 loops=1)

  • Group Key: s.record
11. 1.563 2.256 ↑ 1.0 6,248 1

Nested Loop (cost=0.00..221.59 rows=6,248 width=20) (actual time=0.114..2.256 rows=6,248 loops=1)

  • Join Filter: (s.badge = b.id)
12. 0.018 0.018 ↑ 1.0 1 1

Seq Scan on badge b (cost=0.00..1.01 rows=1 width=8) (actual time=0.017..0.018 rows=1 loops=1)

  • Filter: (scope = ANY ('{1}'::integer[]))
13. 0.675 0.675 ↑ 1.0 6,248 1

Seq Scan on record_badge_score s (cost=0.00..142.48 rows=6,248 width=16) (actual time=0.091..0.675 rows=6,248 loops=1)

14.          

CTE c_attr

15. 6.161 6.161 ↑ 1.0 1 1

Function Scan on patron_default_visibility_mask x (cost=0.25..0.27 rows=1 width=32) (actual time=6.159..6.161 rows=1 loops=1)

16.          

CTE b_attr

17. 0.976 0.976 ↑ 1.0 1 1

Function Scan on patron_default_visibility_mask x_1 (cost=0.25..0.27 rows=1 width=32) (actual time=0.975..0.976 rows=1 loops=1)

18. 1.110 14,619.937 ↓ 6.3 15,515 1

Limit (cost=190,728.89..190,735.01 rows=2,446 width=729) (actual time=14,617.435..14,619.937 rows=15,515 loops=1)

19. 29.158 14,618.827 ↓ 6.3 15,515 1

Sort (cost=190,728.89..190,735.01 rows=2,446 width=729) (actual time=14,617.434..14,618.827 rows=15,515 loops=1)

  • Sort Key: ((1.0 / ((avg(COALESCE((ts_rank_cd('{0.1,0.2,0.4,1}'::real[], fe.index_vector, xe408548_keyword_xq.tsq_rank, 14) * (fe_weight.weight)::double precision), '0'::double precision)) + ((1 * COALESCE(((NULLIF(first((mrv.vlist @> ARRAY[lang_with.id])), false))::integer * 5), 1)))::double precision))::numeric)), (first(pubdate_t.value)) DESC NULLS LAST, (((avg(COALESCE((ts_rank_cd('{0.1,0.2,0.4,1}'::real[], fe.index_vector, xe408548_keyword_xq.tsq_rank, 14) * (fe_weight.weight)::double precision), '0'::double precision)) + ((1 * COALESCE(((NULLIF(first((mrv.vlist @> ARRAY[lang_with.id])), false))::integer * 5), 1)))::double precision))::numeric) DESC
  • Sort Method: quicksort Memory: 2566kB
20. 412.733 14,589.669 ↓ 6.3 15,515 1

HashAggregate (cost=190,444.47..190,591.23 rows=2,446 width=729) (actual time=14,546.174..14,589.669 rows=15,515 loops=1)

  • Group Key: m.source
21. 31.798 14,176.936 ↓ 6.3 15,515 1

Nested Loop (cost=39,278.26..188,524.36 rows=2,446 width=729) (actual time=12,560.996..14,176.936 rows=15,515 loops=1)

  • Join Filter: ((SubPlan 6) OR (b_attr.vis_test IS NULL) OR (bre.vis_attr_vector @@ b_attr.vis_test))
  • Rows Removed by Join Filter: 3673
22. 0.001 7.361 ↑ 1.0 1 1

Nested Loop (cost=0.00..0.08 rows=1 width=68) (actual time=7.274..7.361 rows=1 loops=1)

23. 0.001 6.382 ↑ 1.0 1 1

Nested Loop (cost=0.00..0.05 rows=1 width=36) (actual time=6.297..6.382 rows=1 loops=1)

24. 0.208 0.208 ↑ 1.0 1 1

CTE Scan on lang_with (cost=0.00..0.02 rows=1 width=4) (actual time=0.126..0.208 rows=1 loops=1)

25. 6.173 6.173 ↑ 1.0 1 1

CTE Scan on c_attr (cost=0.00..0.02 rows=1 width=32) (actual time=6.171..6.173 rows=1 loops=1)

26. 0.978 0.978 ↑ 1.0 1 1

CTE Scan on b_attr (cost=0.00..0.02 rows=1 width=32) (actual time=0.976..0.978 rows=1 loops=1)

27. 12.040 13,696.453 ↓ 3.9 19,188 1

Nested Loop Left Join (cost=39,278.26..50,130.62 rows=4,862 width=759) (actual time=12,553.642..13,696.453 rows=19,188 loops=1)

28. 12.819 13,300.653 ↓ 6.6 19,188 1

Hash Join (cost=39,277.83..47,614.56 rows=2,911 width=744) (actual time=12,553.585..13,300.653 rows=19,188 loops=1)

  • Hash Cond: (fe.field = fe_weight.id)
29. 8.904 13,287.802 ↓ 6.6 19,188 1

Nested Loop (cost=39,275.98..47,572.68 rows=2,911 width=744) (actual time=12,553.531..13,287.802 rows=19,188 loops=1)

  • Join Filter: (m.source = mrv.source)
30. 24.366 12,971.810 ↓ 6.3 19,193 1

Nested Loop (cost=39,275.55..46,084.13 rows=3,059 width=641) (actual time=12,553.175..12,971.810 rows=19,193 loops=1)

  • Join Filter: (m.source = bre.id)
31. 15.979 12,577.364 ↓ 2.9 20,560 1

Hash Right Join (cost=39,275.12..39,423.82 rows=7,167 width=599) (actual time=12,552.612..12,577.364 rows=20,560 loops=1)

  • Hash Cond: (pop_with.record = m.source)
32. 19.475 19.475 ↑ 1.0 6,248 1

CTE Scan on pop_with (cost=0.00..124.96 rows=6,248 width=72) (actual time=10.658..19.475 rows=6,248 loops=1)

33. 28.668 12,541.910 ↓ 2.9 20,560 1

Hash (cost=39,185.53..39,185.53 rows=7,167 width=535) (actual time=12,541.910..12,541.910 rows=20,560 loops=1)

  • Buckets: 32768 (originally 8192) Batches: 1 (originally 1) Memory Usage: 9747kB
34. 34.777 12,513.242 ↓ 2.9 20,560 1

Nested Loop (cost=4,204.80..39,185.53 rows=7,167 width=535) (actual time=4,167.486..12,513.242 rows=20,560 loops=1)

35. 16.288 12,201.091 ↓ 3.0 46,229 1

Nested Loop (cost=4,204.37..32,157.64 rows=15,220 width=527) (actual time=4,165.637..12,201.091 rows=46,229 loops=1)

36. 0.709 0.709 ↑ 1.0 1 1

CTE Scan on xe408548_keyword_xq (cost=0.00..0.02 rows=1 width=64) (actual time=0.707..0.709 rows=1 loops=1)

37. 8,134.991 12,184.094 ↓ 3.0 46,229 1

Bitmap Heap Scan on keyword_field_entry fe (cost=4,204.37..32,005.42 rows=15,220 width=495) (actual time=4,164.926..12,184.094 rows=46,229 loops=1)

  • Recheck Cond: (index_vector @@ xe408548_keyword_xq.tsq)
  • Rows Removed by Index Recheck: 412404
  • Filter: (id IS NOT NULL)
  • Heap Blocks: exact=301161
38. 4,049.103 4,049.103 ↓ 34.7 527,433 1

Bitmap Index Scan on metabib_keyword_field_entry_index_vector_idx (cost=0.00..4,200.56 rows=15,220 width=0) (actual time=4,049.103..4,049.103 rows=527,433 loops=1)

  • Index Cond: (index_vector @@ xe408548_keyword_xq.tsq)
39. 277.374 277.374 ↓ 0.0 0 46,229

Index Only Scan using metabib_metarecord_source_map_source_record_idx on metarecord_source_map m (cost=0.43..0.45 rows=1 width=8) (actual time=0.006..0.006 rows=0 loops=46,229)

  • Index Cond: (source = fe.source)
  • Heap Fetches: 2091
40. 370.080 370.080 ↑ 1.0 1 20,560

Index Scan using record_entry_pkey on record_entry bre (cost=0.43..0.92 rows=1 width=42) (actual time=0.018..0.018 rows=1 loops=20,560)

  • Index Cond: (id = fe.source)
  • Filter: (NOT deleted)
  • Rows Removed by Filter: 0
41. 307.088 307.088 ↑ 1.0 1 19,193

Index Scan using record_attr_vector_list_pkey on record_attr_vector_list mrv (cost=0.43..0.47 rows=1 width=127) (actual time=0.015..0.016 rows=1 loops=19,193)

  • Index Cond: (source = fe.source)
42. 0.007 0.032 ↑ 1.0 38 1

Hash (cost=1.38..1.38 rows=38 width=8) (actual time=0.032..0.032 rows=38 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 10kB
43. 0.025 0.025 ↑ 1.0 38 1

Seq Scan on metabib_field fe_weight (cost=0.00..1.38 rows=38 width=8) (actual time=0.019..0.025 rows=38 loops=1)

44. 383.760 383.760 ↑ 4.0 1 19,188

Index Scan using metabib_sorter_source_idx on record_sorter pubdate_t (cost=0.43..0.82 rows=4 width=23) (actual time=0.019..0.020 rows=1 loops=19,188)

  • Index Cond: (m.source = source)
  • Filter: (attr = 'pubdate'::text)
  • Rows Removed by Filter: 2
45.          

SubPlan (forNested Loop)

46. 441.324 441.324 ↑ 1.0 1 19,188

Index Scan using copy_vis_attr_cache_record_idx on copy_vis_attr_cache (cost=0.43..28.45 rows=1 width=0) (actual time=0.023..0.023 rows=1 loops=19,188)

  • Index Cond: (record = m.source)
  • Filter: (vis_attr_vector @@ c_attr.vis_test)
  • Rows Removed by Filter: 0
47. 0.251 14,618.708 ↑ 1.0 1,000 1

Subquery Scan on *SELECT* 1 (cost=0.00..30.00 rows=1,000 width=112) (actual time=14,617.456..14,618.708 rows=1,000 loops=1)

48. 0.081 14,618.457 ↑ 1.0 1,000 1

Limit (cost=0.00..20.00 rows=1,000 width=112) (actual time=14,617.453..14,618.457 rows=1,000 loops=1)

49. 14,618.376 14,618.376 ↑ 2.4 1,000 1

CTE Scan on w (cost=0.00..48.92 rows=2,446 width=112) (actual time=14,617.452..14,618.376 rows=1,000 loops=1)

50. 1.046 14.732 ↑ 1.0 1 1

Aggregate (cost=67.27..67.28 rows=1 width=0) (actual time=14.732..14.732 rows=1 loops=1)

51. 13.686 13.686 ↓ 6.3 15,515 1

CTE Scan on w w_1 (cost=0.00..48.92 rows=2,446 width=0) (actual time=0.001..13.686 rows=15,515 loops=1)