explain.depesz.com

PostgreSQL's explain analyze made readable

Result: vrhd : Optimization for: plan #4BC2

Settings

Optimization path:

# exclusive inclusive rows x rows loops node
1. 542.877 3,923.445 ↑ 4.6 3,109 1

Hash Anti Join (cost=166.51..56,081.49 rows=14,147 width=1,326) (actual time=594.428..3,923.445 rows=3,109 loops=1)

  • Hash Cond: ((t.job_id)::text = (completed.job_id)::text)
  • Buffers: shared hit=277,090 read=114,270 dirtied=1
  • I/O Timings: read=934.822
2.          

CTE started

3. 10.282 10.282 ↓ 210.1 4,622 1

Index Scan using idx_entity_op_created on ticket (cost=0.56..46.78 rows=22 width=37) (actual time=0.046..10.282 rows=4,622 loops=1)

  • Index Cond: (((op_type)::text = 'SDD_SNAPSHOT'::text) AND ((entity_id)::text = 'sdb-services-test10:sdb17'::text))
  • Buffers: shared hit=3,521 read=1,100
  • I/O Timings: read=3.527
4.          

CTE completed

5. 19.368 19.368 ↓ 219.8 4,615 1

Index Scan using idx_entity_op_created on ticket ticket_1 (cost=0.56..45.01 rows=21 width=37) (actual time=0.066..19.368 rows=4,615 loops=1)

  • Index Cond: (((op_type)::text = 'SDD_COPY_EXTENT_COMPLETE'::text) AND ((entity_id)::text = 'sdb-services-test10:sdb17'::text))
  • Filter: ((status)::text = ANY ('{COMPLETED,ABORT}'::text[]))
  • Buffers: shared hit=3,308 read=1,397
  • I/O Timings: read=11.494
6. 1,110.928 3,358.006 ↓ 150.6 2,134,099 1

Nested Loop (cost=74.04..55,810.33 rows=14,171 width=1,326) (actual time=14.778..3,358.006 rows=2,134,099 loops=1)

  • Buffers: shared hit=273,782 read=112,873 dirtied=1
  • I/O Timings: read=923.328
7. 6.965 19.274 ↓ 210.1 4,622 1

HashAggregate (cost=0.49..0.71 rows=22 width=516) (actual time=14.631..19.274 rows=4,622 loops=1)

  • Group Key: (started.job_id)::text
  • Buffers: shared hit=3,521 read=1,100
  • I/O Timings: read=3.527
8. 12.309 12.309 ↓ 210.1 4,622 1

CTE Scan on started (cost=0.00..0.44 rows=22 width=516) (actual time=0.049..12.309 rows=4,622 loops=1)

  • Buffers: shared hit=3,521 read=1,100
  • I/O Timings: read=3.527
9. 1,650.054 2,227.804 ↑ 1.4 462 4,622

Bitmap Heap Scan on ticket t (cost=73.55..2,530.36 rows=644 width=1,326) (actual time=0.136..0.482 rows=462 loops=4,622)

  • Recheck Cond: ((job_id)::text = (started.job_id)::text)
  • Heap Blocks: exact=311,450
  • Buffers: shared hit=270,261 read=111,773 dirtied=1
  • I/O Timings: read=919.801
10. 577.750 577.750 ↑ 1.4 465 4,622

Bitmap Index Scan on idx_job_op (cost=0.00..73.39 rows=644 width=0) (actual time=0.125..0.125 rows=465 loops=4,622)

  • Index Cond: ((job_id)::text = (started.job_id)::text)
  • Buffers: shared hit=12,856 read=57,728
  • I/O Timings: read=202.800
11. 1.227 22.562 ↓ 219.8 4,615 1

Hash (cost=0.42..0.42 rows=21 width=516) (actual time=22.562..22.562 rows=4,615 loops=1)

  • Buckets: 8,192 (originally 1024) Batches: 1 (originally 1) Memory Usage: 375kB
  • Buffers: shared hit=3,308 read=1,397
  • I/O Timings: read=11.494
12. 21.335 21.335 ↓ 219.8 4,615 1

CTE Scan on completed (cost=0.00..0.42 rows=21 width=516) (actual time=0.068..21.335 rows=4,615 loops=1)

  • Buffers: shared hit=3,308 read=1,397
  • I/O Timings: read=11.494
Planning time : 0.363 ms
Execution time : 3,924.061 ms