explain.depesz.com

PostgreSQL's explain analyze made readable

Result: RRCS

Settings
# exclusive inclusive rows x rows loops node
1. 3.286 183,988.264 ↑ 4.0 1 1

GroupAggregate (cost=3,861.33..36,720,127.21 rows=4 width=98) (actual time=183,988.220..183,988.264 rows=1 loops=1)

  • Group Key: t1.doc_kind
  • Buffers: shared hit=627,618
2. 15.722 29.600 ↑ 1.0 36,348 1

Sort (cost=3,861.33..3,952.25 rows=36,367 width=2) (actual time=28.129..29.600 rows=36,348 loops=1)

  • Sort Key: t1.doc_kind
  • Sort Method: quicksort Memory: 3,240kB
  • Buffers: shared hit=742
3. 13.878 13.878 ↑ 1.0 36,348 1

Seq Scan on notifies t1 (cost=0.00..1,106.47 rows=36,367 width=2) (actual time=0.008..13.878 rows=36,348 loops=1)

  • Filter: (parent_id IS NULL)
  • Rows Removed by Filter: 75
  • Buffers: shared hit=742
4.          

SubPlan (for GroupAggregate)

5. 0.009 0.009 ↑ 1.0 1 1

Seq Scan on refdocnames (cost=0.00..1.02 rows=1 width=42) (actual time=0.008..0.009 rows=1 loops=1)

  • Filter: (t1.doc_kind = doc_kind)
  • Rows Removed by Filter: 4
  • Buffers: shared hit=1
6. 8.875 22.428 ↑ 1.0 1 1

Aggregate (cost=1,220.31..1,220.32 rows=1 width=8) (actual time=22.427..22.428 rows=1 loops=1)

  • Buffers: shared hit=742
7. 13.553 13.553 ↓ 4.0 36,348 1

Seq Scan on notifies t2 (cost=0.00..1,197.59 rows=9,090 width=0) (actual time=0.005..13.553 rows=36,348 loops=1)

  • Filter: (processed AND (parent_id IS NULL) AND (doc_kind = t1.doc_kind))
  • Rows Removed by Filter: 75
  • Buffers: shared hit=742
8. 0.002 0.009 ↑ 1.0 1 1

Aggregate (cost=8.45..8.46 rows=1 width=8) (actual time=0.008..0.009 rows=1 loops=1)

  • Buffers: shared hit=2
9. 0.007 0.007 ↓ 0.0 0 1

Index Scan using remd_notifies_processed_idx on notifies t2_1 (cost=0.29..8.45 rows=2 width=0) (actual time=0.007..0.007 rows=0 loops=1)

  • Index Cond: (processed = false)
  • Filter: ((parent_id IS NULL) AND (doc_kind = t1.doc_kind))
  • Buffers: shared hit=2
10. 0.004 4.680 ↑ 1.0 1 1

Aggregate (cost=1,197.59..1,197.60 rows=1 width=8) (actual time=4.679..4.680 rows=1 loops=1)

  • Buffers: shared hit=742
11. 4.676 4.676 ↑ 2.0 1 1

Seq Scan on notifies t2_2 (cost=0.00..1,197.59 rows=2 width=0) (actual time=3.269..4.676 rows=1 loops=1)

  • Filter: (processed AND (parent_id IS NULL) AND (NOT succeeded) AND (doc_kind = t1.doc_kind))
  • Rows Removed by Filter: 36,422
  • Buffers: shared hit=742
12. 0.004 480.291 ↑ 1.0 1 1

Aggregate (cost=4,419.09..4,419.10 rows=1 width=8) (actual time=480.279..480.291 rows=1 loops=1)

  • Buffers: shared hit=218,274
13. 41.377 480.287 ↓ 0.0 0 1

Hash Join (cost=1,311.24..4,389.91 rows=11,674 width=0) (actual time=480.275..480.287 rows=0 loops=1)

  • Hash Cond: (o1.parent_id = o2.id)
  • Join Filter: ((o1.async_response_status = ''::text) OR (o1.async_response_status IS NULL) OR ((o1.async_response_status = 'success'::text) AND ((SubPlan 5) IS NOT NULL)))
  • Rows Removed by Join Filter: 36,347
  • Buffers: shared hit=218,274
14. 18.933 18.933 ↑ 1.3 36,422 1

Seq Scan on demands o1 (cost=0.00..2,931.64 rows=47,651 width=11) (actual time=0.007..18.933 rows=36,422 loops=1)

  • Filter: (sync_response_status = 'success'::text)
  • Buffers: shared hit=2,336
15. 4.913 25.451 ↓ 4.0 36,348 1

Hash (cost=1,197.59..1,197.59 rows=9,092 width=4) (actual time=25.450..25.451 rows=36,348 loops=1)

  • Buckets: 65,536 (originally 16384) Batches: 1 (originally 1) Memory Usage: 1,790kB
  • Buffers: shared hit=742
16. 20.538 20.538 ↓ 4.0 36,348 1

Seq Scan on notifies o2 (cost=0.00..1,197.59 rows=9,092 width=4) (actual time=0.005..20.538 rows=36,348 loops=1)

  • Filter: ((parent_id IS NULL) AND (doc_kind = t1.doc_kind))
  • Rows Removed by Filter: 75
  • Buffers: shared hit=742
17.          

SubPlan (for Hash Join)

18. 143.464 394.526 ↓ 0.0 0 35,866

Limit (cost=9.14..21.93 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=35,866)

  • Buffers: shared hit=215,196
19. 0.000 251.062 ↓ 0.0 0 35,866

Nested Loop (cost=9.14..21.93 rows=1 width=4) (actual time=0.007..0.007 rows=0 loops=35,866)

  • Buffers: shared hit=215,196
20. 0.000 251.062 ↓ 0.0 0 35,866

Bitmap Heap Scan on demands o3 (cost=8.85..12.86 rows=1 width=4) (actual time=0.007..0.007 rows=0 loops=35,866)

  • Recheck Cond: ((async_response_status = ''::text) OR (async_response_status IS NULL))
  • Filter: (sync_response_status = 'success'::text)
  • Buffers: shared hit=215,196
21. 0.000 251.062 ↓ 0.0 0 35,866

BitmapOr (cost=8.85..8.85 rows=1 width=0) (actual time=0.007..0.007 rows=0 loops=35,866)

  • Buffers: shared hit=215,196
22. 179.330 179.330 ↓ 0.0 0 35,866

Bitmap Index Scan on remd_demands_async_response_status_idx (cost=0.00..4.42 rows=1 width=0) (actual time=0.005..0.005 rows=0 loops=35,866)

  • Index Cond: (async_response_status = ''::text)
  • Buffers: shared hit=107,598
23. 71.732 71.732 ↓ 0.0 0 35,866

Bitmap Index Scan on remd_demands_async_response_status_idx (cost=0.00..4.42 rows=1 width=0) (actual time=0.002..0.002 rows=0 loops=35,866)

  • Index Cond: (async_response_status IS NULL)
  • Buffers: shared hit=107,598
24. 0.000 0.000 ↓ 0.0 0

Index Only Scan using remd_notifies_id_parent_id_idx on notifies o4 (cost=0.29..8.31 rows=1 width=4) (never executed)

  • Index Cond: ((id = o3.parent_id) AND (parent_id = o2.id))
  • Heap Fetches: 0
25. 21.662 183,119.417 ↑ 1.0 1 1

Aggregate (cost=6,956,982.96..6,956,982.97 rows=1 width=8) (actual time=183,119.408..183,119.417 rows=1 loops=1)

  • Buffers: shared hit=221,713
26. 109,901.829 183,097.755 ↓ 618.4 35,866 1

Nested Loop (cost=0.58..6,956,982.81 rows=58 width=0) (actual time=25.367..183,097.755 rows=35,866 loops=1)

  • Join Filter: (o2_1.id = o1_1.parent_id)
  • Rows Removed by Join Filter: 1,306,347,602
  • Buffers: shared hit=221,713
27. 49.189 718.014 ↓ 807.7 36,348 1

Nested Loop Anti Join (cost=0.58..6,922,067.87 rows=45 width=4) (actual time=0.047..718.014 rows=36,348 loops=1)

  • Buffers: shared hit=219,377
28. 196.301 632.477 ↓ 807.7 36,348 1

Seq Scan on notifies o2_1 (cost=0.00..6,921,360.96 rows=45 width=4) (actual time=0.040..632.477 rows=36,348 loops=1)

  • Filter: ((parent_id IS NULL) AND (doc_kind = t1.doc_kind) AND ((SubPlan 7) = (SubPlan 8)))
  • Rows Removed by Filter: 75
  • Buffers: shared hit=146,397
29.          

SubPlan (for Seq Scan)

30. 36.348 363.480 ↑ 1.0 1 36,348

Aggregate (cost=165.26..165.27 rows=1 width=8) (actual time=0.010..0.010 rows=1 loops=36,348)

  • Buffers: shared hit=72,953
31. 145.242 327.132 ↓ 0.0 0 36,348

Nested Loop (cost=4.74..165.19 rows=26 width=0) (actual time=0.009..0.009 rows=0 loops=36,348)

  • Buffers: shared hit=72,953
32. 36.348 181.740 ↓ 0.0 0 36,348

Bitmap Heap Scan on notifies tt2 (cost=4.45..74.84 rows=20 width=4) (actual time=0.005..0.005 rows=0 loops=36,348)

  • Recheck Cond: (parent_id = o2_1.id)
  • Heap Blocks: exact=59
  • Buffers: shared hit=72,755
33. 145.392 145.392 ↓ 0.0 0 36,348

Bitmap Index Scan on remd_notifies_parent_id_idx (cost=0.00..4.44 rows=20 width=0) (actual time=0.004..0.004 rows=0 loops=36,348)

  • Index Cond: (parent_id = o2_1.id)
  • Buffers: shared hit=72,696
34. 0.150 0.150 ↑ 1.0 1 75

Index Only Scan using remd_demands_parent_id_idx on demands tt1 (cost=0.29..4.51 rows=1 width=4) (actual time=0.001..0.002 rows=1 loops=75)

  • Index Cond: (parent_id = tt2.id)
  • Heap Fetches: 47
  • Buffers: shared hit=198
35. 36.348 72.696 ↑ 1.0 1 36,348

Aggregate (cost=24.59..24.60 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=36,348)

  • Buffers: shared hit=72,702
36. 36.348 36.348 ↓ 0.0 0 36,348

Index Only Scan using remd_notifies_parent_id_idx on notifies tt3 (cost=0.29..24.54 rows=20 width=0) (actual time=0.001..0.001 rows=0 loops=36,348)

  • Index Cond: (parent_id = o2_1.id)
  • Heap Fetches: 5
  • Buffers: shared hit=72,702
37. 0.000 36.348 ↓ 0.0 0 36,348

Nested Loop (cost=0.58..15.70 rows=1 width=4) (actual time=0.001..0.001 rows=0 loops=36,348)

  • Buffers: shared hit=72,980
38. 36.348 36.348 ↓ 0.0 0 36,348

Index Scan using remd_notifies_parent_id_idx on notifies o4_1 (cost=0.29..7.78 rows=1 width=8) (actual time=0.001..0.001 rows=0 loops=36,348)

  • Index Cond: ((parent_id = o2_1.id) AND (parent_id IS NOT NULL))
  • Buffers: shared hit=72,755
39. 0.075 0.075 ↓ 0.0 0 75

Index Scan using remd_demands_parent_id_idx on demands o3_1 (cost=0.29..7.91 rows=1 width=4) (actual time=0.001..0.001 rows=0 loops=75)

  • Index Cond: (parent_id = o4_1.id)
  • Filter: ((sync_response_status IS NULL) OR (async_response_status IS NULL) OR (sync_response_status <> 'success'::text) OR (async_response_status <> 'success'::text))
  • Rows Removed by Filter: 1
  • Buffers: shared hit=225
40. 72,466.465 72,477.912 ↑ 1.3 35,941 36,348

Materialize (cost=0.00..3,285.92 rows=47,032 width=4) (actual time=0.000..1.994 rows=35,941 loops=36,348)

  • Buffers: shared hit=2,336
41. 11.447 11.447 ↑ 1.3 35,941 1

Seq Scan on demands o1_1 (cost=0.00..3,050.76 rows=47,032 width=4) (actual time=0.006..11.447 rows=35,941 loops=1)

  • Filter: ((sync_response_status = 'success'::text) AND (async_response_status = 'success'::text))
  • Rows Removed by Filter: 481
  • Buffers: shared hit=2,336
42. 0.073 256.015 ↑ 1.0 1 1

Aggregate (cost=2,208,873.16..2,208,873.17 rows=1 width=8) (actual time=256.007..256.015 rows=1 loops=1)

  • Buffers: shared hit=181,801
43. 23.472 255.942 ↑ 12.5 481 1

Nested Loop (cost=0.29..2,208,858.11 rows=6,021 width=0) (actual time=0.032..255.942 rows=481 loops=1)

  • Buffers: shared hit=181,801
44. 14.382 14.382 ↓ 4.0 36,348 1

Seq Scan on notifies t3 (cost=0.00..1,197.59 rows=9,092 width=4) (actual time=0.008..14.382 rows=36,348 loops=1)

  • Filter: ((parent_id IS NULL) AND (doc_kind = t1.doc_kind))
  • Rows Removed by Filter: 75
  • Buffers: shared hit=742
45. 74.624 218.088 ↓ 0.0 0 36,348

Index Scan using remd_demands_parent_id_idx on demands t2_3 (cost=0.29..242.80 rows=1 width=4) (actual time=0.006..0.006 rows=0 loops=36,348)

  • Index Cond: (parent_id = t3.id)
  • Filter: ((sync_response_status = 'error'::text) OR (async_response_status = 'error'::text) OR (alternatives: SubPlan 10 or hashed SubPlan 11))
  • Rows Removed by Filter: 1
  • Buffers: shared hit=181,059
46.          

SubPlan (for Index Scan)

47. 71.582 143.464 ↓ 0.0 0 35,866

Nested Loop (cost=4.74..241.29 rows=1 width=0) (actual time=0.004..0.004 rows=0 loops=35,866)

  • Buffers: shared hit=72,016
48. 35.866 71.732 ↓ 0.0 0 35,866

Bitmap Heap Scan on notifies tt2_1 (cost=4.45..74.84 rows=20 width=4) (actual time=0.002..0.002 rows=0 loops=35,866)

  • Recheck Cond: (parent_id = t2_3.parent_id)
  • Heap Blocks: exact=59
  • Buffers: shared hit=71,791
49. 35.866 35.866 ↓ 0.0 0 35,866

Bitmap Index Scan on remd_notifies_parent_id_idx (cost=0.00..4.44 rows=20 width=0) (actual time=0.001..0.001 rows=0 loops=35,866)

  • Index Cond: (parent_id = t2_3.parent_id)
  • Buffers: shared hit=71,732
50. 0.150 0.150 ↓ 0.0 0 75

Index Scan using remd_demands_parent_id_idx on demands tt1_1 (cost=0.29..8.31 rows=1 width=4) (actual time=0.002..0.002 rows=0 loops=75)

  • Index Cond: (parent_id = tt2_1.id)
  • Filter: ((sync_response_status = 'error'::text) OR (async_response_status = 'error'::text))
  • Rows Removed by Filter: 1
  • Buffers: shared hit=225
51. 0.000 0.000 ↓ 0.0 0

Nested Loop (cost=34.08..2,603.33 rows=619 width=4) (never executed)

52. 0.000 0.000 ↓ 0.0 0

Bitmap Heap Scan on demands tt1_2 (cost=33.79..1,436.99 rows=619 width=4) (never executed)

  • Recheck Cond: ((sync_response_status = 'error'::text) OR (async_response_status = 'error'::text))
53. 0.000 0.000 ↓ 0.0 0

BitmapOr (cost=33.79..33.79 rows=619 width=0) (never executed)

54. 0.000 0.000 ↓ 0.0 0

Bitmap Index Scan on remd_demands_response_status_idx (cost=0.00..4.42 rows=1 width=0) (never executed)

  • Index Cond: (sync_response_status = 'error'::text)
55. 0.000 0.000 ↓ 0.0 0

Bitmap Index Scan on remd_demands_async_response_status_idx (cost=0.00..29.06 rows=619 width=0) (never executed)

  • Index Cond: (async_response_status = 'error'::text)
56. 0.000 0.000 ↓ 0.0 0

Index Only Scan using remd_notifies_id_parent_id_idx on notifies tt2_2 (cost=0.29..1.88 rows=1 width=8) (never executed)

  • Index Cond: (id = tt1_2.parent_id)
  • Heap Fetches: 0
57. 2.056 72.529 ↑ 1.0 1 1

Aggregate (cost=6,295.60..6,295.61 rows=1 width=8) (actual time=72.523..72.529 rows=1 loops=1)

  • Buffers: shared hit=3,601
58. 3.988 70.473 ↓ 4.2 35,866 1

Hash Anti Join (cost=5,608.92..6,274.40 rows=8,481 width=0) (actual time=52.750..70.473 rows=35,866 loops=1)

  • Hash Cond: (o1_2.id = o3_2.parent_id)
  • Buffers: shared hit=3,601
59. 7.351 66.454 ↓ 4.2 35,866 1

Hash Join (cost=5,587.71..6,146.11 rows=8,481 width=4) (actual time=52.711..66.454 rows=35,866 loops=1)

  • Hash Cond: (o4_2.parent_id = o1_2.id)
  • Buffers: shared hit=3,593
60. 18.513 21.761 ↓ 1.0 35,866 1

HashAggregate (cost=955.58..1,300.01 rows=34,443 width=4) (actual time=15.277..21.761 rows=35,866 loops=1)

  • Group Key: o4_2.parent_id
  • Buffers: shared hit=515
61. 3.248 3.248 ↓ 1.0 36,554 1

Seq Scan on chunks o4_2 (cost=0.00..867.46 rows=35,246 width=4) (actual time=0.010..3.248 rows=36,554 loops=1)

  • Buffers: shared hit=515
62. 5.979 37.342 ↓ 3.1 35,866 1

Hash (cost=4,485.47..4,485.47 rows=11,733 width=4) (actual time=37.341..37.342 rows=35,866 loops=1)

  • Buckets: 65,536 (originally 16384) Batches: 1 (originally 1) Memory Usage: 1,773kB
  • Buffers: shared hit=3,078
63. 6.948 31.363 ↓ 3.1 35,866 1

Hash Join (cost=1,311.24..4,485.47 rows=11,733 width=4) (actual time=13.954..31.363 rows=35,866 loops=1)

  • Hash Cond: (o1_2.parent_id = o2_2.id)
  • Buffers: shared hit=3,078
64. 10.559 10.559 ↑ 1.3 35,941 1

Seq Scan on demands o1_2 (cost=0.00..3,050.76 rows=47,032 width=8) (actual time=0.009..10.559 rows=35,941 loops=1)

  • Filter: ((sync_response_status = 'success'::text) AND (async_response_status = 'success'::text))
  • Rows Removed by Filter: 481
  • Buffers: shared hit=2,336
65. 5.808 13.856 ↓ 4.0 36,348 1

Hash (cost=1,197.59..1,197.59 rows=9,092 width=4) (actual time=13.856..13.856 rows=36,348 loops=1)

  • Buckets: 65,536 (originally 16384) Batches: 1 (originally 1) Memory Usage: 1,790kB
  • Buffers: shared hit=742
66. 8.048 8.048 ↓ 4.0 36,348 1

Seq Scan on notifies o2_2 (cost=0.00..1,197.59 rows=9,092 width=4) (actual time=0.014..8.048 rows=36,348 loops=1)

  • Filter: ((parent_id IS NULL) AND (doc_kind = t1.doc_kind))
  • Rows Removed by Filter: 75
  • Buffers: shared hit=742
67. 0.001 0.031 ↓ 0.0 0 1

Hash (cost=21.20..21.20 rows=1 width=4) (actual time=0.030..0.031 rows=0 loops=1)

  • Buckets: 1,024 Batches: 1 Memory Usage: 8kB
  • Buffers: shared hit=8
68. 0.001 0.030 ↓ 0.0 0 1

Bitmap Heap Scan on chunks o3_2 (cost=17.19..21.20 rows=1 width=4) (actual time=0.030..0.030 rows=0 loops=1)

  • Recheck Cond: ((NOT sent) OR (NOT confirmed) OR (sent IS NULL) OR (confirmed IS NULL))
  • Filter: ((NOT sent) OR (NOT confirmed) OR (sent IS NULL) OR (confirmed IS NULL))
  • Buffers: shared hit=8
69. 0.001 0.029 ↓ 0.0 0 1

BitmapOr (cost=17.19..17.19 rows=1 width=0) (actual time=0.028..0.029 rows=0 loops=1)

  • Buffers: shared hit=8
70. 0.012 0.012 ↓ 0.0 0 1

Bitmap Index Scan on remd_chunks_sent_idx (cost=0.00..4.30 rows=1 width=0) (actual time=0.012..0.012 rows=0 loops=1)

  • Index Cond: (sent = false)
  • Buffers: shared hit=2
71. 0.005 0.005 ↓ 0.0 0 1

Bitmap Index Scan on remd_chunks_confirmed_idx (cost=0.00..4.30 rows=1 width=0) (actual time=0.005..0.005 rows=0 loops=1)

  • Index Cond: (confirmed = false)
  • Buffers: shared hit=2
72. 0.008 0.008 ↓ 0.0 0 1

Bitmap Index Scan on remd_chunks_sent_idx (cost=0.00..4.30 rows=1 width=0) (actual time=0.008..0.008 rows=0 loops=1)

  • Index Cond: (sent IS NULL)
  • Buffers: shared hit=2
73. 0.003 0.003 ↓ 0.0 0 1

Bitmap Index Scan on remd_chunks_confirmed_idx (cost=0.00..4.30 rows=1 width=0) (actual time=0.003..0.003 rows=0 loops=1)

  • Index Cond: (confirmed IS NULL)
  • Buffers: shared hit=2
Planning time : 3.614 ms
Execution time : 183,990.105 ms