explain.depesz.com

PostgreSQL's explain analyze made readable

Result: ZIpb

Settings
# exclusive inclusive rows x rows loops node
1. 49.776 23,325.387 ↓ 26.4 29,496 1

Sort (cost=30,439,552.73..30,439,555.53 rows=1,118 width=152) (actual time=23,320.659..23,325.387 rows=29,496 loops=1)

  • Sort Key: r.course_id, r.question_definition_id, r.occurances
  • Sort Method: external sort Disk: 8592kB
2.          

CTE course_urls

3. 0.005 0.005 ↑ 1.0 9 1

Values Scan on "*VALUES*" (cost=0.00..0.11 rows=9 width=32) (actual time=0.002..0.005 rows=9 loops=1)

4.          

CTE courses

5. 6.629 18.645 ↓ 1.3 9 1

Hash Join (cost=0.29..7,661.00 rows=7 width=40) (actual time=4.838..18.645 rows=9 loops=1)

  • Hash Cond: ((c.url)::text = u.course_url)
6. 12.005 12.005 ↑ 1.1 38,744 1

Seq Scan on groupfinder c (cost=0.00..7,505.74 rows=41,306 width=34) (actual time=0.008..12.005 rows=38,744 loops=1)

  • Filter: (del IS NULL)
  • Rows Removed by Filter: 17044
7. 0.003 0.011 ↑ 1.0 9 1

Hash (cost=0.18..0.18 rows=9 width=32) (actual time=0.011..0.011 rows=9 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
8. 0.008 0.008 ↑ 1.0 9 1

CTE Scan on course_urls u (cost=0.00..0.18 rows=9 width=32) (actual time=0.004..0.008 rows=9 loops=1)

9.          

CTE excluded_users

10. 1.936 22.111 ↑ 24.6 29 1

Nested Loop (cost=1.13..2,473.26 rows=713 width=8) (actual time=0.568..22.111 rows=29 loops=1)

  • Join Filter: (((r_1.roleid)::text <> 'student'::text) OR (upper((u_1.username)::text) ~~ '%PREVIEW%'::text) OR (upper((u_1.familyname)::text) ~~ '%PREVIEW%'::text) OR (upper((u_1.givenname)::text) ~~ '%PREVIEW%'::text) OR (upper((u_1.middlename)::text) ~~ '%PRE
  • Rows Removed by Join Filter: 1402
11. 0.535 18.744 ↓ 1.9 1,431 1

Nested Loop (cost=0.85..2,228.17 rows=736 width=75) (actual time=0.019..18.744 rows=1,431 loops=1)

12. 0.329 15.347 ↓ 1.9 1,431 1

Nested Loop (cost=0.42..1,839.06 rows=740 width=16) (actual time=0.011..15.347 rows=1,431 loops=1)

13. 13.812 13.812 ↓ 1.3 9 1

CTE Scan on courses c_1 (cost=0.00..0.14 rows=7 width=8) (actual time=0.000..13.812 rows=9 loops=1)

14. 1.206 1.206 ↓ 1.5 159 9

Index Scan using enrollmentfinder_group_id_normal_idx on enrollmentfinder ef (cost=0.42..261.64 rows=106 width=24) (actual time=0.005..0.134 rows=159 loops=9)

  • Index Cond: (group_id = c_1.course_id)
  • Filter: ((del IS NULL) AND (del IS NULL))
15. 2.862 2.862 ↑ 1.0 1 1,431

Index Scan using userfinder_pkey on userfinder u_1 (cost=0.42..0.52 rows=1 width=67) (actual time=0.002..0.002 rows=1 loops=1,431)

  • Index Cond: (id = ef.parent_id)
  • Filter: (del IS NULL)
16. 1.431 1.431 ↑ 1.0 1 1,431

Index Scan using rolefinder_pkey on rolefinder r_1 (cost=0.28..0.30 rows=1 width=19) (actual time=0.001..0.001 rows=1 loops=1,431)

  • Index Cond: (id = ef.role_id)
17.          

CTE responses

18. 524.816 7,488.081 ↑ 4.1 585,735 1

Nested Loop Left Join (cost=17.05..196,741.42 rows=2,386,392 width=106) (actual time=27.078..7,488.081 rows=585,735 loops=1)

19. 0.000 1,691.650 ↓ 24.5 585,735 1

Nested Loop (cost=17.04..137,081.46 rows=23,864 width=178) (actual time=27.017..1,691.650 rows=585,735 loops=1)

20. 59.008 608.042 ↓ 20.3 585,902 1

Nested Loop (cost=16.61..38,785.99 rows=28,909 width=148) (actual time=27.006..608.042 rows=585,902 loops=1)

21. 4.849 4.849 ↓ 1.3 9 1

CTE Scan on courses c_2 (cost=0.00..0.14 rows=7 width=40) (actual time=4.839..4.849 rows=9 loops=1)

22. 522.063 544.185 ↓ 15.8 65,100 9

Index Scan using assess_question_respfinder_course_id_normal_idx on assess_question_respfinder r_2 (cost=16.61..5,499.54 rows=4,130 width=116) (actual time=2.473..60.465 rows=65,100 loops=9)

  • Index Cond: (course_id = c_2.course_id)
  • Filter: ((del IS NULL) AND (outcomevaluesmap IS NOT NULL) AND (NOT (hashed SubPlan 4)))
  • Rows Removed by Filter: 16
23.          

SubPlan (forIndex Scan)

24. 22.122 22.122 ↑ 24.6 29 1

CTE Scan on excluded_users (cost=0.00..14.26 rows=713 width=8) (actual time=0.571..22.122 rows=29 loops=1)

25. 1,171.804 1,171.804 ↑ 1.0 1 585,902

Index Scan using assess_questionfinder_pkey on assess_questionfinder q (cost=0.43..3.39 rows=1 width=38) (actual time=0.001..0.002 rows=1 loops=585,902)

  • Index Cond: (id = r_2.questiondefinition_id)
  • Filter: ((pointspossible IS NOT NULL) AND (del IS NULL) AND ((questionimpltype)::text = ANY ('{SimpleQuestionType.multiChoice,SimpleQuestionType.trueFalse}'::text[])))
  • Rows Removed by Filter: 0
26. 5,271.615 5,271.615 ↑ 100.0 1 585,735

Function Scan on unnest x (cost=0.01..1.01 rows=100 width=40) (actual time=0.009..0.009 rows=1 loops=585,735)

27.          

CTE responses_indexed

28. 1,258.992 15,302.109 ↓ 2.4 579,632 1

GroupAggregate (cost=3,182,698.91..3,239,972.31 rows=238,639 width=644) (actual time=13,883.459..15,302.109 rows=579,632 loops=1)

  • Group Key: r_3.response_id, r_3.course_id, r_3.course_url, r_3.user_id, r_3.question_definition_id, r_3.question_type
29. 580.317 14,043.117 ↑ 4.1 579,632 1

Sort (cost=3,182,698.91..3,188,664.89 rows=2,386,392 width=630) (actual time=13,883.431..14,043.117 rows=579,632 loops=1)

  • Sort Key: r_3.response_id, r_3.course_id, r_3.course_url, r_3.user_id, r_3.question_definition_id, r_3.question_type
  • Sort Method: external merge Disk: 96624kB
30. 1,192.702 13,462.800 ↑ 4.1 579,632 1

Hash Join (cost=779,110.50..1,353,345.13 rows=2,386,392 width=630) (actual time=4,489.128..13,462.800 rows=579,632 loops=1)

  • Hash Cond: (r_3.choice = c_3.id)
31. 7,814.697 7,814.697 ↑ 4.1 585,735 1

CTE Scan on responses r_3 (cost=0.00..47,727.84 rows=2,386,392 width=592) (actual time=27.079..7,814.697 rows=585,735 loops=1)

32. 2,089.681 4,455.401 ↑ 1.1 10,218,415 1

Hash (cost=539,774.89..539,774.89 rows=10,749,089 width=50) (actual time=4,455.401..4,455.401 rows=10,218,415 loops=1)

  • Buckets: 65536 Batches: 512 Memory Usage: 2188kB
33. 2,365.720 2,365.720 ↑ 1.1 10,218,415 1

Seq Scan on assess_question_choicefinder c_3 (cost=0.00..539,774.89 rows=10,749,089 width=50) (actual time=0.038..2,365.720 rows=10,218,415 loops=1)

34.          

CTE responses_counted

35. 332.855 23,245.001 ↑ 7.6 29,496 1

GroupAggregate (cost=13,801,939.50..26,987,615.10 rows=223,685 width=776) (actual time=22,380.976..23,245.001 rows=29,496 loops=1)

  • Group Key: r_4.course_id, r_4.course_url, r_4.question_definition_id, r_4.question_type, ((SubPlan 7)), q_1.questiontext, r_4.choices_text
36. 2,508.206 22,912.146 ↓ 2.6 579,632 1

Sort (cost=13,801,939.50..13,802,498.71 rows=223,685 width=732) (actual time=22,380.962..22,912.146 rows=579,632 loops=1)

  • Sort Key: r_4.course_id, r_4.course_url, r_4.question_definition_id, r_4.question_type, ((SubPlan 7)), q_1.questiontext, r_4.choices_text
  • Sort Method: external merge Disk: 189744kB
37. 1,070.240 20,403.940 ↓ 2.6 579,632 1

Hash Join (cost=399,504.59..13,667,922.34 rows=223,685 width=732) (actual time=15,849.495..20,403.940 rows=579,632 loops=1)

  • Hash Cond: (r_4.question_definition_id = q_1.id)
38. 15,632.334 15,632.334 ↓ 2.4 579,632 1

CTE Scan on responses_indexed r_4 (cost=0.00..4,772.78 rows=238,639 width=596) (actual time=13,883.462..15,632.334 rows=579,632 loops=1)

39. 691.574 1,962.470 ↓ 1.0 2,835,741 1

Hash (cost=319,370.75..319,370.75 rows=2,753,587 width=112) (actual time=1,962.470..1,962.470 rows=2,835,741 loops=1)

  • Buckets: 32768 Batches: 128 Memory Usage: 3273kB
40. 1,270.896 1,270.896 ↓ 1.0 2,835,741 1

Seq Scan on assess_questionfinder q_1 (cost=0.00..319,370.75 rows=2,753,587 width=112) (actual time=0.042..1,270.896 rows=2,835,741 loops=1)

  • Filter: ((del IS NULL) AND (pointspossible IS NOT NULL))
  • Rows Removed by Filter: 193864
41.          

SubPlan (forHash Join)

42. 579.632 1,738.896 ↑ 1.0 1 579,632

Aggregate (cost=58.90..58.91 rows=1 width=32) (actual time=0.003..0.003 rows=1 loops=579,632)

43. 1,159.264 1,159.264 ↑ 6.0 4 579,632

Index Scan using publishedassetfinder_linkedcomponent_id_normal_idx on publishedassetfinder (cost=0.56..58.84 rows=24 width=37) (actual time=0.001..0.002 rows=4 loops=579,632)

  • Index Cond: (linkedcomponent_id = q_1.id)
44. 23,275.611 23,275.611 ↓ 26.4 29,496 1

CTE Scan on responses_counted r (cost=0.00..5,032.91 rows=1,118 width=152) (actual time=22,380.983..23,275.611 rows=29,496 loops=1)

  • Filter: (number_of_selections = 1)