explain.depesz.com

PostgreSQL's explain analyze made readable

Result: CRdb : qqq

Settings
# exclusive inclusive rows x rows loops node
1. 0.116 363,162.668 ↓ 50.0 50 1

Sort (cost=1,921.48..1,921.48 rows=1 width=2,083) (actual time=363,162.663..363,162.668 rows=50 loops=1)

  • Sort Key: tab.rn
  • Sort Method: quicksort Memory: 50kB
  • Buffers: shared hit=99860435 read=2947865 dirtied=5781
2. 0.015 363,162.552 ↓ 50.0 50 1

Nested Loop Left Join (cost=4.65..1,921.47 rows=1 width=2,083) (actual time=363,056.387..363,162.552 rows=50 loops=1)

  • Buffers: shared hit=99860432 read=2947865 dirtied=5781
3. 0.030 363,162.287 ↓ 50.0 50 1

Nested Loop Left Join (cost=4.36..1,921.15 rows=1 width=2,059) (actual time=363,056.366..363,162.287 rows=50 loops=1)

  • Buffers: shared hit=99860284 read=2947863 dirtied=5781
4. 0.075 363,162.107 ↓ 50.0 50 1

Nested Loop Left Join (cost=4.08..1,920.84 rows=1 width=2,008) (actual time=363,056.352..363,162.107 rows=50 loops=1)

  • Join Filter: (security_audit.action_result_id = audit_action_results.aa_res_id)
  • Rows Removed by Join Filter: 100
  • Buffers: shared hit=99860134 read=2947863 dirtied=5781
5. 0.062 363,161.982 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,919.77 rows=1 width=2,002) (actual time=363,056.344..363,161.982 rows=50 loops=1)

  • Join Filter: (security_audit.auth_result_id = audit_auth_results.auth_result_id)
  • Rows Removed by Join Filter: 50
  • Buffers: shared hit=99860084 read=2947863 dirtied=5781
6. 0.060 363,161.870 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,918.73 rows=1 width=2,001) (actual time=363,056.334..363,161.870 rows=50 loops=1)

  • Join Filter: (security_audit.source_type_id = source_types.source_type_id)
  • Rows Removed by Join Filter: 50
  • Buffers: shared hit=99860034 read=2947863 dirtied=5781
7. 0.220 363,161.760 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,917.68 rows=1 width=2,002) (actual time=363,056.324..363,161.760 rows=50 loops=1)

  • Join Filter: (permissions.perm_action_id = permission_actions.perm_action_id)
  • Rows Removed by Join Filter: 1100
  • Buffers: shared hit=99859984 read=2947863 dirtied=5781
8. 0.118 363,161.440 ↓ 50.0 50 1

Nested Loop Left Join (cost=4.08..1,916.16 rows=1 width=1,996) (actual time=363,056.313..363,161.440 rows=50 loops=1)

  • Join Filter: (biz_objects_types.namespace_id = namespaces.namespace_id)
  • Rows Removed by Join Filter: 400
  • Buffers: shared hit=99859934 read=2947863 dirtied=5781
9. 0.285 363,161.272 ↓ 50.0 50 1

Nested Loop Left Join (cost=4.08..1,914.96 rows=1 width=1,993) (actual time=363,056.305..363,161.272 rows=50 loops=1)

  • Join Filter: (permissions.obj_type_id = biz_objects_types.obj_type_id)
  • Rows Removed by Join Filter: 1750
  • Buffers: shared hit=99859884 read=2947863 dirtied=5781
10. 0.973 363,160.837 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,913.15 rows=1 width=1,981) (actual time=363,056.291..363,160.837 rows=50 loops=1)

  • Join Filter: (security_audit.perm_id = permissions.perm_id)
  • Rows Removed by Join Filter: 6800
  • Buffers: shared hit=99859834 read=2947863 dirtied=5781
11. 0.085 363,159.414 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,908.07 rows=1 width=1,961) (actual time=363,056.269..363,159.414 rows=50 loops=1)

  • Join Filter: (security_audit.importance_id = audit_importance.importance_id)
  • Rows Removed by Join Filter: 150
  • Buffers: shared hit=99859734 read=2947863 dirtied=5781
12. 0.073 363,159.279 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,906.98 rows=1 width=1,960) (actual time=363,056.261..363,159.279 rows=50 loops=1)

  • Join Filter: (security_audit.category_id = audit_categories.category_id)
  • Rows Removed by Join Filter: 50
  • Buffers: shared hit=99859684 read=2947863 dirtied=5781
13. 0.060 363,159.156 ↓ 50.0 50 1

Nested Loop (cost=4.08..1,905.93 rows=1 width=1,948) (actual time=363,056.253..363,159.156 rows=50 loops=1)

  • Buffers: shared hit=99859634 read=2947863 dirtied=5781
14. 0.028 363,158.796 ↓ 50.0 50 1

Subquery Scan on tab (cost=3.50..1,897.33 rows=1 width=16) (actual time=363,056.218..363,158.796 rows=50 loops=1)

  • Filter: ((tab.rn >= 1) AND (tab.rn <= 50))
  • Buffers: shared hit=99859392 read=2947855 dirtied=5781
15. 0.008 363,158.768 ↑ 1.0 50 1

Limit (cost=3.50..1,896.58 rows=50 width=24) (actual time=363,056.214..363,158.768 rows=50 loops=1)

  • Buffers: shared hit=99859392 read=2947855 dirtied=5781
16. 0.044 363,158.760 ↑ 11,651.1 50 1

WindowAgg (cost=3.50..22,056,507.67 rows=582,556 width=24) (actual time=363,056.213..363,158.760 rows=50 loops=1)

  • Buffers: shared hit=99859392 read=2947855 dirtied=5781
17. 0.022 363,158.716 ↑ 11,651.1 50 1

Nested Loop (cost=3.50..22,047,769.33 rows=582,556 width=16) (actual time=363,056.206..363,158.716 rows=50 loops=1)

  • Buffers: shared hit=99859392 read=2947855 dirtied=5781
18. 70.018 363,158.444 ↑ 11,651.1 50 1

Nested Loop Semi Join (cost=3.21..21,864,138.86 rows=582,556 width=21) (actual time=363,056.164..363,158.444 rows=50 loops=1)

  • Join Filter: (security_audit_1.perm_id = permissions_1.perm_id)
  • Rows Removed by Join Filter: 508510
  • Buffers: shared hit=99859280 read=2947854 dirtied=5781
19. 363,069.572 363,069.572 ↑ 92.7 18,854 1

Index Scan Backward using idx_sa_action_time_start on security_audit security_audit_1 (cost=0.57..21,706,840.66 rows=1,747,668 width=26) (actual time=363,055.616..363,069.572 rows=18,854 loops=1)

  • Filter: ((COALESCE(action_time_end, action_time_start) >= '2019-12-21 00:59:00'::timestamp without time zone) AND (COALESCE(action_time_end, action_time_start) <= '2019-12-21 23:59:00'::timestamp without time zone))
  • Rows Removed by Filter: 112951136
  • Buffers: shared hit=99859219 read=2947854 dirtied=5781
20. 18.656 18.854 ↓ 4.5 27 18,854

Materialize (cost=2.64..8.09 rows=6 width=4) (actual time=0.000..0.001 rows=27 loops=18,854)

  • Buffers: shared hit=61
21. 0.060 0.198 ↓ 4.5 27 1

Hash Join (cost=2.64..8.06 rows=6 width=4) (actual time=0.120..0.198 rows=27 loops=1)

  • Hash Cond: (biz_objects_types_1.namespace_id = namespaces_1.namespace_id)
  • Buffers: shared hit=61
22. 0.020 0.123 ↓ 4.5 27 1

Nested Loop (cost=1.44..6.77 rows=6 width=9) (actual time=0.054..0.123 rows=27 loops=1)

  • Buffers: shared hit=57
23. 0.041 0.076 ↓ 4.5 27 1

Hash Join (cost=1.30..5.24 rows=6 width=8) (actual time=0.043..0.076 rows=27 loops=1)

  • Hash Cond: (permissions_1.perm_action_id = permission_actions_1.perm_action_id)
  • Buffers: shared hit=3
24. 0.015 0.015 ↑ 1.0 137 1

Seq Scan on permissions permissions_1 (cost=0.00..3.37 rows=137 width=12) (actual time=0.007..0.015 rows=137 loops=1)

  • Buffers: shared hit=2
25. 0.011 0.020 ↑ 1.0 1 1

Hash (cost=1.29..1.29 rows=1 width=4) (actual time=0.020..0.020 rows=1 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
  • Buffers: shared hit=1
26. 0.009 0.009 ↑ 1.0 1 1

Seq Scan on permission_actions permission_actions_1 (cost=0.00..1.29 rows=1 width=4) (actual time=0.007..0.009 rows=1 loops=1)

  • Filter: ((perm_action_lcode)::text = 'READ'::text)
  • Rows Removed by Filter: 22
  • Buffers: shared hit=1
27. 0.027 0.027 ↑ 1.0 1 27

Index Scan using pk_biz_objects_types on biz_objects_types biz_objects_types_1 (cost=0.14..0.25 rows=1 width=9) (actual time=0.001..0.001 rows=1 loops=27)

  • Index Cond: (obj_type_id = permissions_1.obj_type_id)
  • Buffers: shared hit=54
28. 0.008 0.015 ↑ 1.0 9 1

Hash (cost=1.09..1.09 rows=9 width=5) (actual time=0.015..0.015 rows=9 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
  • Buffers: shared hit=1
29. 0.007 0.007 ↑ 1.0 9 1

Seq Scan on namespaces namespaces_1 (cost=0.00..1.09 rows=9 width=5) (actual time=0.005..0.007 rows=9 loops=1)

  • Buffers: shared hit=1
30. 0.250 0.250 ↑ 1.0 1 50

Index Only Scan using pk_users on users users_1 (cost=0.29..0.31 rows=1 width=6) (actual time=0.005..0.005 rows=1 loops=50)

  • Index Cond: (user_id = security_audit_1.user_id)
  • Heap Fetches: 12
  • Buffers: shared hit=112 read=1
31. 0.300 0.300 ↑ 1.0 1 50

Index Scan using pk_security_audit on security_audit (cost=0.57..8.59 rows=1 width=1,940) (actual time=0.006..0.006 rows=1 loops=50)

  • Index Cond: (audit_id = tab.audit_id)
  • Buffers: shared hit=242 read=8
32. 0.050 0.050 ↑ 1.0 2 50

Seq Scan on audit_categories (cost=0.00..1.02 rows=2 width=22) (actual time=0.000..0.001 rows=2 loops=50)

  • Buffers: shared hit=50
33. 0.050 0.050 ↑ 1.0 4 50

Seq Scan on audit_importance (cost=0.00..1.04 rows=4 width=11) (actual time=0.000..0.001 rows=4 loops=50)

  • Buffers: shared hit=50
34. 0.450 0.450 ↑ 1.0 137 50

Seq Scan on permissions (cost=0.00..3.37 rows=137 width=29) (actual time=0.001..0.009 rows=137 loops=50)

  • Buffers: shared hit=100
35. 0.150 0.150 ↑ 1.0 36 50

Seq Scan on biz_objects_types (cost=0.00..1.36 rows=36 width=20) (actual time=0.001..0.003 rows=36 loops=50)

  • Buffers: shared hit=50
36. 0.050 0.050 ↑ 1.0 9 50

Seq Scan on namespaces (cost=0.00..1.09 rows=9 width=13) (actual time=0.000..0.001 rows=9 loops=50)

  • Buffers: shared hit=50
37. 0.100 0.100 ↑ 1.0 23 50

Seq Scan on permission_actions (cost=0.00..1.23 rows=23 width=14) (actual time=0.001..0.002 rows=23 loops=50)

  • Buffers: shared hit=50
38. 0.050 0.050 ↑ 1.0 2 50

Seq Scan on source_types (cost=0.00..1.02 rows=2 width=9) (actual time=0.001..0.001 rows=2 loops=50)

  • Buffers: shared hit=50
39. 0.050 0.050 ↑ 1.0 2 50

Seq Scan on audit_auth_results (cost=0.00..1.02 rows=2 width=11) (actual time=0.000..0.001 rows=2 loops=50)

  • Buffers: shared hit=50
40. 0.050 0.050 ↑ 1.0 3 50

Seq Scan on audit_action_results (cost=0.00..1.03 rows=3 width=16) (actual time=0.000..0.001 rows=3 loops=50)

  • Buffers: shared hit=50
41. 0.150 0.150 ↑ 1.0 1 50

Index Scan using pk_users on users (cost=0.29..0.31 rows=1 width=57) (actual time=0.003..0.003 rows=1 loops=50)

  • Index Cond: (security_audit.user_id = user_id)
  • Buffers: shared hit=150
42. 0.250 0.250 ↑ 1.0 1 50

Index Scan using idx_uac_user_id on user_auth_credentials (cost=0.29..0.31 rows=1 width=14) (actual time=0.005..0.005 rows=1 loops=50)

  • Index Cond: (security_audit.user_id = user_id)
  • Buffers: shared hit=148 read=2
Planning time : 98.179 ms
Execution time : 363,163.039 ms