explain.depesz.com

PostgreSQL's explain analyze made readable

Result: F8dM

Settings
# exclusive inclusive rows x rows loops node
1. 245.890 98,076.924 ↓ 269.2 2,108,022 1

Subquery Scan on s (cost=592,320.21..654,978.57 rows=7,832 width=300) (actual time=95,854.176..98,076.924 rows=2,108,022 loops=1)

  • Output: s.origination_id, s.id, s.created_at, s.updated_at, s.body, s.report_name, s.report_type, s.control_file_name
  • Filter: (s.rownum1 = 1)
  • Rows Removed by Filter: 10402
  • Buffers: shared hit=19144250 read=2283790 written=150090
2. 1,535.002 97,831.034 ↓ 1.4 2,118,424 1

WindowAgg (cost=592,320.21..635,397.83 rows=1,566,459 width=308) (actual time=95,854.174..97,831.034 rows=2,118,424 loops=1)

  • Output: rep_use.origination_id, cach_1.id, cach_1.created_at, cach_1.updated_at, cach_1.body, cach_1.report_name, cach_1.report_type, ((cach_1.body #>> '{xml_response,clear_products_request,control_file_name}'::text[])), row_number() OVER (?)
  • Buffers: shared hit=19144250 read=2283790 written=150090
3. 12,096.759 96,296.032 ↓ 1.4 2,118,424 1

Sort (cost=592,320.21..596,236.36 rows=1,566,459 width=300) (actual time=95,854.162..96,296.032 rows=2,118,424 loops=1)

  • Output: rep_use.origination_id, cach_1.created_at, cach_1.report_name, ((cach_1.body #>> '{xml_response,clear_products_request,control_file_name}'::text[])), cach_1.id, cach_1.updated_at, cach_1.body, cach_1.report_type
  • Sort Key: rep_use.origination_id, cach_1.report_name, ((cach_1.body #>> '{xml_response,clear_products_request,control_file_name}'::text[])), cach_1.created_at DESC
  • Sort Method: quicksort Memory: 949316kB
  • Buffers: shared hit=19144250 read=2283790 written=150090
4. 0.000 84,199.273 ↓ 1.4 2,118,424 1

Gather (cost=100.86..431,138.82 rows=1,566,459 width=300) (actual time=172.979..84,199.273 rows=2,118,424 loops=1)

  • Output: rep_use.origination_id, cach_1.created_at, cach_1.report_name, ((cach_1.body #>> '{xml_response,clear_products_request,control_file_name}'::text[])), cach_1.id, cach_1.updated_at, cach_1.body, cach_1.report_type
  • Workers Planned: 9
  • Workers Launched: 9
  • Buffers: shared hit=19144250 read=2283790 written=150090
5. 82,963.768 84,803.595 ↓ 1.2 211,842 10

Nested Loop (cost=0.86..274,392.92 rows=174,051 width=300) (actual time=165.669..84,803.595 rows=211,842 loops=10)

  • Output: rep_use.origination_id, cach_1.created_at, cach_1.report_name, (cach_1.body #>> '{xml_response,clear_products_request,control_file_name}'::text[]), cach_1.id, cach_1.updated_at, cach_1.body, cach_1.report_type
  • Inner Unique: true
  • Buffers: shared hit=19144250 read=2283790 written=150090
  • Worker 0: actual time=163.753..84985.032 rows=215159 loops=1
  • Buffers: shared hit=1943547 read=231159 written=15153
  • Worker 1: actual time=163.422..85087.283 rows=211840 loops=1
  • Buffers: shared hit=1915159 read=228536 written=15073
  • Worker 2: actual time=164.335..85036.223 rows=212245 loops=1
  • Buffers: shared hit=1922289 read=228625 written=14971
  • Worker 3: actual time=163.871..84774.694 rows=211723 loops=1
  • Buffers: shared hit=1908001 read=227722 written=14752
  • Worker 4: actual time=165.065..84875.873 rows=211010 loops=1
  • Buffers: shared hit=1905456 read=228211 written=15139
  • Worker 5: actual time=165.070..84941.780 rows=211125 loops=1
  • Buffers: shared hit=1905834 read=227547 written=14929
  • Worker 6: actual time=165.983..84647.141 rows=212934 loops=1
  • Buffers: shared hit=1929303 read=230872 written=15142
  • Worker 7: actual time=166.232..85076.343 rows=209653 loops=1
  • Buffers: shared hit=1894999 read=225616 written=14799
  • Worker 8: actual time=166.526..84997.986 rows=213956 loops=1
  • Buffers: shared hit=1929185 read=230193 written=15273
6. 1,839.820 1,839.820 ↑ 1.1 274,837 10

Parallel Index Only Scan using report_usages_idx1 on public.report_usages rep_use (cost=0.43..90,957.78 rows=305,374 width=40) (actual time=0.371..1,839.820 rows=274,837 loops=10)

  • Output: rep_use.cached_report_id, rep_use.origination_id
  • Heap Fetches: 2748404
  • Buffers: shared hit=1482713 read=33929 written=2026
  • Worker 0: actual time=0.348..1908.238 rows=278988 loops=1
  • Buffers: shared hit=150742 read=3435 written=187
  • Worker 1: actual time=0.331..1917.415 rows=274818 loops=1
  • Buffers: shared hit=148485 read=3398 written=210
  • Worker 2: actual time=0.361..1752.979 rows=276256 loops=1
  • Buffers: shared hit=148493 read=3394 written=217
  • Worker 3: actual time=0.359..1878.616 rows=273548 loops=1
  • Buffers: shared hit=147652 read=3380 written=200
  • Worker 4: actual time=0.579..1577.443 rows=273523 loops=1
  • Buffers: shared hit=147152 read=3369 written=202
  • Worker 5: actual time=0.386..2002.870 rows=273664 loops=1
  • Buffers: shared hit=147569 read=3381 written=196
  • Worker 6: actual time=0.574..1802.898 rows=277636 loops=1
  • Buffers: shared hit=148857 read=3446 written=208
  • Worker 7: actual time=0.361..2014.747 rows=272144 loops=1
  • Buffers: shared hit=146371 read=3369 written=203
  • Worker 8: actual time=0.403..1778.871 rows=276471 loops=1
  • Buffers: shared hit=150011 read=3406 written=212
7. 0.007 0.007 ↑ 1.0 1 2,748,370

Index Scan using cached_reports_pkey on public.cached_reports cach_1 (cost=0.43..0.60 rows=1 width=232) (actual time=0.007..0.007 rows=1 loops=2,748,370)

  • Output: cach_1.id, cach_1.report_key, cach_1.report_name, cach_1.body, cach_1.used, cach_1.created_at, cach_1.updated_at, cach_1.originating_org, cach_1.report_type, cach_1.invalidated_at
  • Index Cond: (cach_1.id = rep_use.cached_report_id)
  • Filter: ((cach_1.created_at > '2019-02-17 00:00:00'::timestamp without time zone) AND ((cach_1.report_type)::text <> 'neuro'::text))
  • Rows Removed by Filter: 0
  • Buffers: shared hit=10971794 read=32429 written=881
  • Worker 0: actual time=0.007..0.007 rows=1 loops=278988
  • Buffers: shared hit=1113647 read=3384 written=72
  • Worker 1: actual time=0.007..0.007 rows=1 loops=274818
  • Buffers: shared hit=1097166 read=3215 written=81
  • Worker 2: actual time=0.007..0.007 rows=1 loops=276256
  • Buffers: shared hit=1103016 read=3103 written=94
  • Worker 3: actual time=0.007..0.007 rows=1 loops=273548
  • Buffers: shared hit=1092222 read=3069 written=94
  • Worker 4: actual time=0.007..0.007 rows=1 loops=273523
  • Buffers: shared hit=1091846 read=3305 written=103
  • Worker 5: actual time=0.008..0.008 rows=1 loops=273664
  • Buffers: shared hit=1092368 read=3365 written=93
  • Worker 6: actual time=0.007..0.007 rows=1 loops=277636
  • Buffers: shared hit=1108417 read=3183 written=79
  • Worker 7: actual time=0.007..0.007 rows=1 loops=272144
  • Buffers: shared hit=1086402 read=3251 written=83
  • Worker 8: actual time=0.007..0.007 rows=1 loops=276471
  • Buffers: shared hit=1103604 read=3332 written=92
Planning time : 0.400 ms
Execution time : 98,221.302 ms