dmnobunaga
10/14/2015 - 11:45 PM

test2.sql

First run


EXPLAIN (ANALYZE, BUFFERS) SELECT
	date_trunc('day', install_time) AS d,
	COUNT (*) AS agg
FROM
	application_events
WHERE
	application_id = 9
AND event_type = 'install'
AND install_time >= '2015-10-01 0:0+0'
AND install_time < '2015-10-15 0:0+0'
GROUP BY
	1;


	HashAggregate  (cost=228441.33..228450.62 rows=743 width=8) (actual time=90008.946..90008.960 rows=14 loops=1)
  Buffers: shared hit=2 read=100027 dirtied=14 written=1
  ->  Result  (cost=27270.91..228437.62 rows=743 width=8) (actual time=3962.444..90000.102 rows=2309 loops=1)
        Buffers: shared hit=2 read=100027 dirtied=14 written=1
        ->  Append  (cost=27270.91..228435.76 rows=743 width=8) (actual time=3962.417..89982.179 rows=2309 loops=1)
              Buffers: shared hit=2 read=100027 dirtied=14 written=1
              ->  Bitmap Heap Scan on application_events  (cost=27270.91..101320.84 rows=734 width=8) (actual time=3962.416..58885.589 rows=2309 loops=1)
                    Recheck Cond: ((application_id = 9) AND (install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                    Filter: (event_type = 'install'::text)
                    Rows Removed by Filter: 40898
                    Buffers: shared hit=2 read=37332 dirtied=14
                    ->  BitmapAnd  (cost=27270.91..27270.91 rows=25919 width=0) (actual time=3882.849..3882.849 rows=0 loops=1)
                          Buffers: shared hit=2 read=3872
                          ->  Bitmap Index Scan on application_events_application_id  (cost=0.00..3105.75 rows=163909 width=0) (actual time=3141.139..3141.139 rows=176935 loops=1)
                                Index Cond: (application_id = 9)
                                Buffers: shared read=508
                          ->  Bitmap Index Scan on application_events_install_time  (cost=0.00..24164.54 rows=1158811 width=0) (actual time=698.015..698.015 rows=1229886 loops=1)
                                Index Cond: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                                Buffers: shared hit=2 read=3364
              ->  Bitmap Heap Scan on application_events_y2015m09  (cost=1702.64..127114.92 rows=9 width=8) (actual time=31093.584..31093.584 rows=0 loops=1)
                    Recheck Cond: (application_id = 9)
                    Filter: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone) AND (event_type = 'install'::text))
                    Rows Removed by Filter: 99474
                    Buffers: shared read=62695 written=1
                    ->  Bitmap Index Scan on application_events_y2015m09_application_id_idx  (cost=0.00..1702.64 rows=101095 width=0) (actual time=378.215..378.215 rows=99474 loops=1)
                          Index Cond: (application_id = 9)
                          Buffers: shared read=232
Total runtime: 90010.637 ms


Second run

HashAggregate  (cost=228441.33..228450.62 rows=743 width=8) (actual time=100637.633..100637.651 rows=14 loops=1)
  Buffers: shared hit=2 read=100027
  ->  Result  (cost=27270.91..228437.62 rows=743 width=8) (actual time=798.458..100629.886 rows=2309 loops=1)
        Buffers: shared hit=2 read=100027
        ->  Append  (cost=27270.91..228435.76 rows=743 width=8) (actual time=798.446..100614.209 rows=2309 loops=1)
              Buffers: shared hit=2 read=100027
              ->  Bitmap Heap Scan on application_events  (cost=27270.91..101320.84 rows=734 width=8) (actual time=798.445..91071.462 rows=2309 loops=1)
                    Recheck Cond: ((application_id = 9) AND (install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                    Filter: (event_type = 'install'::text)
                    Rows Removed by Filter: 40898
                    Buffers: shared hit=2 read=37332
                    ->  BitmapAnd  (cost=27270.91..27270.91 rows=25919 width=0) (actual time=785.706..785.706 rows=0 loops=1)
                          Buffers: shared hit=2 read=3872
                          ->  Bitmap Index Scan on application_events_application_id  (cost=0.00..3105.75 rows=163909 width=0) (actual time=209.476..209.476 rows=176935 loops=1)
                                Index Cond: (application_id = 9)
                                Buffers: shared read=508
                          ->  Bitmap Index Scan on application_events_install_time  (cost=0.00..24164.54 rows=1158811 width=0) (actual time=532.099..532.099 rows=1229886 loops=1)
                                Index Cond: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                                Buffers: shared hit=2 read=3364
              ->  Bitmap Heap Scan on application_events_y2015m09  (cost=1702.64..127114.92 rows=9 width=8) (actual time=9539.905..9539.905 rows=0 loops=1)
                    Recheck Cond: (application_id = 9)
                    Filter: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone) AND (event_type = 'install'::text))
                    Rows Removed by Filter: 99474
                    Buffers: shared read=62695
                    ->  Bitmap Index Scan on application_events_y2015m09_application_id_idx  (cost=0.00..1702.64 rows=101095 width=0) (actual time=468.593..468.593 rows=99474 loops=1)
                          Index Cond: (application_id = 9)
                          Buffers: shared read=232
Total runtime: 100639.019 ms


Third run.

HashAggregate  (cost=228441.33..228450.62 rows=743 width=8) (actual time=2164.373..2164.385 rows=14 loops=1)
  Buffers: shared hit=3 read=100026
  ->  Result  (cost=27270.91..228437.62 rows=743 width=8) (actual time=562.697..2161.192 rows=2309 loops=1)
        Buffers: shared hit=3 read=100026
        ->  Append  (cost=27270.91..228435.76 rows=743 width=8) (actual time=562.684..2155.202 rows=2309 loops=1)
              Buffers: shared hit=3 read=100026
              ->  Bitmap Heap Scan on application_events  (cost=27270.91..101320.84 rows=734 width=8) (actual time=562.683..1704.544 rows=2309 loops=1)
                    Recheck Cond: ((application_id = 9) AND (install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                    Filter: (event_type = 'install'::text)
                    Rows Removed by Filter: 40898
                    Buffers: shared hit=3 read=37331
                    ->  BitmapAnd  (cost=27270.91..27270.91 rows=25919 width=0) (actual time=549.901..549.901 rows=0 loops=1)
                          Buffers: shared hit=2 read=3872
                          ->  Bitmap Index Scan on application_events_application_id  (cost=0.00..3105.75 rows=163909 width=0) (actual time=83.597..83.597 rows=176935 loops=1)
                                Index Cond: (application_id = 9)
                                Buffers: shared read=508
                          ->  Bitmap Index Scan on application_events_install_time  (cost=0.00..24164.54 rows=1158811 width=0) (actual time=428.053..428.053 rows=1229886 loops=1)
                                Index Cond: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                                Buffers: shared hit=2 read=3364
              ->  Bitmap Heap Scan on application_events_y2015m09  (cost=1702.64..127114.92 rows=9 width=8) (actual time=449.012..449.012 rows=0 loops=1)
                    Recheck Cond: (application_id = 9)
                    Filter: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone) AND (event_type = 'install'::text))
                    Rows Removed by Filter: 99474
                    Buffers: shared read=62695
                    ->  Bitmap Index Scan on application_events_y2015m09_application_id_idx  (cost=0.00..1702.64 rows=101095 width=0) (actual time=27.543..27.543 rows=99474 loops=1)
                          Index Cond: (application_id = 9)
                          Buffers: shared read=232
Total runtime: 2165.431 ms !!!! //Very wird 100% cache hit?


4th run.

HashAggregate  (cost=228441.33..228450.62 rows=743 width=8) (actual time=1332.476..1332.486 rows=14 loops=1)
  Buffers: shared hit=2 read=100027
  ->  Result  (cost=27270.91..228437.62 rows=743 width=8) (actual time=586.576..1329.671 rows=2309 loops=1)
        Buffers: shared hit=2 read=100027
        ->  Append  (cost=27270.91..228435.76 rows=743 width=8) (actual time=586.565..1324.455 rows=2309 loops=1)
              Buffers: shared hit=2 read=100027
              ->  Bitmap Heap Scan on application_events  (cost=27270.91..101320.84 rows=734 width=8) (actual time=586.564..802.173 rows=2309 loops=1)
                    Recheck Cond: ((application_id = 9) AND (install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                    Filter: (event_type = 'install'::text)
                    Rows Removed by Filter: 40898
                    Buffers: shared hit=2 read=37332
                    ->  BitmapAnd  (cost=27270.91..27270.91 rows=25919 width=0) (actual time=574.038..574.038 rows=0 loops=1)
                          Buffers: shared hit=2 read=3872
                          ->  Bitmap Index Scan on application_events_application_id  (cost=0.00..3105.75 rows=163909 width=0) (actual time=66.389..66.389 rows=176935 loops=1)
                                Index Cond: (application_id = 9)
                                Buffers: shared read=508
                          ->  Bitmap Index Scan on application_events_install_time  (cost=0.00..24164.54 rows=1158811 width=0) (actual time=471.092..471.092 rows=1229886 loops=1)
                                Index Cond: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone))
                                Buffers: shared hit=2 read=3364
              ->  Bitmap Heap Scan on application_events_y2015m09  (cost=1702.64..127114.92 rows=9 width=8) (actual time=520.743..520.743 rows=0 loops=1)
                    Recheck Cond: (application_id = 9)
                    Filter: ((install_time >= '2015-10-01 00:00:00+00'::timestamp with time zone) AND (install_time < '2015-10-15 00:00:00+00'::timestamp with time zone) AND (event_type = 'install'::text))
                    Rows Removed by Filter: 99474
                    Buffers: shared read=62695
                    ->  Bitmap Index Scan on application_events_y2015m09_application_id_idx  (cost=0.00..1702.64 rows=101095 width=0) (actual time=35.426..35.426 rows=99474 loops=1)
                          Index Cond: (application_id = 9)
                          Buffers: shared read=232
Total runtime: 1333.781 ms // Great incrases

5th 6th 7th and 8th ~ 1300 - 1400 ms