explain.depesz.com

PostgreSQL's explain analyze made readable

Result: Qgm : Optimization for: app_log; plan #6lPs

Settings

Optimization path:

Optimization(s) for this plan:

# exclusive inclusive rows x rows loops node
1. 0.107 2,534.492 ↑ 1.0 10 1

Limit (cost=148,345.79..148,346.29 rows=10 width=164) (actual time=2,534.373..2,534.492 rows=10 loops=1)

2. 0.153 2,534.385 ↑ 7,400.7 70 1

GroupAggregate (cost=148,342.79..169,064.87 rows=518,052 width=164) (actual time=2,534.213..2,534.385 rows=70 loops=1)

  • Group Key: j1.username, t.""timestamp"", t.ip, t.backend_url, t.backend_body, t.backend_params, t.backend_query
3. 2,005.265 2,534.232 ↑ 6,816.5 76 1

Sort (cost=148,342.79..149,637.92 rows=518,052 width=180) (actual time=2,534.184..2,534.232 rows=76 loops=1)

  • Sort Key: j1.username, t.""timestamp"", t.ip, t.backend_url, t.backend_body, t.backend_params, t.backend_query
  • Sort Method: external merge Disk: 77224kB
4. 162.050 528.967 ↑ 1.2 431,693 1

Hash Left Join (cost=2,646.98..72,206.86 rows=518,052 width=180) (actual time=4.373..528.967 rows=431,693 loops=1)

  • Hash Cond: ((t.object_id = j2.id) AND ((t.object_type)::text = (j2.object_type)::text))
5. 251.356 362.579 ↑ 1.2 431,693 1

Hash Left Join (cost=1.27..20,321.95 rows=518,052 width=152) (actual time=0.030..362.579 rows=431,693 loops=1)

  • Hash Cond: (t.userid = j1.id)
6. 111.208 111.208 ↑ 1.2 431,693 1

Seq Scan on app_log t (cost=0.00..18,480.52 rows=518,052 width=148) (actual time=0.008..111.208 rows=431,693 loops=1)

7. 0.006 0.015 ↑ 1.0 12 1

Hash (cost=1.12..1.12 rows=12 width=12) (actual time=0.014..0.015 rows=12 loops=1)

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

Seq Scan on nms_user j1 (cost=0.00..1.12 rows=12 width=12) (actual time=0.005..0.009 rows=12 loops=1)

9. 0.168 4.338 ↓ 1.3 454 1

Hash (cost=2,640.37..2,640.37 rows=356 width=154) (actual time=4.338..4.338 rows=454 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 35kB
10. 0.121 4.170 ↓ 1.3 454 1

Subquery Scan on j2 (cost=2,615.08..2,640.37 rows=356 width=154) (actual time=3.717..4.170 rows=454 loops=1)

11. 0.080 4.049 ↓ 1.3 454 1

Append (cost=2,615.08..2,636.81 rows=356 width=154) (actual time=3.717..4.049 rows=454 loops=1)

12. 0.004 3.719 ↑ 3.0 2 1

Hash Join (cost=2,615.08..2,616.23 rows=6 width=136) (actual time=3.716..3.719 rows=2 loops=1)

  • Hash Cond: (j3.field_id = j2_1.id)
13. 0.006 3.696 ↑ 3.0 2 1

Hash Left Join (cost=2,613.81..2,614.94 rows=6 width=22) (actual time=3.693..3.696 rows=2 loops=1)

  • Hash Cond: (j3.id = foo.entity_id)
14. 0.008 0.008 ↑ 3.0 2 1

Seq Scan on device j3 (cost=0.00..1.10 rows=6 width=22) (actual time=0.007..0.008 rows=2 loops=1)

  • Filter: (device_name IS NOT NULL)
  • Rows Removed by Filter: 9
15. 0.002 3.682 ↓ 2.0 2 1

Hash (cost=2,613.79..2,613.79 rows=1 width=4) (actual time=3.682..3.682 rows=2 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
16. 0.002 3.680 ↓ 2.0 2 1

Subquery Scan on foo (cost=2,612.67..2,613.79 rows=1 width=4) (actual time=3.673..3.680 rows=2 loops=1)

  • Filter: (foo.rank = 1)
  • Rows Removed by Filter: 2
17. 0.010 3.678 ↑ 8.0 4 1

WindowAgg (cost=2,612.67..2,613.39 rows=32 width=61) (actual time=3.672..3.678 rows=4 loops=1)

18. 0.005 3.668 ↑ 8.0 4 1

Sort (cost=2,612.67..2,612.75 rows=32 width=21) (actual time=3.667..3.668 rows=4 loops=1)

  • Sort Key: faa.entity_id, faa.""time"" DESC
  • Sort Method: quicksort Memory: 25kB
19. 0.002 3.663 ↑ 8.0 4 1

Subquery Scan on faa (cost=2,610.83..2,611.87 rows=32 width=21) (actual time=3.657..3.663 rows=4 loops=1)

20. 0.007 3.661 ↑ 8.0 4 1

GroupAggregate (cost=2,610.83..2,611.55 rows=32 width=53) (actual time=3.657..3.661 rows=4 loops=1)

  • Group Key: metric_log.entity_id, metric_log.entity_type, (time_bucket('00:01:00'::interval, metric_log.""time""))
21. 0.015 3.654 ↑ 2.7 12 1

Sort (cost=2,610.83..2,610.91 rows=32 width=21) (actual time=3.652..3.654 rows=12 loops=1)

  • Sort Key: metric_log.entity_id, (time_bucket('00:01:00'::interval, metric_log.""time""))
  • Sort Method: quicksort Memory: 25kB
22. 2.908 3.639 ↑ 2.7 12 1

Bitmap Heap Scan on metric_log (cost=7.85..2,610.03 rows=32 width=21) (actual time=3.564..3.639 rows=12 loops=1)

  • Recheck Cond: ((""time"" > (now() - '00:05:00'::interval)) AND ((entity_type)::text = 'DEVICE'::text))
  • Rows Removed by Index Recheck: 11496
  • Heap Blocks: lossy=112
23. 0.003 0.731 ↓ 0.0 0 1

BitmapAnd (cost=7.85..7.85 rows=2,516 width=0) (actual time=0.731..0.731 rows=0 loops=1)

24. 0.064 0.064 ↑ 12.3 1,280 1

Bitmap Index Scan on metric_log_time_brin_idx (cost=0.00..3.34 rows=15,763 width=0) (actual time=0.064..0.064 rows=1,280 loops=1)

  • Index Cond: (""time"" > (now() - '00:05:00'::interval))
25. 0.664 0.664 ↑ 1.7 235,520 1

Bitmap Index Scan on metric_log_entity_type_bri_idx (cost=0.00..4.24 rows=399,598 width=0) (actual time=0.664..0.664 rows=235,520 loops=1)

  • Index Cond: ((entity_type)::text = 'DEVICE'::text)
26. 0.010 0.019 ↓ 1.1 13 1

Hash (cost=1.12..1.12 rows=12 width=4) (actual time=0.018..0.019 rows=13 loops=1)

  • Buckets: 1024 Batches: 1 Memory Usage: 9kB
27. 0.009 0.009 ↓ 1.1 13 1

Seq Scan on field j2_1 (cost=0.00..1.12 rows=12 width=4) (actual time=0.006..0.009 rows=13 loops=1)

28. 0.066 0.066 ↓ 1.1 80 1

Seq Scan on component (cost=0.00..3.23 rows=70 width=146) (actual time=0.018..0.066 rows=80 loops=1)

29. 0.040 0.040 ↓ 1.0 89 1

Seq Scan on city (cost=0.00..1.87 rows=87 width=130) (actual time=0.015..0.040 rows=89 loops=1)

30. 0.010 0.010 ↓ 1.2 16 1

Seq Scan on region (cost=0.00..1.13 rows=13 width=240) (actual time=0.006..0.010 rows=16 loops=1)

31. 0.008 0.008 ↓ 1.1 12 1

Seq Scan on metric_event_rule (cost=0.00..1.11 rows=11 width=240) (actual time=0.005..0.008 rows=12 loops=1)

32. 0.023 0.023 ↓ 3.3 36 1

Seq Scan on dashboard (cost=0.00..1.11 rows=11 width=240) (actual time=0.005..0.023 rows=36 loops=1)

33. 0.018 0.018 ↓ 1.4 43 1

Seq Scan on discovery (cost=0.00..1.31 rows=31 width=134) (actual time=0.008..0.018 rows=43 loops=1)

34. 0.008 0.008 ↑ 1.0 12 1

Seq Scan on nms_user (cost=0.00..1.12 rows=12 width=130) (actual time=0.005..0.008 rows=12 loops=1)

35. 0.008 0.008 ↓ 2.8 17 1

Seq Scan on user_group (cost=0.00..1.06 rows=6 width=240) (actual time=0.005..0.008 rows=17 loops=1)

36. 0.011 0.011 ↓ 1.9 26 1

Seq Scan on user_role (cost=0.00..1.14 rows=14 width=240) (actual time=0.005..0.011 rows=26 loops=1)

37. 0.041 0.041 ↓ 1.3 105 1

Seq Scan on user_action (cost=0.00..1.81 rows=81 width=139) (actual time=0.005..0.041 rows=105 loops=1)

38. 0.006 0.006 ↑ 1.0 5 1

Seq Scan on device_group (cost=0.00..1.05 rows=5 width=240) (actual time=0.005..0.006 rows=5 loops=1)

39. 0.003 0.011 ↓ 1.2 11 1

Subquery Scan on "*SELECT* 13" (cost=0.00..1.18 rows=9 width=154) (actual time=0.005..0.011 rows=11 loops=1)

40. 0.008 0.008 ↓ 1.2 11 1

Seq Scan on interface_connection (cost=0.00..1.09 rows=9 width=154) (actual time=0.005..0.008 rows=11 loops=1)

Planning time : 1.496 ms
Execution time : 2,556.798 ms