Re: 57 minute SELECT

From: Samuel Stearns <sstearns(at)staff(dot)iinet(dot)net(dot)au>
To: Samuel Stearns <sstearns(at)staff(dot)iinet(dot)net(dot)au>, David Johnston <polobo(at)yahoo(dot)com>, "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Re: 57 minute SELECT
Date: 2013-10-03 01:35:25
Message-ID: CB03CD8D2C3F9347BAFEC8EA9DD89C9318D379E4@ISP-OSB-DAG2.win2k.iinet.net.au
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

zone))
-> Bitmap Index Scan on syslog_master_ip_idx (cost=0.00..4.27 rows=2 width=0) (actual time=0.019..0.019 rows=0 loops=1)
Index Cond: (public.syslog_master.ip = public.devices.ip)
-> Bitmap Heap Scan on syslog_201307 syslog_master (cost=4175.37..355209.50 rows=150004 width=112) (actual time=30112.618..686289.128 rows=297015 loops=1)
Recheck Cond: (public.syslog_master.ip = public.devices.ip)
Filter: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time zone))
-> Bitmap Index Scan on syslog_201307_ip_idx (cost=0.00..4137.88 rows=150004 width=0) (actual time=30040.703..30040.703 rows=297015 loops=1)
Index Cond: (public.syslog_master.ip = public.devices.ip)
-> Index Scan using syslog_201308_datetime_idx on syslog_201308 syslog_master (cost=0.00..8.46 rows=1 width=108) (actual time=30.022..124.656 rows=52 loops=1)
Index Cond: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time zone))
-> Bitmap Heap Scan on syslog_201304 syslog_master (cost=1829.05..235809.88 rows=98010 width=117) (actual time=1049.606..875045.663 rows=320488 loops=1)
Recheck Cond: (public.syslog_master.ip = public.devices.ip)
Filter: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time zone))
-> Bitmap Index Scan on syslog_201304_ip_idx (cost=0.00..1813.37 rows=98010 width=0) (actual time=984.401..984.401 rows=505789 loops=1)
Index Cond: (public.syslog_master.ip = public.devices.ip)
-> Bitmap Heap Scan on syslog_201305 syslog_master (cost=2157.14..264759.11 rows=114937 width=115) (actual time=926.035..910323.922 rows=520315 loops=1)
Recheck Cond: (public.syslog_master.ip = public.devices.ip)
Filter: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time zone))
-> Bitmap Index Scan on syslog_201305_ip_idx (cost=0.00..2128.41 rows=114937 width=0) (actual time=864.109..864.109 rows=520315 loops=1)
Index Cond: (public.syslog_master.ip = public.devices.ip)
-> Bitmap Heap Scan on syslog_201306 syslog_master (cost=2020.92..258582.12 rows=107670 width=117) (actual time=1948.265..942909.424 rows=791896 loops=1)
Recheck Cond: (public.syslog_master.ip = public.devices.ip)
Filter: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time zone))
-> Bitmap Index Scan on syslog_201306_ip_idx (cost=0.00..1994.01 rows=107670 width=0) (actual time=1896.295..1896.295 rows=791896 loops=1)
Index Cond: (public.syslog_master.ip = public.devices.ip)
-> Hash (cost=170.08..170.08 rows=2303 width=18) (actual time=3.398..3.398 rows=2386 loops=1)
-> Seq Scan on devices (cost=0.00..170.08 rows=2303 width=18) (actual time=0.017..2.407 rows=2387 loops=1)
Filter: ((active = 't'::bpchar) OR (active = 's'::bpchar))
Total runtime: 3419878.638 ms

Thank you,

Sam

-----Original Message-----
From: pgsql-performance-owner(at)postgresql(dot)org [mailto:pgsql-performance-owner(at)postgresql(dot)org] On Behalf Of Samuel Stearns
Sent: Thursday, 3 October 2013 11:00 AM
To: David Johnston; pgsql-performance(at)postgresql(dot)org
Subject: Re: [PERFORM] 57 minute SELECT

Total RAM = 1G is correct

This query executes as the result of a search from our Network Management System Device Audit web tool where the date range is large and is focused on a specific device.

I was thinking it should execute more quickly since syslog.ip has an index and we're not performing any textual matching.

EXPLAIN:

QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Hash Join (cost=408.53..1962721.39 rows=98068 width=126) (actual time=30121.265..3419306.752 rows=1929714 loops=1)
Hash Cond: (public.syslog_master.ip = public.devices.ip)
-> Nested Loop (cost=209.67..1120466.90 rows=37316116 width=122) (actual time=30117.845..3416690.561 rows=1929714 loops=1)
Join Filter: (public.syslog_master.ip = public.devices.ip)
-> HashAggregate (cost=205.40..205.41 rows=1 width=7) (actual time=5.133..5.142 rows=1 loops=1)
-> Nested Loop (cost=0.00..205.40 rows=1 width=7) (actual time=4.117..5.124 rows=1 loops=1)
Join Filter: ((public.devices.hostgroup)::text = (mongroups.hostgroup)::text)
-> Seq Scan on devices (cost=0.00..202.80 rows=1 width=14) (actual time=4.088..5.075 rows=1 loops=1)
Filter: ((id <> 1291) AND ((active = 't'::bpchar) OR (active = 's'::bpchar)) AND ((((hostname)::text || '.'::text) || (hostpop)::text) ~* 'pe1.mel4'::text))
-> Seq Scan on mongroups (cost=0.00..1.71 rows=71 width=6) (actual time=0.009..0.017 rows=71 loops=1)
-> Append (cost=4.27..1114378.69 rows=470624 width=115) (actual time=30112.646..3415201.052 rows=1929766 loops=1)
-> Bitmap Heap Scan on syslog_master (cost=4.27..9.61 rows=2 width=72) (actual time=0.027..0.027 rows=0 loops=1)
Recheck Cond: (public.syslog_master.ip = public.devices.ip)
Filter: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time zone))
-> Bitmap Index Scan on syslog_master_ip_idx (cost=0.00..4.27 rows=2 width=0) (actual time=0.019..0.019 rows=0 loops=1)
Index Cond: (public.syslog_master.ip = public.devices.ip)
-> Bitmap Heap Scan on syslog_201307 syslog_master (cost=4175.37..355209.50 rows=150004 width=112) (actual time=30112.618..686289.128 rows=297015 loops=1)
Recheck Cond: (public.syslog_master.ip = public.devices.ip)
Filter: ((public.syslog_master.datetime <= '2013-08-01 00:00:00'::timestamp without time zone) AND (public.syslog_master.datetime >= '2013-04-12 00:00:00'::timestamp without time

-----Original Message-----
From: pgsql-performance-owner(at)postgresql(dot)org [mailto:pgsql-performance-owner(at)postgresql(dot)org] On Behalf Of David Johnston
Sent: Thursday, 3 October 2013 10:47 AM
To: pgsql-performance(at)postgresql(dot)org
Subject: Re: [PERFORM] 57 minute SELECT

Samuel Stearns-2 wrote
> Total RAM - 1G
>
>
> 1. Explain on SELECT.

So either this is a typo (1 GB of RAM) or your query is likely ending up I/O bound.

You should probably provide EXPLAIN and EXPLAIN (ANALYZE) output since even with the schema it is impossible for someone to see what the planner is proposing for a multiple-million record source table that is going to be empty if all someone does is create the schema.

For my money it is also helpful to actual write some prose describing what you are providing and seeing and not just toss some settings and schema out there.

http://wiki.postgresql.org/wiki/SlowQueryQuestions

David J.

--
View this message in context: http://postgresql.1045698.n5.nabble.com/57-minute-SELECT-tp5773169p5773174.html
Sent from the PostgreSQL - performance mailing list archive at Nabble.com.

--
Sent via pgsql-performance mailing list (pgsql-performance(at)postgresql(dot)org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance

--
Sent via pgsql-performance mailing list (pgsql-performance(at)postgresql(dot)org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Claudio Freire 2013-10-03 01:45:41 Re: 57 minute SELECT
Previous Message Samuel Stearns 2013-10-03 01:30:18 Re: 57 minute SELECT