explain.depesz.com

PostgreSQL's explain analyze made readable

Result: DXOC

Settings
# exclusive inclusive rows x rows loops node
1. 108.681 4,435.258 ↓ 1.0 6,671 1

Sort (cost=929,446.59..929,462.60 rows=6,403 width=66) (actual time=4,428.088..4,435.258 rows=6,671 loops=1)

  • Sort Key: users.username
  • Sort Method: external merge Disk: 4,816kB
  • Execution time: 4,439.015 ms(41 rows
2. 97.163 4,326.577 ↓ 1.0 6,671 1

Seq Scan on users (cost=0.00..929,041.77 rows=6,403 width=66) (actual time=0.039..4,326.577 rows=6,671 loops=1)

3.          

SubPlan (for Seq Scan)

4. 15.573 126.749 ↑ 2.0 1 6,671

Result (cost=0.66..8.69 rows=2 width=794) (actual time=0.018..0.019 rows=1 loops=6,671)

  • One-Time Filter: users.is_active
5. 111.176 111.176 ↑ 2.0 1 4,276

Index Only Scan using u__ssh_keys__username_key on ssh_keys (cost=0.66..8.69 rows=2 width=794) (actual time=0.025..0.026 rows=1 loops=4,276)

  • Index Cond: (username = (users.username)::text)
  • Heap Fetches: 1,876
6. 406.931 4,102.665 ↑ 33.3 6 6,671

Sort (cost=135.87..136.37 rows=200 width=274) (actual time=0.610..0.615 rows=6 loops=6,671)

  • Sort Key: all_groups_1.parent_groupname
  • Sort Method: quicksort Memory: 25kB
7.          

CTE all_groups

8. 136.997 1,274.161 ↑ 81.0 6 6,671

Recursive Union (cost=4.46..76.78 rows=486 width=23) (actual time=0.033..0.191 rows=6 loops=6,671)

9. 67.410 306.866 ↑ 1.2 5 6,671

Result (cost=4.46..26.16 rows=6 width=17) (actual time=0.025..0.046 rows=5 loops=6,671)

  • One-Time Filter: users.is_active
10. 111.176 239.456 ↓ 1.3 8 4,276

Bitmap Heap Scan on group_memberships (cost=4.46..26.16 rows=6 width=17) (actual time=0.036..0.056 rows=8 loops=4,276)

  • Recheck Cond: ((username)::text = (users.username)::text)
  • Heap Blocks: exact=27,912
11. 128.280 128.280 ↓ 1.3 8 4,276

Bitmap Index Scan on group_memberships_pkey (cost=0.00..4.46 rows=6 width=0) (actual time=0.030..0.030 rows=8 loops=4,276)

  • Index Cond: ((username)::text = (users.username)::text)
12. 415.460 830.298 ↑ 48.0 1 7,833

Hash Join (cost=1.95..4.09 rows=48 width=23) (actual time=0.100..0.106 rows=1 loops=7,833)

  • Hash Cond: ((gd.groupname)::text = (all_groups.parent_groupname)::text)
13. 320.842 320.842 ↓ 1.3 62 5,438

Seq Scan on group_delegations gd (cost=0.00..1.48 rows=48 width=44) (actual time=0.012..0.059 rows=62 loops=5,438)

14. 70.497 93.996 ↑ 12.0 5 7,833

Hash (cost=1.20..1.20 rows=60 width=274) (actual time=0.012..0.012 rows=5 loops=7,833)

  • Buckets: 1,024 Batches: 1 Memory Usage: 9kB
15. 23.499 23.499 ↑ 12.0 5 7,833

WorkTable Scan on all_groups (cost=0.00..1.20 rows=60 width=274) (actual time=0.000..0.003 rows=5 loops=7,833)

16. 166.775 3,695.734 ↑ 33.3 6 6,671

HashAggregate (cost=49.44..51.44 rows=200 width=274) (actual time=0.547..0.554 rows=6 loops=6,671)

  • Group Key: all_groups_1.parent_groupname
17. 157.791 3,528.959 ↑ 40.5 6 6,671

Hash Anti Join (cost=35.14..48.84 rows=243 width=274) (actual time=0.347..0.529 rows=6 loops=6,671)

  • Hash Cond: ((all_groups_1.parent_groupname)::text = (disabled_memberships.groupname)::text)
18. 1,387.568 1,387.568 ↑ 81.0 6 6,671

CTE Scan on all_groups all_groups_1 (cost=0.00..9.72 rows=486 width=274) (actual time=0.037..0.208 rows=6 loops=6,671)

19. 25.650 1,983.600 ↓ 0.0 0 4,275

Hash (cost=35.12..35.12 rows=1 width=18) (actual time=0.464..0.464 rows=0 loops=4,275)

  • Buckets: 1,024 Batches: 1 Memory Usage: 8kB
20. 1,957.950 1,957.950 ↓ 0.0 0 4,275

Seq Scan on disabled_memberships (cost=0.00..35.12 rows=1 width=18) (actual time=0.419..0.458 rows=0 loops=4,275)

  • Filter: ((username)::text = (users.username)::text)
  • Rows Removed by Filter: 1,033
Planning time : 0.493 ms