explain.depesz.com

PostgreSQL's explain analyze made readable

Result: I3uo

Settings
# exclusive inclusive rows x rows loops node
1. 0.768 20,143.596 ↑ 1.0 1,001 1

Append (cost=837,789.72..838,377.69 rows=1,001 width=112) (actual time=20,126.944..20,143.596 rows=1,001 loops=1)

  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
2.          

CTE w

3. 3.873 20,135.394 ↑ 5.7 3,552 1

Subquery Scan on core_query (cost=837,434.67..837,789.72 rows=20,289 width=116) (actual time=20,126.933..20,135.394 rows=3,552 loops=1)

  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
4.          

CTE xde71d30_keyword_xq

5. 0.856 0.856 ↑ 1.0 1 1

Result (cost=0.00..0.03 rows=1 width=0) (actual time=0.856..0.856 rows=1 loops=1)

  • Buffers: shared hit=18 read=20
6.          

CTE lang_with

7. 0.154 0.154 ↑ 1.0 1 1

Index Scan using config_coded_value_map_ctype_idx on coded_value_map (cost=0.28..28.02 rows=1 width=4) (actual time=0.019..0.154 rows=1 loops=1)

  • Index Cond: (ctype = 'item_lang'::text)
  • Filter: (code = 'eng'::text)
  • Rows Removed by Filter: 487
  • Buffers: shared hit=11
8.          

CTE pop_with

9. 0.002 0.020 ↓ 0.0 0 1

HashAggregate (cost=8.54..8.70 rows=8 width=20) (actual time=0.020..0.020 rows=0 loops=1)

  • Group Key: s.record
  • Buffers: shared hit=2
10. 0.007 0.018 ↓ 0.0 0 1

Nested Loop (cost=0.15..8.38 rows=8 width=20) (actual time=0.018..0.018 rows=0 loops=1)

  • Buffers: shared hit=2
11. 0.008 0.008 ↑ 1.0 1 1

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

  • Filter: (scope = ANY ('{1}'::integer[]))
  • Buffers: shared hit=1
12. 0.003 0.003 ↓ 0.0 0 1

Index Scan using record_badge_score_badge_idx on record_badge_score s (cost=0.15..7.29 rows=8 width=16) (actual time=0.003..0.003 rows=0 loops=1)

  • Index Cond: (badge = b.id)
  • Buffers: shared hit=1
13.          

CTE c_attr

14. 5.503 5.503 ↑ 1.0 1 1

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

  • Buffers: shared hit=420 read=54
15.          

CTE b_attr

16. 0.942 0.942 ↑ 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.941..0.942 rows=1 loops=1)

  • Buffers: shared hit=38
17. 2.668 20,131.521 ↑ 5.7 3,552 1

Limit (cost=837,397.38..837,448.10 rows=20,289 width=467) (actual time=20,126.924..20,131.521 rows=3,552 loops=1)

  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
18. 10.056 20,128.853 ↑ 5.7 3,552 1

Sort (cost=837,397.38..837,448.10 rows=20,289 width=467) (actual time=20,126.923..20,128.853 rows=3,552 loops=1)

  • Sort Key: ((1.0 / ((avg(COALESCE(((ts_rank_cd('{0.1,0.2,0.4,1}'::real[], "*SELECT* 1_1".index_vector, "*SELECT* 1_1".tsq_rank, 14) * ("*SELECT* 1_1".weight)::double precision) * '1000'::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[], "*SELECT* 1_1".index_vector, "*SELECT* 1_1".tsq_rank, 14) * ("*SELECT* 1_1".weight)::double precision) * '1000'::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: 596kB
  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
19. 198.694 20,118.797 ↑ 5.7 3,552 1

GroupAggregate (cost=555,767.69..835,945.86 rows=20,289 width=467) (actual time=19,555.069..20,118.797 rows=3,552 loops=1)

  • Group Key: m.source
  • Buffers: shared hit=1238151 read=1516407 dirtied=8 written=763
20. 52.172 19,920.103 ↑ 1.5 13,187 1

Nested Loop (cost=555,767.69..818,700.21 rows=20,289 width=467) (actual time=19,554.681..19,920.103 rows=13,187 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: 2056
  • Buffers: shared hit=1222756 read=1513242 dirtied=8 written=763
21. 15.233 19,578.314 ↑ 2.6 15,243 1

Merge Left Join (cost=555,767.69..555,969.42 rows=40,336 width=486) (actual time=19,548.104..19,578.314 rows=15,243 loops=1)

  • Merge Cond: (m.source = pop_with.record)
  • Buffers: shared hit=1167667 read=1506014 written=763
22. 51.400 19,563.045 ↑ 2.6 15,243 1

Sort (cost=555,767.41..555,868.25 rows=40,336 width=422) (actual time=19,548.063..19,563.045 rows=15,243 loops=1)

  • Sort Key: m.source
  • Sort Method: quicksort Memory: 12202kB
  • Buffers: shared hit=1167665 read=1506014 written=763
23. 36.234 19,511.645 ↑ 2.6 15,243 1

Nested Loop Left Join (cost=5.38..552,681.75 rows=40,336 width=422) (actual time=59.766..19,511.645 rows=15,243 loops=1)

  • Buffers: shared hit=1167665 read=1506014 written=763
24. 44.829 19,185.794 ↑ 2.4 15,243 1

Nested Loop (cost=4.95..529,602.36 rows=35,912 width=406) (actual time=59.710..19,185.794 rows=15,243 loops=1)

  • Buffers: shared hit=1127111 read=1484862 written=753
25. 45.345 18,879.114 ↑ 5.4 15,403 1

Nested Loop (cost=4.51..463,591.96 rows=83,005 width=399) (actual time=59.661..18,879.114 rows=15,403 loops=1)

  • Buffers: shared hit=1084167 read=1466069 written=742
26. 68.423 18,538.599 ↑ 6.7 19,678 1

Nested Loop (cost=4.08..399,855.34 rows=131,397 width=272) (actual time=3.224..18,538.599 rows=19,678 loops=1)

  • Buffers: shared hit=1029998 read=1445676 written=736
27. 23.865 18,119.602 ↑ 5.2 25,041 1

Append (cost=3.65..321,897.38 rows=131,154 width=264) (actual time=3.127..18,119.602 rows=25,041 loops=1)

  • Buffers: shared hit=958415 read=1427174 written=728
28. 13.087 7,948.159 ↑ 4.1 12,488 1

Subquery Scan on *SELECT* 1_1 (cost=3.65..57,043.30 rows=51,661 width=417) (actual time=3.126..7,948.159 rows=12,488 loops=1)

  • Buffers: shared hit=445874 read=598884 written=280
29. 22.780 7,935.072 ↑ 4.1 12,488 1

Hash Join (cost=3.65..56,526.69 rows=51,661 width=417) (actual time=3.124..7,935.072 rows=12,488 loops=1)

  • Hash Cond: (fe.field = fe_weight.id)
  • Buffers: shared hit=445874 read=598884 written=280
30. 15.452 7,912.196 ↑ 4.1 12,488 1

Nested Loop (cost=0.42..55,813.11 rows=51,661 width=417) (actual time=3.008..7,912.196 rows=12,488 loops=1)

  • Buffers: shared hit=445869 read=598884 written=280
31. 0.863 0.863 ↑ 1.0 1 1

CTE Scan on xde71d30_keyword_xq (cost=0.00..0.02 rows=1 width=64) (actual time=0.860..0.863 rows=1 loops=1)

  • Buffers: shared hit=18 read=20
32. 7,895.881 7,895.881 ↑ 4.1 12,488 1

Index Scan using metabib_keyword_field_entry_index_vector_idx on keyword_field_entry fe (cost=0.42..55,296.49 rows=51,661 width=385) (actual time=2.145..7,895.881 rows=12,488 loops=1)

  • Index Cond: (index_vector @@ xde71d30_keyword_xq.tsq)
  • Rows Removed by Index Recheck: 101834
  • Filter: (id IS NOT NULL)
  • Buffers: shared hit=445851 read=598864 written=280
33. 0.035 0.096 ↑ 1.0 55 1

Hash (cost=2.55..2.55 rows=55 width=8) (actual time=0.096..0.096 rows=55 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 11kB
  • Buffers: shared hit=2
34. 0.061 0.061 ↑ 1.0 55 1

Seq Scan on metabib_field fe_weight (cost=0.00..2.55 rows=55 width=8) (actual time=0.023..0.061 rows=55 loops=1)

  • Buffers: shared hit=2
35. 3.408 1,513.752 ↑ 5.6 3,590 1

Subquery Scan on *SELECT* 2 (cost=0.42..79,021.57 rows=20,221 width=161) (actual time=0.551..1,513.752 rows=3,590 loops=1)

  • Buffers: shared hit=14655 read=105431 written=88
36. 4.004 1,510.344 ↑ 5.6 3,590 1

Nested Loop (cost=0.42..78,819.36 rows=20,221 width=161) (actual time=0.549..1,510.344 rows=3,590 loops=1)

  • Buffers: shared hit=14655 read=105431 written=88
37. 0.018 0.018 ↑ 1.0 1 1

Seq Scan on metabib_field_virtual_map fe_weight_1 (cost=0.00..1.60 rows=1 width=8) (actual time=0.013..0.018 rows=1 loops=1)

  • Filter: ((virtual = 45) AND ("real" = 16))
  • Rows Removed by Filter: 39
  • Buffers: shared hit=1
38. 3.917 1,506.322 ↑ 5.6 3,590 1

Nested Loop (cost=0.42..78,615.55 rows=20,221 width=161) (actual time=0.532..1,506.322 rows=3,590 loops=1)

  • Buffers: shared hit=14654 read=105431 written=88
39. 0.002 0.002 ↑ 1.0 1 1

CTE Scan on xde71d30_keyword_xq xde71d30_keyword_xq_1 (cost=0.00..0.02 rows=1 width=64) (actual time=0.001..0.002 rows=1 loops=1)

40. 1,502.403 1,502.403 ↑ 5.6 3,590 1

Index Scan using metabib_subject_field_entry_index_vector_idx on subject_field_entry fe_1 (cost=0.42..78,413.32 rows=20,221 width=129) (actual time=0.526..1,502.403 rows=3,590 loops=1)

  • Index Cond: (index_vector @@ xde71d30_keyword_xq_1.tsq)
  • Rows Removed by Index Recheck: 27
  • Filter: ((id IS NOT NULL) AND (field = 16))
  • Rows Removed by Filter: 5559
  • Buffers: shared hit=14654 read=105431 written=88
41. 0.162 1,036.408 ↑ 523.5 92 1

Subquery Scan on *SELECT* 3 (cost=0.42..88,702.15 rows=48,163 width=120) (actual time=0.903..1,036.408 rows=92 loops=1)

  • Buffers: shared hit=35876 read=47544
42. 0.205 1,036.246 ↑ 523.5 92 1

Nested Loop (cost=0.42..88,220.52 rows=48,163 width=120) (actual time=0.902..1,036.246 rows=92 loops=1)

  • Buffers: shared hit=35876 read=47544
43. 0.017 0.017 ↑ 1.0 1 1

Seq Scan on metabib_field_virtual_map fe_weight_2 (cost=0.00..1.60 rows=1 width=8) (actual time=0.011..0.017 rows=1 loops=1)

  • Filter: ((virtual = 45) AND ("real" = 8))
  • Rows Removed by Filter: 39
  • Buffers: shared hit=1
44. 0.194 1,036.024 ↑ 523.5 92 1

Nested Loop (cost=0.42..87,737.29 rows=48,163 width=120) (actual time=0.886..1,036.024 rows=92 loops=1)

  • Buffers: shared hit=35875 read=47544
45. 0.003 0.003 ↑ 1.0 1 1

CTE Scan on xde71d30_keyword_xq xde71d30_keyword_xq_2 (cost=0.00..0.02 rows=1 width=64) (actual time=0.001..0.003 rows=1 loops=1)

46. 1,035.827 1,035.827 ↑ 523.5 92 1

Index Scan using metabib_author_field_entry_index_vector_idx on author_field_entry fe_2 (cost=0.42..87,255.64 rows=48,163 width=88) (actual time=0.879..1,035.827 rows=92 loops=1)

  • Index Cond: (index_vector @@ xde71d30_keyword_xq_2.tsq)
  • Rows Removed by Index Recheck: 59
  • Filter: ((id IS NOT NULL) AND (field = 8))
  • Rows Removed by Filter: 135
  • Buffers: shared hit=35875 read=47544
47. 4.259 6,620.256 ↑ 2.3 3,957 1

Subquery Scan on *SELECT* 4 (cost=2.35..56,189.60 rows=9,041 width=417) (actual time=37.361..6,620.256 rows=3,957 loops=1)

  • Buffers: shared hit=426932 read=617765 written=360
48. 13.446 6,615.997 ↑ 2.3 3,957 1

Hash Join (cost=2.35..56,099.19 rows=9,041 width=417) (actual time=37.358..6,615.997 rows=3,957 loops=1)

  • Hash Cond: (fe_3.field = fe_weight_3."real")
  • Buffers: shared hit=426932 read=617765 written=360
49. 15.177 6,602.502 ↑ 4.1 12,488 1

Nested Loop (cost=0.42..55,813.11 rows=51,661 width=417) (actual time=1.194..6,602.502 rows=12,488 loops=1)

  • Buffers: shared hit=426931 read=617765 written=360
50. 0.003 0.003 ↑ 1.0 1 1

CTE Scan on xde71d30_keyword_xq xde71d30_keyword_xq_3 (cost=0.00..0.02 rows=1 width=64) (actual time=0.002..0.003 rows=1 loops=1)

51. 6,587.322 6,587.322 ↑ 4.1 12,488 1

Index Scan using metabib_keyword_field_entry_index_vector_idx on keyword_field_entry fe_3 (cost=0.42..55,296.49 rows=51,661 width=385) (actual time=1.184..6,587.322 rows=12,488 loops=1)

  • Index Cond: (index_vector @@ xde71d30_keyword_xq_3.tsq)
  • Rows Removed by Index Recheck: 101834
  • Filter: (id IS NOT NULL)
  • Buffers: shared hit=426931 read=617765 written=360
52. 0.026 0.049 ↑ 1.0 7 1

Hash (cost=1.85..1.85 rows=7 width=8) (actual time=0.049..0.049 rows=7 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
  • Buffers: shared hit=1
53. 0.023 0.023 ↑ 1.0 7 1

Seq Scan on metabib_field_virtual_map fe_weight_3 (cost=0.00..1.85 rows=7 width=8) (actual time=0.015..0.023 rows=7 loops=1)

  • Filter: ((virtual = 45) AND ("real" = ANY ('{39,41,42,46,47,48,50}'::integer[])))
  • Rows Removed by Filter: 33
  • Buffers: shared hit=1
54. 4.644 977.162 ↓ 2.4 4,914 1

Subquery Scan on *SELECT* 5 (cost=2.04..40,940.76 rows=2,068 width=151) (actual time=0.458..977.162 rows=4,914 loops=1)

  • Buffers: shared hit=35078 read=57550
55. 7.358 972.518 ↓ 2.4 4,914 1

Hash Join (cost=2.04..40,920.08 rows=2,068 width=151) (actual time=0.456..972.518 rows=4,914 loops=1)

  • Hash Cond: (fe_4.field = fe_weight_4."real")
  • Buffers: shared hit=35078 read=57550
56. 5.748 965.139 ↑ 7.5 5,522 1

Nested Loop (cost=0.41..40,742.70 rows=41,355 width=151) (actual time=0.410..965.139 rows=5,522 loops=1)

  • Buffers: shared hit=35077 read=57550
57. 0.004 0.004 ↑ 1.0 1 1

CTE Scan on xde71d30_keyword_xq xde71d30_keyword_xq_4 (cost=0.00..0.02 rows=1 width=64) (actual time=0.002..0.004 rows=1 loops=1)

58. 959.387 959.387 ↑ 7.5 5,522 1

Index Scan using metabib_title_field_entry_index_vector_idx on title_field_entry fe_4 (cost=0.41..40,329.13 rows=41,355 width=119) (actual time=0.404..959.387 rows=5,522 loops=1)

  • Index Cond: (index_vector @@ xde71d30_keyword_xq_4.tsq)
  • Rows Removed by Index Recheck: 22
  • Filter: (id IS NOT NULL)
  • Buffers: shared hit=35077 read=57550
59. 0.008 0.021 ↑ 1.0 2 1

Hash (cost=1.60..1.60 rows=2 width=8) (actual time=0.021..0.021 rows=2 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
  • Buffers: shared hit=1
60. 0.013 0.013 ↑ 1.0 2 1

Seq Scan on metabib_field_virtual_map fe_weight_4 (cost=0.00..1.60 rows=2 width=8) (actual time=0.012..0.013 rows=2 loops=1)

  • Filter: (("real" = ANY ('{6,53}'::integer[])) AND (virtual = 45))
  • Rows Removed by Filter: 38
  • Buffers: shared hit=1
61. 350.574 350.574 ↑ 1.0 1 25,041

Index Only Scan using metabib_metarecord_source_map_source_record_idx on metarecord_source_map m (cost=0.43..0.58 rows=1 width=8) (actual time=0.014..0.014 rows=1 loops=25,041)

  • Index Cond: (source = "*SELECT* 1_1".source)
  • Heap Fetches: 14684
  • Buffers: shared hit=71583 read=18502 written=8
62. 295.170 295.170 ↑ 1.0 1 19,678

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

  • Index Cond: (source = m.source)
  • Buffers: shared hit=54169 read=20393 written=6
63. 261.851 261.851 ↑ 1.0 1 15,403

Index Scan using record_entry_pkey on record_entry bre (cost=0.43..0.79 rows=1 width=31) (actual time=0.017..0.017 rows=1 loops=15,403)

  • Index Cond: (id = m.source)
  • Filter: (NOT deleted)
  • Rows Removed by Filter: 0
  • Buffers: shared hit=42944 read=18793 written=11
64. 289.617 289.617 ↑ 2.0 1 15,243

Index Scan using metabib_sorter_source_idx on record_sorter pubdate_t (cost=0.43..0.62 rows=2 width=24) (actual time=0.018..0.019 rows=1 loops=15,243)

  • Index Cond: (m.source = source)
  • Filter: (attr = 'pubdate'::text)
  • Rows Removed by Filter: 2
  • Buffers: shared hit=40554 read=21152 written=10
65. 0.013 0.036 ↓ 0.0 0 1

Sort (cost=0.28..0.30 rows=8 width=72) (actual time=0.036..0.036 rows=0 loops=1)

  • Sort Key: pop_with.record
  • Sort Method: quicksort Memory: 25kB
  • Buffers: shared hit=2
66. 0.023 0.023 ↓ 0.0 0 1

CTE Scan on pop_with (cost=0.00..0.16 rows=8 width=72) (actual time=0.023..0.023 rows=0 loops=1)

  • Buffers: shared hit=2
67. 8.616 15.243 ↑ 1.0 1 15,243

Materialize (cost=0.00..0.09 rows=1 width=68) (actual time=0.001..0.001 rows=1 loops=15,243)

  • Buffers: shared hit=469 read=54
68. 0.004 6.627 ↑ 1.0 1 1

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

  • Buffers: shared hit=469 read=54
69. 0.007 5.677 ↑ 1.0 1 1

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

  • Buffers: shared hit=431 read=54
70. 0.157 0.157 ↑ 1.0 1 1

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

  • Buffers: shared hit=11
71. 5.513 5.513 ↑ 1.0 1 1

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

  • Buffers: shared hit=420 read=54
72. 0.946 0.946 ↑ 1.0 1 1

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

  • Buffers: shared hit=38
73.          

SubPlan (forNested Loop)

74. 274.374 274.374 ↑ 1.0 1 15,243

Index Scan using copy_vis_attr_cache_record_idx on copy_vis_attr_cache (cost=0.43..6.50 rows=1 width=0) (actual time=0.018..0.018 rows=1 loops=15,243)

  • Index Cond: (record = m.source)
  • Filter: (vis_attr_vector @@ c_attr.vis_test)
  • Rows Removed by Filter: 0
  • Buffers: shared hit=54620 read=7174 dirtied=8
75. 1.003 20,132.072 ↑ 1.0 1,000 1

Subquery Scan on *SELECT* 1 (cost=0.00..30.00 rows=1,000 width=112) (actual time=20,126.943..20,132.072 rows=1,000 loops=1)

  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
76. 0.753 20,131.069 ↑ 1.0 1,000 1

Limit (cost=0.00..20.00 rows=1,000 width=112) (actual time=20,126.938..20,131.069 rows=1,000 loops=1)

  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
77. 20,130.316 20,130.316 ↑ 20.3 1,000 1

CTE Scan on w (cost=0.00..405.78 rows=20,289 width=112) (actual time=20,126.936..20,130.316 rows=1,000 loops=1)

  • Buffers: shared hit=1238157 read=1516407 dirtied=8 written=763
78. 1.415 10.756 ↑ 1.0 1 1

Aggregate (cost=557.95..557.96 rows=1 width=0) (actual time=10.755..10.756 rows=1 loops=1)

79. 9.341 9.341 ↑ 5.7 3,552 1

CTE Scan on w w_1 (cost=0.00..405.78 rows=20,289 width=0) (actual time=0.001..9.341 rows=3,552 loops=1)

Planning time : 140.868 ms
Execution time : 20,146.736 ms