explain.depesz.com

PostgreSQL's explain analyze made readable

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

Settings

Optimization path:

# exclusive inclusive rows x rows loops node
1. 0.045 2,328.214 ↑ 1.0 10 1

Limit (cost=125,730.17..125,730.67 rows=10 width=164) (actual time=2,328.164..2,328.214 rows=10 loops=1)

2. 0.159 2,328.169 ↑ 6,168.1 70 1

GroupAggregate (cost=125,727.17..142,997.73 rows=431,764 width=164) (actual time=2,328.001..2,328.169 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. 1,820.616 2,328.010 ↑ 5,681.1 76 1

Sort (cost=125,727.17..126,806.58 rows=431,764 width=180) (actual time=2,327.974..2,328.010 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: 77,232kB
4. 153.806 507.394 ↓ 1.0 431,765 1

Hash Left Join (cost=2,648.07..62,840.17 rows=431,764 width=180) (actual time=6.488..507.394 rows=431,765 loops=1)

  • Hash Cond: ((t.object_id = j2.id) AND ((t.object_type)::text = (j2.object_type)::text))
5. 243.616 347.158 ↓ 1.0 431,765 1

Hash Left Join (cost=1.27..19,155.57 rows=431,764 width=152) (actual time=0.049..347.158 rows=431,765 loops=1)

  • Hash Cond: (t.userid = j1.id)
6. 103.512 103.512 ↓ 1.0 431,765 1

Seq Scan on app_log t (cost=0.00..17,620.64 rows=431,764 width=148) (actual time=0.010..103.512 rows=431,765 loops=1)

7. 0.007 0.030 ↑ 1.0 12 1

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

  • Buckets: 1,024 Batches: 1 Memory Usage: 9kB
8. 0.023 0.023 ↑ 1.0 12 1

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

9. 0.283 6.430 ↓ 1.3 454 1

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

  • Buckets: 1,024 Batches: 1 Memory Usage: 35kB
10. 0.147 6.147 ↓ 1.3 454 1

Subquery Scan on j2 (cost=2,616.16..2,641.46 rows=356 width=154) (actual time=5.451..6.147 rows=454 loops=1)

11. 0.113 6.000 ↓ 1.3 454 1

Append (cost=2,616.16..2,637.90 rows=356 width=154) (actual time=5.450..6.000 rows=454 loops=1)

12. 0.006 5.454 ↑ 3.0 2 1

Hash Join (cost=2,616.16..2,617.31 rows=6 width=136) (actual time=5.450..5.454 rows=2 loops=1)

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

Hash Left Join (cost=2,614.89..2,616.03 rows=6 width=22) (actual time=5.428..5.431 rows=2 loops=1)

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

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

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

Hash (cost=2,614.88..2,614.88 rows=1 width=4) (actual time=5.404..5.404 rows=2 loops=1)

  • Buckets: 1,024 Batches: 1 Memory Usage: 9kB
16. 0.002 5.401 ↓ 2.0 2 1

Subquery Scan on foo (cost=2,613.76..2,614.88 rows=1 width=4) (actual time=5.392..5.401 rows=2 loops=1)

  • Filter: (foo.rank = 1)
  • Rows Removed by Filter: 1
17. 0.013 5.399 ↑ 10.7 3 1

WindowAgg (cost=2,613.76..2,614.48 rows=32 width=61) (actual time=5.391..5.399 rows=3 loops=1)

18. 0.007 5.386 ↑ 10.7 3 1

Sort (cost=2,613.76..2,613.84 rows=32 width=21) (actual time=5.384..5.386 rows=3 loops=1)

  • Sort Key: faa.entity_id, faa.""time"" DESC
  • Sort Method: quicksort Memory: 25kB
19. 0.002 5.379 ↑ 10.7 3 1

Subquery Scan on faa (cost=2,611.92..2,612.96 rows=32 width=21) (actual time=5.373..5.379 rows=3 loops=1)

20. 0.009 5.377 ↑ 10.7 3 1

GroupAggregate (cost=2,611.92..2,612.64 rows=32 width=53) (actual time=5.372..5.377 rows=3 loops=1)

  • Group Key: metric_log.entity_id, metric_log.entity_type, (time_bucket('00:01:00'::interval, metric_log.""time""))
21. 0.015 5.368 ↑ 3.6 9 1

Sort (cost=2,611.92..2,612.00 rows=32 width=21) (actual time=5.366..5.368 rows=9 loops=1)

  • Sort Key: metric_log.entity_id, (time_bucket('00:01:00'::interval, metric_log.""time""))
  • Sort Method: quicksort Memory: 25kB
22. 4.360 5.353 ↑ 3.6 9 1

Bitmap Heap Scan on metric_log (cost=7.85..2,611.12 rows=32 width=21) (actual time=5.247..5.353 rows=9 loops=1)

  • Recheck Cond: ((""time"" > (now() - '00:05:00'::interval)) AND ((entity_type)::text = 'DEVICE'::text))
  • Rows Removed by Index Recheck: 12,521
  • Heap Blocks: lossy=121
23. 0.004 0.993 ↓ 0.0 0 1

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

24. 0.086 0.086 ↑ 12.3 1,280 1

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

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

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

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

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

  • Buckets: 1,024 Batches: 1 Memory Usage: 9kB
27. 0.011 0.011 ↓ 1.1 13 1

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

28. 0.130 0.130 ↓ 1.1 80 1

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

29. 0.043 0.043 ↓ 1.0 89 1

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

30. 0.020 0.020 ↓ 1.2 16 1

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

31. 0.010 0.010 ↓ 1.1 12 1

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

32. 0.088 0.088 ↓ 3.3 36 1

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

33. 0.032 0.032 ↓ 1.4 43 1

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

34. 0.011 0.011 ↑ 1.0 12 1

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

35. 0.011 0.011 ↓ 2.8 17 1

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

36. 0.013 0.013 ↓ 1.9 26 1

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

37. 0.053 0.053 ↓ 1.3 105 1

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

38. 0.008 0.008 ↑ 1.0 5 1

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

39. 0.004 0.014 ↓ 1.2 11 1

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

40. 0.010 0.010 ↓ 1.2 11 1

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

Planning time : 2.425 ms
Execution time : 2,350.606 ms