explain.depesz.com

PostgreSQL's explain analyze made readable

Result: KJnH

Settings
# exclusive inclusive rows x rows loops node
1. 20.194 15,284.359 ↑ 8.4 1,282 1

Seq Scan on search_debug (cost=0.00..7,711,011.76 rows=10,710 width=20) (actual time=829.529..15,284.359 rows=1,282 loops=1)

  • Filter: (SubPlan 4)
  • Rows Removed by Filter: 18363
2.          

SubPlan (forSeq Scan)

3. 15,200.416 15,264.165 ↓ 0.0 0 19,645

CTE Scan on relevantdata (cost=349.24..370.70 rows=1 width=4) (actual time=0.777..0.777 rows=0 loops=19,645)

  • Filter: ((SubPlan 3) AND (SubPlan 2))
  • Rows Removed by Filter: 0
4.          

CTE relevantdata

5. 35.348 15,185.585 ↓ 0.0 0 19,645

Nested Loop (cost=66.84..349.24 rows=1 width=16) (actual time=0.773..0.773 rows=0 loops=19,645)

6. 1,774.448 15,146.295 ↓ 0.0 0 19,645

Nested Loop (cost=66.55..348.30 rows=1 width=16) (actual time=0.770..0.771 rows=0 loops=19,645)

  • Join Filter: (qfc.child_folder_id = qfo.folder_id)
7. 2,199.591 4,420.125 ↑ 1.0 456 19,645

Hash Join (cost=66.25..128.95 rows=466 width=16) (actual time=0.005..0.225 rows=456 loops=19,645)

  • Hash Cond: (qfc.child_folder_id = qf.id)
8. 2,219.885 2,219.885 ↑ 1.0 456 19,645

Index Scan using pk_qbank_folder_closure_parent_child on qbank_folder_closure qfc (cost=0.29..56.58 rows=466 width=8) (actual time=0.005..0.113 rows=456 loops=19,645)

  • Index Cond: (parent_folder_id = ANY (('{1810}'::text[])::integer[]))
  • Filter: (depth <= 1000)
9. 0.316 0.649 ↑ 1.0 2,354 1

Hash (cost=36.54..36.54 rows=2,354 width=8) (actual time=0.649..0.649 rows=2,354 loops=1)

  • Buckets: 4096 Batches: 1 Memory Usage: 124kB
10. 0.333 0.333 ↑ 1.0 2,354 1

Seq Scan on qbank_folder qf (cost=0.00..36.54 rows=2,354 width=8) (actual time=0.004..0.333 rows=2,354 loops=1)

11. 8,951.722 8,951.722 ↓ 0.0 0 8,951,722

Index Only Scan using pk_qbank_folder_object on qbank_folder_object qfo (cost=0.29..0.46 rows=1 width=8) (actual time=0.001..0.001 rows=0 loops=8,951,722)

  • Index Cond: ((folder_id = qf.id) AND (object_id = search_debug.object_id))
  • Heap Fetches: 45
12. 3.942 3.942 ↑ 1.0 1 1,314

Index Scan using pk_qbank_object_id on qbank_object qo (cost=0.29..0.93 rows=1 width=4) (actual time=0.003..0.003 rows=1 loops=1,314)

  • Index Cond: (id = qf.object_id)
  • Filter: (NOT deleted)
  • Rows Removed by Filter: 0
13.          

SubPlan (forCTE Scan)

14. 1.301 32.525 ↑ 2.0 1 1,301

HashSetOp Except (cost=7.12..9.61 rows=2 width=8) (actual time=0.025..0.025 rows=1 loops=1,301)

15. 0.000 31.224 ↑ 3.0 1 1,301

Append (cost=7.12..9.61 rows=3 width=8) (actual time=0.020..0.024 rows=1 loops=1,301)

16. 1.301 27.321 ↑ 2.0 1 1,301

Result (cost=7.12..7.15 rows=2 width=8) (actual time=0.020..0.021 rows=1 loops=1,301)

17. 1.301 26.020 ↑ 2.0 1 1,301

Unique (cost=7.12..7.13 rows=2 width=4) (actual time=0.020..0.020 rows=1 loops=1,301)

18. 3.903 24.719 ↑ 1.0 2 1,301

Sort (cost=7.12..7.13 rows=2 width=4) (actual time=0.019..0.019 rows=2 loops=1,301)

  • Sort Key: qbank_acl_group.object_id
  • Sort Method: quicksort Memory: 25kB
19. 1.301 20.816 ↑ 1.0 2 1,301

Append (cost=0.57..7.11 rows=2 width=4) (actual time=0.012..0.016 rows=2 loops=1,301)

20. 2.602 14.311 ↑ 1.0 1 1,301

GroupAggregate (cost=0.57..4.64 rows=1 width=4) (actual time=0.011..0.011 rows=1 loops=1,301)

  • Group Key: qbank_acl_group.object_id
  • Filter: ((bit_or(qbank_acl_group.permissions) & B'00000010'::"bit") = B'00000010'::"bit")
21. 0.000 11.709 ↑ 1.0 1 1,301

Nested Loop (cost=0.57..4.63 rows=1 width=10) (actual time=0.006..0.009 rows=1 loops=1,301)

22. 3.903 3.903 ↓ 2.0 2 1,301

Index Scan using pk_account_user_group_id on account_group_user (cost=0.15..2.18 rows=1 width=4) (actual time=0.002..0.003 rows=2 loops=1,301)

  • Index Cond: (user_id = 1)
  • Filter: (((startdate IS NULL) OR (startdate < now())) AND ((enddate IS NULL) OR (enddate > now())))
23. 7.806 7.806 ↓ 0.0 0 2,602

Index Scan using pk_acl_group_id on qbank_acl_group (cost=0.42..2.44 rows=1 width=14) (actual time=0.002..0.003 rows=0 loops=2,602)

  • Index Cond: ((object_id = relevantdata.folder_object_id) AND (group_id = account_group_user.group_id))
24. 5.204 5.204 ↑ 1.0 1 1,301

Index Scan using pk_acl_user_id on qbank_acl_user (cost=0.42..2.45 rows=1 width=4) (actual time=0.004..0.004 rows=1 loops=1,301)

  • Index Cond: ((object_id = relevantdata.folder_object_id) AND (user_id = 1))
  • Filter: ((permissions & B'00000010'::"bit") = B'00000010'::"bit")
25. 1.301 3.903 ↓ 0.0 0 1,301

Subquery Scan on *SELECT* 3 (cost=0.42..2.46 rows=1 width=8) (actual time=0.003..0.003 rows=0 loops=1,301)

26. 2.602 2.602 ↓ 0.0 0 1,301

Index Scan using pk_acl_user_id on qbank_acl_user qbank_acl_user_1 (cost=0.42..2.45 rows=1 width=4) (actual time=0.002..0.002 rows=0 loops=1,301)

  • Index Cond: ((object_id = relevantdata.folder_object_id) AND (user_id = 1))
  • Filter: (permissions = B'00000000'::"bit")
  • Rows Removed by Filter: 1
27. 1.301 31.224 ↑ 1.0 1 1,301

Aggregate (cost=13.06..13.07 rows=1 width=1) (actual time=0.024..0.024 rows=1 loops=1,301)

28. 2.310 29.923 ↓ 1.3 4 1,301

Nested Loop (cost=0.85..13.05 rows=3 width=1) (actual time=0.008..0.023 rows=4 loops=1,301)

29. 2.310 16.913 ↓ 1.3 4 1,301

Nested Loop (cost=0.57..10.22 rows=3 width=4) (actual time=0.005..0.013 rows=4 loops=1,301)

30. 3.903 3.903 ↓ 1.3 4 1,301

Index Scan using fki_qbank_folder_closure_child_folder_id on qbank_folder_closure parent_folder_closure (cost=0.29..3.30 rows=3 width=4) (actual time=0.002..0.003 rows=4 loops=1,301)

  • Index Cond: (child_folder_id = relevantdata.folder_id)
31. 10.700 10.700 ↑ 1.0 1 5,350

Index Scan using pk_qbank_folder_id on qbank_folder parent_folder (cost=0.28..2.30 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=5,350)

  • Index Cond: (id = parent_folder_closure.parent_folder_id)
32. 10.700 10.700 ↑ 1.0 1 5,350

Index Scan using pk_qbank_object_id on qbank_object parent_object (cost=0.29..0.93 rows=1 width=5) (actual time=0.002..0.002 rows=1 loops=5,350)

  • Index Cond: (id = parent_folder.object_id)
Planning time : 2.890 ms
Execution time : 15,284.759 ms