explain.depesz.com

PostgreSQL's explain analyze made readable

Result: NnMd : Second run in session

Settings

Optimization path:

# exclusive inclusive rows x rows loops node
1. 0.001 70,474.925 ↓ 0.0 0 1

Limit (cost=594,396.70..594,402.70 rows=50 width=11,599) (actual time=70,474.925..70,474.925 rows=0 loops=1)

  • Buffers: shared hit=13,144,283 read=5,129,276 dirtied=6,519 written=55,963, temp read=28,274 written=28,274
2. 0.001 70,474.924 ↓ 0.0 0 1

Unique (cost=594,396.70..594,405.34 rows=72 width=11,599) (actual time=70,474.924..70,474.924 rows=0 loops=1)

  • Buffers: shared hit=13,144,283 read=5,129,276 dirtied=6,519 written=55,963, temp read=28,274 written=28,274
3. 0.083 70,474.923 ↓ 0.0 0 1

Sort (cost=594,396.70..594,396.88 rows=72 width=11,599) (actual time=70,474.923..70,474.923 rows=0 loops=1)

  • Sort Key: (collkey((users.sortable_name)::text, 'root'::text, false, 3, true)), users.id, users.name, users.sortable_name, users.workflow_state, users.time_zone, users.uuid, users.created_at, users.updated_at, users.avatar_image_url, users.avatar_image_source, users.avatar_image_updated_at, users.phone, users.school_name, users.school_position, users.short_name, users.deleted_at, users.show_user_services, users.gender, users.page_views_count, users.reminder_time_for_due_dates, users.reminder_time_for_grading, users.storage_quota, users.visible_inbox_types, users.last_user_note, users.subscribe_to_emails, users.features_used, users.preferences, users.avatar_state, users.locale, users.browser_locale, users.unread_conversations_count, users.stuck_sis_fields, users.public, users.birthdate, users.otp_secret_key_enc, users.otp_secret_key_salt, users.otp_communication_channel_id, users.initial_enrollment_type, users.crocodoc_id, users.registration_remote_ip, users.last_logged_out, users.country_code, users.lti_context_id, users.turnitin_id, users.lti_id, (max(pseudonyms.current_login_at))
  • Sort Method: quicksort Memory: 25kB
  • Buffers: shared hit=13,144,283 read=5,129,276 dirtied=6,519 written=55,963, temp read=28,274 written=28,274
4. 158.912 70,474.840 ↓ 0.0 0 1

Nested Loop (cost=403,538.56..594,394.48 rows=72 width=11,599) (actual time=70,474.840..70,474.840 rows=0 loops=1)

  • Buffers: shared hit=13,144,283 read=5,129,276 dirtied=6,519 written=55,963, temp read=28,274 written=28,274
5. 349.596 15,410.366 ↓ 11.4 345,318 1

Nested Loop (cost=403,538.12..453,270.64 rows=30,315 width=11,607) (actual time=12,819.372..15,410.366 rows=345,318 loops=1)

  • Buffers: shared hit=5,315,523 read=404,996 dirtied=3,958 written=5,485, temp read=28,274 written=28,274
6. 208.578 13,334.180 ↓ 17.3 345,318 1

Unique (cost=403,537.69..405,878.41 rows=19,921 width=3,436) (actual time=12,819.293..13,334.180 rows=345,318 loops=1)

  • Buffers: shared hit=4,223,930 read=375,776 dirtied=3,958 written=5,157, temp read=28,274 written=28,274
7. 1,253.620 13,125.602 ↓ 17.3 345,513 1

Sort (cost=403,537.69..403,587.49 rows=19,921 width=3,436) (actual time=12,819.289..13,125.602 rows=345,513 loops=1)

  • Sort Key: users.id, users.name, users.sortable_name, users.workflow_state, users.time_zone, users.uuid, users.created_at, users.updated_at, users.avatar_image_url, users.avatar_image_source, users.avatar_image_updated_at, users.phone, users.school_name, users.school_position, users.short_name, users.deleted_at, users.show_user_services, users.gender, users.page_views_count, users.reminder_time_for_due_dates, users.reminder_time_for_grading, users.storage_quota, users.visible_inbox_types, users.last_user_note, users.subscribe_to_emails, users.features_used, users.preferences, users.avatar_state, users.locale, users.browser_locale, users.unread_conversations_count, users.stuck_sis_fields, users.public, users.birthdate, users.otp_secret_key_enc, users.otp_secret_key_salt, users.otp_communication_channel_id, users.initial_enrollment_type, users.crocodoc_id, users.registration_remote_ip, users.last_logged_out, users.country_code, users.lti_context_id, users.turnitin_id, users.lti_id, (max(pseudonyms.current_login_at))
  • Sort Method: external sort Disk: 226,192kB
  • Buffers: shared hit=4,223,930 read=375,776 dirtied=3,958 written=5,157, temp read=28,274 written=28,274
8. 67.831 11,871.982 ↓ 17.3 345,513 1

Append (cost=764.10..384,845.93 rows=19,921 width=3,436) (actual time=198.562..11,871.982 rows=345,513 loops=1)

  • Buffers: shared hit=4,223,930 read=375,776 dirtied=3,958 written=5,157
9. 0.017 198.562 ↑ 5.0 1 1

HashAggregate (cost=764.10..764.15 rows=5 width=3,436) (actual time=198.562..198.562 rows=1 loops=1)

  • Group Key: users.id
  • Buffers: shared hit=436 read=876 written=19
10. 0.004 198.545 ↑ 5.0 1 1

Nested Loop Left Join (cost=330.88..764.08 rows=5 width=3,436) (actual time=198.025..198.545 rows=1 loops=1)

  • Buffers: shared hit=436 read=876 written=19
11. 0.006 198.511 ↑ 5.0 1 1

Nested Loop (cost=330.46..750.79 rows=5 width=3,428) (actual time=197.992..198.511 rows=1 loops=1)

  • Buffers: shared hit=433 read=875 written=19
12. 0.652 198.485 ↑ 30.0 1 1

Bitmap Heap Scan on users (cost=330.03..660.75 rows=30 width=3,428) (actual time=197.966..198.485 rows=1 loops=1)

  • Recheck Cond: (lower((name)::text) ~~ '%@students.ocps.net%'::text)
  • Filter: (((workflow_state)::text <> 'deleted'::text) AND ((workflow_state)::text <> 'deleted'::text))
  • Rows Removed by Filter: 145
  • Heap Blocks: exact=33
  • Buffers: shared hit=429 read=875 written=19
13. 197.833 197.833 ↑ 2.0 146 1

Bitmap Index Scan on index_gin_trgm_users_name (cost=0.00..330.02 rows=296 width=0) (actual time=197.833..197.833 rows=146 loops=1)

  • Index Cond: (lower((name)::text) ~~ '%@students.ocps.net%'::text)
  • Buffers: shared hit=429 read=842 written=17
14. 0.020 0.020 ↑ 2.0 1 1

Index Only Scan using index_user_account_associations_on_user_id_and_account_id on user_account_associations user_account_associations_1 (cost=0.43..2.98 rows=2 width=8) (actual time=0.020..0.020 rows=1 loops=1)

  • Index Cond: ((user_id = users.id) AND (account_id = 557))
  • Heap Fetches: 0
  • Buffers: shared hit=4
15. 0.030 0.030 ↑ 1.0 1 1

Index Scan using index_pseudonyms_on_user_id on pseudonyms (cost=0.42..2.65 rows=1 width=16) (actual time=0.029..0.030 rows=1 loops=1)

  • Index Cond: (user_id = users.id)
  • Filter: ((account_id = '557'::bigint) AND ((workflow_state)::text = 'active'::text))
  • Buffers: shared hit=3 read=1
16. 0.394 8.177 ↓ 55.7 167 1

HashAggregate (cost=339.04..339.07 rows=3 width=3,436) (actual time=8.068..8.177 rows=167 loops=1)

  • Group Key: users_1.id
  • Buffers: shared hit=1,086 read=277 written=10
17. 0.139 7.783 ↓ 55.7 167 1

Nested Loop (cost=73.12..339.03 rows=3 width=3,436) (actual time=2.366..7.783 rows=167 loops=1)

  • Buffers: shared hit=1,086 read=277 written=10
18. 0.213 6.642 ↓ 27.8 167 1

Nested Loop (cost=72.69..334.60 rows=6 width=3,444) (actual time=2.346..6.642 rows=167 loops=1)

  • Buffers: shared hit=601 read=247 written=9
19. 2.016 4.258 ↓ 2.9 167 1

Bitmap Heap Scan on pseudonyms pseudonyms_1 (cost=72.26..182.84 rows=57 width=16) (actual time=2.297..4.258 rows=167 loops=1)

  • Recheck Cond: (lower((unique_id)::text) ~~ '%@students.ocps.net%'::text)
  • Filter: ((account_id = 557) AND ((workflow_state)::text = 'active'::text))
  • Rows Removed by Filter: 4
  • Heap Blocks: exact=111
  • Buffers: shared hit=41 read=137 written=7
20. 2.242 2.242 ↓ 1.7 171 1

Bitmap Index Scan on index_gin_trgm_pseudonyms_unique_id (cost=0.00..72.24 rows=99 width=0) (actual time=2.242..2.242 rows=171 loops=1)

  • Index Cond: (lower((unique_id)::text) ~~ '%@students.ocps.net%'::text)
  • Buffers: shared hit=39 read=28 written=2
21. 2.171 2.171 ↑ 1.0 1 167

Index Scan using users_pkey on users users_1 (cost=0.43..2.65 rows=1 width=3,428) (actual time=0.013..0.013 rows=1 loops=167)

  • Index Cond: (id = pseudonyms_1.user_id)
  • Filter: (((workflow_state)::text <> 'deleted'::text) AND ((workflow_state)::text <> 'deleted'::text))
  • Buffers: shared hit=560 read=110 written=2
22. 1.002 1.002 ↑ 2.0 1 167

Index Only Scan using index_user_account_associations_on_user_id_and_account_id on user_account_associations user_account_associations_2 (cost=0.43..0.72 rows=2 width=8) (actual time=0.006..0.006 rows=1 loops=167)

  • Index Cond: ((user_id = users_1.id) AND (account_id = 557))
  • Heap Fetches: 12
  • Buffers: shared hit=485 read=30 written=1
23. 0.299 3.225 ↓ 50.7 152 1

HashAggregate (cost=347.31..347.34 rows=3 width=3,436) (actual time=3.137..3.225 rows=152 loops=1)

  • Group Key: users_2.id
  • Buffers: shared hit=1,186 read=14
24. 0.063 2.926 ↓ 50.7 152 1

Nested Loop (cost=99.47..347.30 rows=3 width=3,436) (actual time=0.651..2.926 rows=152 loops=1)

  • Buffers: shared hit=1,186 read=14
25. 0.074 2.255 ↓ 30.4 152 1

Nested Loop (cost=99.04..343.61 rows=5 width=3,444) (actual time=0.638..2.255 rows=152 loops=1)

  • Buffers: shared hit=728 read=14
26. 0.670 1.269 ↓ 2.9 152 1

Bitmap Heap Scan on pseudonyms pseudonyms_2 (cost=98.61..202.50 rows=53 width=16) (actual time=0.623..1.269 rows=152 loops=1)

  • Recheck Cond: (lower((sis_user_id)::text) ~~ '%@students.ocps.net%'::text)
  • Filter: ((account_id = 557) AND ((workflow_state)::text = 'active'::text))
  • Heap Blocks: exact=92
  • Buffers: shared hit=120 read=14
27. 0.599 0.599 ↓ 1.6 152 1

Bitmap Index Scan on index_gin_trgm_pseudonyms_sis_user_id (cost=0.00..98.59 rows=93 width=0) (actual time=0.599..0.599 rows=152 loops=1)

  • Index Cond: (lower((sis_user_id)::text) ~~ '%@students.ocps.net%'::text)
  • Buffers: shared hit=28 read=14
28. 0.912 0.912 ↑ 1.0 1 152

Index Scan using users_pkey on users users_2 (cost=0.43..2.65 rows=1 width=3,428) (actual time=0.005..0.006 rows=1 loops=152)

  • Index Cond: (id = pseudonyms_2.user_id)
  • Filter: (((workflow_state)::text <> 'deleted'::text) AND ((workflow_state)::text <> 'deleted'::text))
  • Buffers: shared hit=608
29. 0.608 0.608 ↑ 2.0 1 152

Index Only Scan using index_user_account_associations_on_user_id_and_account_id on user_account_associations user_account_associations_3 (cost=0.43..0.72 rows=2 width=8) (actual time=0.003..0.004 rows=1 loops=152)

  • Index Cond: ((user_id = users_2.id) AND (account_id = 557))
  • Heap Fetches: 1
  • Buffers: shared hit=458
30. 587.153 11,594.187 ↓ 17.3 345,193 1

GroupAggregate (cost=1.71..383,196.16 rows=19,910 width=3,436) (actual time=0.593..11,594.187 rows=345,193 loops=1)

  • Group Key: users_3.id
  • Buffers: shared hit=4,221,222 read=374,609 dirtied=3,958 written=5,128
31. 312.750 11,007.034 ↓ 17.3 345,291 1

Nested Loop Left Join (cost=1.71..382,897.51 rows=19,910 width=3,436) (actual time=0.505..11,007.034 rows=345,291 loops=1)

  • Buffers: shared hit=4,221,222 read=374,609 dirtied=3,958 written=5,128
32. 130.324 7,586.773 ↓ 17.3 345,279 1

Nested Loop (cost=1.29..365,714.32 rows=19,910 width=3,428) (actual time=0.481..7,586.773 rows=345,279 loops=1)

  • Buffers: shared hit=2,986,774 read=223,555 dirtied=2,372 written=3,116
33. 313.464 5,729.999 ↓ 15.8 345,290 1

Nested Loop (cost=0.85..349,652.75 rows=21,785 width=3,436) (actual time=0.432..5,729.999 rows=345,290 loops=1)

  • Buffers: shared hit=1,895,108 read=194,481 dirtied=2,372 written=2,733
34. 1,963.635 1,963.635 ↓ 1.6 345,290 1

Index Scan using index_communication_channels_on_user_id_and_position on communication_channels (cost=0.42..45,779.80 rows=217,660 width=8) (actual time=0.413..1,963.635 rows=345,290 loops=1)

  • Filter: (((workflow_state)::text = ANY ('{active,unconfirmed}'::text[])) AND ((path_type)::text = 'email'::text) AND (lower((path)::text) ~~ '%@students.ocps.net%'::text))
  • Rows Removed by Filter: 399,936
  • Buffers: shared hit=634,730 read=32,447 written=548
35. 3,452.900 3,452.900 ↑ 1.0 1 345,290

Index Scan using users_pkey on users users_3 (cost=0.43..1.39 rows=1 width=3,428) (actual time=0.009..0.010 rows=1 loops=345,290)

  • Index Cond: (id = communication_channels.user_id)
  • Filter: (((workflow_state)::text <> 'deleted'::text) AND ((workflow_state)::text <> 'deleted'::text))
  • Buffers: shared hit=1,260,378 read=162,034 dirtied=2,372 written=2,185
36. 1,726.450 1,726.450 ↑ 2.0 1 345,290

Index Only Scan using index_user_account_associations_on_user_id_and_account_id on user_account_associations user_account_associations_4 (cost=0.43..0.72 rows=2 width=8) (actual time=0.004..0.005 rows=1 loops=345,290)

  • Index Cond: ((user_id = users_3.id) AND (account_id = 557))
  • Heap Fetches: 79,856
  • Buffers: shared hit=1,091,666 read=29,074 written=383
37. 3,107.511 3,107.511 ↑ 1.0 1 345,279

Index Scan using index_pseudonyms_on_user_id on pseudonyms pseudonyms_3 (cost=0.42..0.85 rows=1 width=16) (actual time=0.009..0.009 rows=1 loops=345,279)

  • Index Cond: (user_id = users_3.id)
  • Filter: ((account_id = '557'::bigint) AND ((workflow_state)::text = 'active'::text))
  • Rows Removed by Filter: 0
  • Buffers: shared hit=1,234,448 read=151,054 dirtied=1,586 written=2,012
38. 1,726.590 1,726.590 ↑ 2.0 1 345,318

Index Only Scan using index_user_account_associations_on_user_id_and_account_id on user_account_associations (cost=0.43..2.35 rows=2 width=8) (actual time=0.005..0.005 rows=1 loops=345,318)

  • Index Cond: ((user_id = users.id) AND (account_id = 557))
  • Heap Fetches: 79,846
  • Buffers: shared hit=1,091,593 read=29,220 written=328
39. 54,905.562 54,905.562 ↓ 0.0 0 345,318

Index Scan using index_enrollments_on_user_id on enrollments (cost=0.44..4.65 rows=1 width=8) (actual time=0.159..0.159 rows=0 loops=345,318)

  • Index Cond: (user_id = user_account_associations.user_id)
  • Filter: ((role_id = 1,152) AND ((workflow_state)::text <> ALL ('{rejected,deleted,inactive}'::text[])))
  • Rows Removed by Filter: 34
  • Buffers: shared hit=7,828,760 read=4,724,280 dirtied=2,561 written=50,478
Planning time : 6.217 ms
Execution time : 70,506.247 ms