explain.depesz.com

PostgreSQL's explain analyze made readable

Result: IVxj

Settings
# exclusive inclusive rows x rows loops node
1. 10.779 13,580.584 ↓ 6,486.0 6,486 1

Sort (cost=70,587.78..70,587.78 rows=1 width=993) (actual time=13,577.011..13,580.584 rows=6,486 loops=1)

  • Sort Key: (sum(anon_1.count)) DESC
  • Sort Method: quicksort Memory: 3,745kB
  • Buffers: shared hit=91,115 read=26,667 written=2,119, temp read=50,208 written=50,288
2. 49.592 13,569.805 ↓ 6,486.0 6,486 1

GroupAggregate (cost=70,587.73..70,587.77 rows=1 width=993) (actual time=13,418.986..13,569.805 rows=6,486 loops=1)

  • Group Key: anon_1.srvid, anon_1.queryid, powa_statements.query, anon_1.event_type, anon_1.event
  • Buffers: shared hit=91,115 read=26,667 written=2,119, temp read=50,208 written=50,288
3. 390.458 13,520.213 ↓ 22,849.0 22,849 1

Sort (cost=70,587.73..70,587.74 rows=1 width=969) (actual time=13,418.957..13,520.213 rows=22,849 loops=1)

  • Sort Key: anon_1.srvid, anon_1.queryid, powa_statements.query, anon_1.event_type, anon_1.event
  • Sort Method: external merge Disk: 10,432kB
  • Buffers: shared hit=85,139 read=26,667 written=2,119, temp read=50,208 written=50,288
4. 127.134 13,129.755 ↓ 22,849.0 22,849 1

Hash Join (cost=46,391.40..70,587.72 rows=1 width=969) (actual time=13,006.338..13,129.755 rows=22,849 loops=1)

  • Hash Cond: ((powa_statements.queryid = anon_1.queryid) AND (powa_statements.dbid = anon_1.dbid))
  • Buffers: shared hit=8,605 read=26,648 written=2,119, temp read=48,904 written=48,981
5. 143.433 143.433 ↑ 1.0 168,361 1

Seq Scan on powa_statements (cost=0.00..22,933.61 rows=168,361 width=942) (actual time=0.019..143.433 rows=168,361 loops=1)

  • Buffers: shared hit=2,600 read=18,650
6. 5.177 12,859.188 ↓ 91.0 6,100 1

Hash (cost=46,390.39..46,390.39 rows=67 width=43) (actual time=12,859.188..12,859.188 rows=6,100 loops=1)

  • Buckets: 8,192 (originally 1024) Batches: 1 (originally 1) Memory Usage: 563kB
  • Buffers: shared hit=6,005 read=7,998 written=2,119, temp read=48,904 written=48,981
7. 7.248 12,854.011 ↓ 91.0 6,100 1

Subquery Scan on anon_1 (cost=46,379.76..46,390.39 rows=67 width=43) (actual time=10,405.770..12,854.011 rows=6,100 loops=1)

  • Buffers: shared hit=6,005 read=7,998 written=2,119, temp read=48,904 written=48,981
8. 1,109.936 12,846.763 ↓ 91.0 6,100 1

GroupAggregate (cost=46,379.76..46,389.72 rows=67 width=107) (actual time=10,405.768..12,846.763 rows=6,100 loops=1)

  • Group Key: powa_databases.srvid, "*SELECT* 1".queryid, "*SELECT* 1".dbid, powa_databases.datname, "*SELECT* 1".event_type, "*SELECT* 1".event
  • Filter: ((max("*SELECT* 1".count) - min("*SELECT* 1".count)) > 0)
  • Rows Removed by Filter: 2,037
  • Buffers: shared hit=6,005 read=7,998 written=2,119, temp read=48,904 written=48,981
9. 3,658.261 11,736.827 ↓ 6,012.0 1,484,965 1

Sort (cost=46,379.76..46,380.38 rows=247 width=107) (actual time=10,405.348..11,736.827 rows=1,484,965 loops=1)

  • Sort Key: "*SELECT* 1".queryid, "*SELECT* 1".dbid, "*SELECT* 1".event_type, "*SELECT* 1".event
  • Sort Method: external merge Disk: 180,944kB
  • Buffers: shared hit=6,005 read=7,998 written=2,119, temp read=48,904 written=48,981
10. 1,662.638 8,078.566 ↓ 6,012.0 1,484,965 1

Nested Loop (cost=5,886.01..46,369.94 rows=247 width=107) (actual time=96.378..8,078.566 rows=1,484,965 loops=1)

  • Buffers: shared hit=6,005 read=7,998 written=2,119
11. 0.015 0.015 ↑ 1.0 1 1

Seq Scan on powa_databases (cost=0.00..2.05 rows=1 width=72) (actual time=0.013..0.015 rows=1 loops=1)

  • Filter: ((srvid = 14) AND (datname = 'VCDB'::name))
  • Rows Removed by Filter: 69
  • Buffers: shared hit=1
12. 1,598.572 6,415.913 ↓ 6,012.0 1,484,965 1

Append (cost=5,886.01..46,365.42 rows=247 width=39) (actual time=96.361..6,415.913 rows=1,484,965 loops=1)

  • Buffers: shared hit=6,004 read=7,998 written=2,119
13. 1,262.834 3,509.979 ↓ 160,605.6 1,124,239 1

Subquery Scan on *SELECT* 1 (cost=5,886.01..6,662.78 rows=7 width=39) (actual time=96.359..3,509.979 rows=1,124,239 loops=1)

  • Buffers: shared hit=1,166 read=1,781
14. 1,349.820 2,247.145 ↓ 160,605.6 1,124,239 1

Subquery Scan on unnested (cost=5,886.01..6,662.71 rows=7 width=47) (actual time=96.357..2,247.145 rows=1,124,239 loops=1)

  • Filter: ((unnested.records).ts <@ '["2020-06-23 05:00:23+00","2020-06-25 22:00:00+00"]'::tstzrange)
  • Buffers: shared hit=1,166 read=1,781
15. 765.736 897.325 ↓ 803.0 1,124,239 1

ProjectSet (cost=5,886.01..6,645.21 rows=1,400 width=95) (actual time=96.352..897.325 rows=1,124,239 loops=1)

  • Buffers: shared hit=1,166 read=1,781
16. 16.517 131.589 ↓ 864.6 12,104 1

Hash Semi Join (cost=5,886.01..6,638.10 rows=14 width=847) (actual time=96.345..131.589 rows=12,104 loops=1)

  • Hash Cond: (wsh.queryid = ps.queryid)
  • Buffers: shared hit=1,166 read=1,781
17. 18.953 22.314 ↓ 864.6 12,104 1

Bitmap Heap Scan on powa_wait_sampling_history wsh (cost=14.34..765.37 rows=14 width=847) (actual time=3.561..22.314 rows=12,104 loops=1)

  • Recheck Cond: ((srvid = 14) AND (coalesce_range && '["2020-06-23 05:00:23+00","2020-06-25 22:00:00+00"]'::tstzrange))
  • Filter: (dbid = powa_databases.oid)
  • Rows Removed by Filter: 472
  • Heap Blocks: exact=1,699
  • Buffers: shared hit=83 read=1,781
18. 3.361 3.361 ↓ 65.2 12,576 1

Bitmap Index Scan on powa_wait_sampling_history_query_ts (cost=0.00..14.34 rows=193 width=0) (actual time=3.361..3.361 rows=12,576 loops=1)

  • Index Cond: ((srvid = 14) AND (coalesce_range && '["2020-06-23 05:00:23+00","2020-06-25 22:00:00+00"]'::tstzrange))
  • Buffers: shared read=165
19. 44.894 92.758 ↓ 6.2 69,590 1

Hash (cost=5,731.37..5,731.37 rows=11,224 width=8) (actual time=92.757..92.758 rows=69,590 loops=1)

  • Buckets: 131,072 (originally 16384) Batches: 1 (originally 1) Memory Usage: 3,743kB
  • Buffers: shared hit=1,083
20. 47.864 47.864 ↓ 6.2 69,590 1

Index Only Scan using powa_statements_pkey on powa_statements ps (cost=0.42..5,731.37 rows=11,224 width=8) (actual time=2.875..47.864 rows=69,590 loops=1)

  • Index Cond: (dbid = powa_databases.oid)
  • Heap Fetches: 0
  • Buffers: shared hit=1,083
21. 401.349 1,307.362 ↓ 1,503.0 360,726 1

Subquery Scan on *SELECT* 2 (cost=5,872.10..39,701.41 rows=240 width=39) (actual time=93.062..1,307.362 rows=360,726 loops=1)

  • Buffers: shared hit=4,838 read=6,217 written=2,119
22. 473.607 906.013 ↓ 1,503.0 360,726 1

Hash Semi Join (cost=5,872.10..39,699.01 rows=240 width=47) (actual time=93.060..906.013 rows=360,726 loops=1)

  • Hash Cond: (wsc.queryid = ps_1.queryid)
  • Buffers: shared hit=4,838 read=6,217 written=2,119
23. 339.410 339.410 ↓ 1,503.0 360,726 1

Index Scan using powa_wait_sampling_history_current_srvid_idx on powa_wait_sampling_history_current wsc (cost=0.43..33,809.05 rows=240 width=68) (actual time=0.033..339.410 rows=360,726 loops=1)

  • Index Cond: (srvid = 14)
  • Filter: (((record).ts <@ '["2020-06-23 05:00:23+00","2020-06-25 22:00:00+00"]'::tstzrange) AND (dbid = powa_databases.oid))
  • Rows Removed by Filter: 15,138
  • Buffers: shared hit=3,755 read=6,217 written=2,119
24. 45.119 92.996 ↓ 6.2 69,590 1

Hash (cost=5,731.37..5,731.37 rows=11,224 width=8) (actual time=92.996..92.996 rows=69,590 loops=1)

  • Buckets: 131,072 (originally 16384) Batches: 1 (originally 1) Memory Usage: 3,743kB
  • Buffers: shared hit=1,083
25. 47.877 47.877 ↓ 6.2 69,590 1

Index Only Scan using powa_statements_pkey on powa_statements ps_1 (cost=0.42..5,731.37 rows=11,224 width=8) (actual time=2.928..47.877 rows=69,590 loops=1)

  • Index Cond: (dbid = powa_databases.oid)
  • Heap Fetches: 0
  • Buffers: shared hit=1,083
Planning time : 1.185 ms
Execution time : 13,607.790 ms