Re: Very slow Query compared to Oracle / SQL - Server

ok one last thing, not to be a PITA, but just in case if this helps.

postgres=# SELECT * FROM pg_stat_user_indexes where relname = 'logtable';
postgres=# SELECT * FROM pg_stat_user_tables where relname = 'logtable';
basically, i just to verify if the table is not bloated.
looking at *n_live_tup* vs *n_dead_tup* would help understand it.

if you see too many dead tuples,
vacuum (ANALYZE,verbose) logtable; -- would get rid of dead tuples (if
there are no tx using the dead tuples)

and then run your query.

Thanks,
Vijay

On Fri, 7 May 2021 at 13:34, Semen Yefimenko <semen(dot)yefimenko(at)gmail(dot)com>
wrote:

> Sorry if I'm cumulatively answering everyone in one E-Mail, I'm not sure
> how I'm supposed to do it. (single E-Mails vs many)
>
>
>> Can you try tuning by increasing the shared_buffers slowly in steps of
>> 500MB, and running explain analyze against the query.
>
>
> -- 2500 MB shared buffers - random_page_cost = 1;
> Gather Merge (cost=343085.23..392186.19 rows=420836 width=2542) (actual
> time=2076.329..3737.050 rows=516517 loops=1)
> Output: column1, .. , column54
> Workers Planned: 2
> Workers Launched: 2
> Buffers: shared hit=295446
> -> Sort (cost=342085.21..342611.25 rows=210418 width=2542) (actual
> time=2007.487..2202.707 rows=172172 loops=3)
> Output: column1, .. , column54
> Sort Key: logtable.timestampcol DESC
> Sort Method: quicksort Memory: 65154kB
> Worker 0: Sort Method: quicksort Memory: 55707kB
> Worker 1: Sort Method: quicksort Memory: 55304kB
> Buffers: shared hit=295446
> Worker 0: actual time=1963.969..2156.624 rows=161205 loops=1
> Buffers: shared hit=91028
> Worker 1: actual time=1984.700..2179.697 rows=161935 loops=1
> Buffers: shared hit=92133
> -> Parallel Bitmap Heap Scan on schema.logtable
> (cost=5546.39..323481.21 rows=210418 width=2542) (actual
> time=322.125..1618.971 rows=172172 loops=3)
> Output: column1, .. , column54
> Recheck Cond: ((logtable.entrytype = 4000) OR
> (logtable.entrytype = 4001) OR (logtable.entrytype = 4002))
> Filter: (logtable.archivestatus <= 1)
> Heap Blocks: exact=110951
> Buffers: shared hit=295432
> Worker 0: actual time=282.201..1595.117 rows=161205 loops=1
> Buffers: shared hit=91021
> Worker 1: actual time=303.671..1623.299 rows=161935 loops=1
> Buffers: shared hit=92126
> -> BitmapOr (cost=5546.39..5546.39 rows=510578 width=0)
> (actual time=199.119..199.119 rows=0 loops=1)
> Buffers: shared hit=1334
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..682.13 rows=67293 width=0) (actual time=28.856..28.857
> rows=65970 loops=1)
> Index Cond: (logtable.entrytype = 4000)
> Buffers: shared hit=172
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..2223.63 rows=219760 width=0) (actual time=108.871..108.872
> rows=225283 loops=1)
> Index Cond: (logtable.entrytype = 4001)
> Buffers: shared hit=581
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..2261.87 rows=223525 width=0) (actual time=61.377..61.377
> rows=225264 loops=1)
> Index Cond: (logtable.entrytype = 4002)
> Buffers: shared hit=581
> Settings: random_page_cost = '1', temp_buffers = '80MB', work_mem = '1GB'
> Planning Time: 0.940 ms
> Execution Time: 4188.083 ms
>
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> -- 3000 MB shared buffers - random_page_cost = 1;
> Gather Merge (cost=343085.23..392186.19 rows=420836 width=2542) (actual
> time=2062.280..3763.408 rows=516517 loops=1)
> Output: column1, .. , column54
> Workers Planned: 2
> Workers Launched: 2
> Buffers: shared hit=295446
> -> Sort (cost=342085.21..342611.25 rows=210418 width=2542) (actual
> time=1987.933..2180.422 rows=172172 loops=3)
> Output: column1, .. , column54
> Sort Key: logtable.timestampcol DESC
> Sort Method: quicksort Memory: 66602kB
> Worker 0: Sort Method: quicksort Memory: 55149kB
> Worker 1: Sort Method: quicksort Memory: 54415kB
> Buffers: shared hit=295446
> Worker 0: actual time=1963.059..2147.916 rows=159556 loops=1
> Buffers: shared hit=89981
> Worker 1: actual time=1949.726..2136.200 rows=158554 loops=1
> Buffers: shared hit=90141
> -> Parallel Bitmap Heap Scan on schema.logtable
> (cost=5546.39..323481.21 rows=210418 width=2542) (actual
> time=340.705..1603.796 rows=172172 loops=3)
> Output: column1, .. , column54
> Recheck Cond: ((logtable.entrytype = 4000) OR
> (logtable.entrytype = 4001) OR (logtable.entrytype = 4002))
> Filter: (logtable.archivestatus <= 1)
> Heap Blocks: exact=113990
> Buffers: shared hit=295432
> Worker 0: actual time=317.918..1605.548 rows=159556 loops=1
> Buffers: shared hit=89974
> Worker 1: actual time=304.744..1589.221 rows=158554 loops=1
> Buffers: shared hit=90134
> -> BitmapOr (cost=5546.39..5546.39 rows=510578 width=0)
> (actual time=218.972..218.973 rows=0 loops=1)
> Buffers: shared hit=1334
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..682.13 rows=67293 width=0) (actual time=37.741..37.742
> rows=65970 loops=1)
> Index Cond: (logtable.entrytype = 4000)
> Buffers: shared hit=172
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..2223.63 rows=219760 width=0) (actual time=119.120..119.121
> rows=225283 loops=1)
> Index Cond: (logtable.entrytype = 4001)
> Buffers: shared hit=581
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..2261.87 rows=223525 width=0) (actual time=62.097..62.098
> rows=225264 loops=1)
> Index Cond: (logtable.entrytype = 4002)
> Buffers: shared hit=581
> Settings: random_page_cost = '1', temp_buffers = '80MB', work_mem = '1GB'
> Planning Time: 2.717 ms
> Execution Time: 4224.670 ms
>
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> -- 3500 MB shared buffers - random_page_cost = 1;
> Gather Merge (cost=343085.23..392186.19 rows=420836 width=2542) (actual
> time=3578.155..4932.858 rows=516517 loops=1)
> Output: column1, .. , column54
> Workers Planned: 2
> Workers Launched: 2
> Buffers: shared hit=14 read=295432 written=67
> -> Sort (cost=342085.21..342611.25 rows=210418 width=2542) (actual
> time=3482.159..3677.227 rows=172172 loops=3)
> Output: column1, .. , column54
> Sort Key: logtable.timestampcol DESC
> Sort Method: quicksort Memory: 58533kB
> Worker 0: Sort Method: quicksort Memory: 56878kB
> Worker 1: Sort Method: quicksort Memory: 60755kB
> Buffers: shared hit=14 read=295432 written=67
> Worker 0: actual time=3435.131..3632.985 rows=166842 loops=1
> Buffers: shared hit=7 read=95783 written=25
> Worker 1: actual time=3441.545..3649.345 rows=179354 loops=1
> Buffers: shared hit=5 read=101608 written=20
> -> Parallel Bitmap Heap Scan on schema.logtable
> (cost=5546.39..323481.21 rows=210418 width=2542) (actual
> time=345.111..3042.932 rows=172172 loops=3)
> Output: column1, .. , column54
> Recheck Cond: ((logtable.entrytype = 4000) OR
> (logtable.entrytype = 4001) OR (logtable.entrytype = 4002))
> Filter: (logtable.archivestatus <= 1)
> Heap Blocks: exact=96709
> Buffers: shared hit=2 read=295430 written=67
> Worker 0: actual time=300.525..2999.403 rows=166842 loops=1
> Buffers: shared read=95783 written=25
> Worker 1: actual time=300.552..3004.859 rows=179354 loops=1
> Buffers: shared read=101606 written=20
> -> BitmapOr (cost=5546.39..5546.39 rows=510578 width=0)
> (actual time=241.996..241.997 rows=0 loops=1)
> Buffers: shared hit=2 read=1332
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..682.13 rows=67293 width=0) (actual time=37.129..37.130
> rows=65970 loops=1)
> Index Cond: (logtable.entrytype = 4000)
> Buffers: shared read=172
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..2223.63 rows=219760 width=0) (actual time=131.051..131.052
> rows=225283 loops=1)
> Index Cond: (logtable.entrytype = 4001)
> Buffers: shared hit=1 read=580
> -> Bitmap Index Scan on idx_entrytype
> (cost=0.00..2261.87 rows=223525 width=0) (actual time=73.800..73.800
> rows=225264 loops=1)
> Index Cond: (logtable.entrytype = 4002)
> Buffers: shared hit=1 read=580
> Settings: random_page_cost = '1', temp_buffers = '80MB', work_mem = '1GB'
> Planning Time: 0.597 ms
> Execution Time: 5389.811 ms
>
>
> This doesn't seem to have had an effect.
> Thanks for the suggestion.
>
> Have you try of excluding not null from index? Can you give dispersion of
>> archivestatus?
>>
>
> Yes I have, it yielded the same performance boost as :
>
> create index test on logtable(entrytype) where archivestatus <= 1;
>
> I wonder what the old query plan was...
>> Would you include links to your prior correspondance ?
>
>
> So prior Execution Plans are present in the SO.
> The other forums I've tried are the official slack channel :
> https://postgresteam.slack.com/archives/C0FS3UTAP/p1620286295228600
> And SO :
> https://stackoverflow.com/questions/67401792/slow-running-postgresql-query
> But I think most of the points discussed in these posts have already been
> mentionend by you except bloating of indexes.
>
> Oracle is apparently doing a single scan on "entrytype".
>> As a test, you could try forcing that, like:
>> begin; SET enable_bitmapscan=off ; explain (analyze) [...]; rollback;
>> or
>> begin; DROP INDEX idx_arcstatus; explain (analyze) [...]; rollback;
>
>
> I've tried enable_bitmapscan=off but it didn't yield any good results.
>
> -- 2000 MB shared buffers - random_page_cost = 4 - enable_bitmapscan to off
> Gather Merge (cost=543949.72..593050.69 rows=420836 width=2542) (actual
> time=7716.031..9043.399 rows=516517 loops=1)
> Output: column1, .., column54
> Workers Planned: 2
> Workers Launched: 2
> Buffers: shared hit=192 read=406605
> -> Sort (cost=542949.70..543475.75 rows=210418 width=2542) (actual
> time=7642.666..7835.527 rows=172172 loops=3)
> Output: column1, .., column54
> Sort Key: logtable.timestampcol DESC
> Sort Method: quicksort Memory: 58803kB
> Worker 0: Sort Method: quicksort Memory: 60376kB
> Worker 1: Sort Method: quicksort Memory: 56988kB
> Buffers: shared hit=192 read=406605
> Worker 0: actual time=7610.482..7814.905 rows=177637 loops=1
> Buffers: shared hit=78 read=137826
> Worker 1: actual time=7607.645..7803.561 rows=167316 loops=1
> Buffers: shared hit=80 read=132672
> -> Parallel Seq Scan on schema.logtable (cost=0.00..524345.70
> rows=210418 width=2542) (actual time=1.669..7189.365 rows=172172 loops=3)
> Output: column1, .., column54
> Filter: ((logtable.acrhivestatus <= 1) AND
> ((logtable.entrytype = 4000) OR (logtable.entrytype = 4001) OR
> (logtable.entrytype = 4002)))
> Rows Removed by Filter: 4533459
> Buffers: shared hit=96 read=406605
> Worker 0: actual time=1.537..7158.286 rows=177637 loops=1
> Buffers: shared hit=30 read=137826
> Worker 1: actual time=1.414..7161.670 rows=167316 loops=1
> Buffers: shared hit=32 read=132672
> Settings: enable_bitmapscan = 'off', temp_buffers = '80MB', work_mem =
> '1GB'
> Planning Time: 0.725 ms
> Execution Time: 9500.928 ms
> ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> 2000 MB shared buffers - random_page_cost = 4 - -- 2000 -- 2000 MB shared
> buffers - random_page_cost = 1 - enable_bitmapscan to off
> Gather Merge (cost=543949.72..593050.69 rows=420836 width=2542) (actual
> time=7519.032..8871.433 rows=516517 loops=1)
> Output: column1, .., column54
> Workers Planned: 2
> Workers Launched: 2
> Buffers: shared hit=576 read=406221
> -> Sort (cost=542949.70..543475.75 rows=210418 width=2542) (actual
> time=7451.958..7649.480 rows=172172 loops=3)
> Output: column1, .., column54
> Sort Key: logtable.timestampcol DESC
> Sort Method: quicksort Memory: 58867kB
> Worker 0: Sort Method: quicksort Memory: 58510kB
> Worker 1: Sort Method: quicksort Memory: 58788kB
> Buffers: shared hit=576 read=406221
> Worker 0: actual time=7438.271..7644.241 rows=172085 loops=1
> Buffers: shared hit=203 read=135166
> Worker 1: actual time=7407.574..7609.922 rows=172948 loops=1
> Buffers: shared hit=202 read=135225
> -> Parallel Seq Scan on schema.logtable (cost=0.00..524345.70
> rows=210418 width=2542) (actual time=2.839..7017.729 rows=172172 loops=3)
> Output: column1, .., column54
> Filter: ((logtable.acrhivestatus <= 1) AND
> ((logtable.entrytype = 4000) OR (logtable.entrytype = 4001) OR
> (logtable.entrytype = 4002)))
> Rows Removed by Filter: 4533459
> Buffers: shared hit=480 read=406221
> Worker 0: actual time=2.628..7006.420 rows=172085 loops=1
> Buffers: shared hit=155 read=135166
> Worker 1: actual time=3.948..6978.154 rows=172948 loops=1
> Buffers: shared hit=154 read=135225
> Settings: enable_bitmapscan = 'off', random_page_cost = '1', temp_buffers
> = '80MB', work_mem = '1GB'
> Planning Time: 0.621 ms
> Execution Time: 9339.457 ms
>
> Have you tune shared buffers enough? Each block is of 8k by default.
>> BTW, please try to reset random_page_cost.
>
>
> Look above.
>
> I will try upgrading the minor version next.
> I will also try setting up a 13.X version locally and import the data from
> 12.2 to 13.X and see if it might be faster.
>
>
> Am Do., 6. Mai 2021 um 23:16 Uhr schrieb Imre Samu <pella(dot)samu(at)gmail(dot)com>:
>
>> *> Postgres Version : *PostgreSQL 12.2,
>> > ... ON ... USING btree
>>
>> IMHO:
>> The next minor (bugix&security) release is near ( expected ~ May 13th,
>> 2021 ) https://www.postgresql.org/developer/roadmap/
>> so you can update your PostgreSQL to 12.7 ( + full Reindexing
>> recommended ! )
>>
>> You can find a lot of B-tree index-related fixes.
>> https://www.postgresql.org/docs/12/release-12-3.html Release date:
>> 2020-05-14
>> - Fix possible undercounting of deleted B-tree index pages in VACUUM
>> VERBOSE output
>> - Fix wrong bookkeeping for oldest deleted page in a B-tree index
>> - Ensure INCLUDE'd columns are always removed from B-tree pivot tuples
>> https://www.postgresql.org/docs/12/release-12-4.html
>> - Avoid repeated marking of dead btree index entries as dead
>> https://www.postgresql.org/docs/12/release-12-5.html
>> - Fix failure of parallel B-tree index scans when the index condition
>> is unsatisfiable
>> https://www.postgresql.org/docs/12/release-12-6.html Release date:
>> 2021-02-11
>>
>>
>> > COLLATE pg_catalog."default"
>>
>> You can test the "C" Collation in some columns (keys ? ) ; in theory,
>> it should be faster :
>> "The drawback of using locales other than C or POSIX in PostgreSQL is its
>> performance impact. It slows character handling and prevents ordinary
>> indexes from being used by LIKE. For this reason use locales only if you
>> actually need them."
>> https://www.postgresql.org/docs/12/locale.html
>>
>> https://www.postgresql.org/message-id/flat/CAF6DVKNU0vb4ZeQQ-%3Dagg69QJU3wdjPnMYYrPYY7CKc6iOU7eQ%40mail.gmail.com
>>
>> Best,
>> Imre
>>
>>
>> Semen Yefimenko <semen(dot)yefimenko(at)gmail(dot)com> ezt írta (időpont: 2021.
>> máj. 6., Cs, 16:38):
>>
>>> Hi there,
>>>
>>> I've recently been involved in migrating our old system to SQL Server
>>> and then PostgreSQL. Everything has been working fine so far but now after
>>> executing our tests on Postgres, we saw a very slow running query on a
>>> large table in our database.
>>> I have tried asking on other platforms but no one has been able to give
>>> me a satisfying answer.
>>>
>>> *Postgres Version : *PostgreSQL 12.2, compiled by Visual C++ build
>>> 1914, 64-bit
>>> No notable errors in the Server log and the Postgres Server itself.
>>>
>>> The table structure :
>>>
>>> CREATE TABLE logtable
>>> (
>>> key character varying(20) COLLATE pg_catalog."default" NOT NULL,
>>> id integer,
>>> column3 integer,
>>> column4 integer,
>>> column5 integer,
>>> column6 integer,
>>> column7 integer,
>>> column8 integer,
>>> column9 character varying(128) COLLATE pg_catalog."default",
>>> column10 character varying(2048) COLLATE pg_catalog."default",
>>> column11 character varying(2048) COLLATE pg_catalog."default",
>>> column12 character varying(2048) COLLATE pg_catalog."default",
>>> column13 character varying(2048) COLLATE pg_catalog."default",
>>> column14 character varying(2048) COLLATE pg_catalog."default",
>>> column15 character varying(2048) COLLATE pg_catalog."default",
>>> column16 character varying(2048) COLLATE pg_catalog."default",
>>> column17 character varying(2048) COLLATE pg_catalog."default",
>>> column18 character varying(2048) COLLATE pg_catalog."default",
>>> column19 character varying(2048) COLLATE pg_catalog."default",
>>> column21 character varying(256) COLLATE pg_catalog."default",
>>> column22 character varying(256) COLLATE pg_catalog."default",
>>> column23 character varying(256) COLLATE pg_catalog."default",
>>> column24 character varying(256) COLLATE pg_catalog."default",
>>> column25 character varying(256) COLLATE pg_catalog."default",
>>> column26 character varying(256) COLLATE pg_catalog."default",
>>> column27 character varying(256) COLLATE pg_catalog."default",
>>> column28 character varying(256) COLLATE pg_catalog."default",
>>> column29 character varying(256) COLLATE pg_catalog."default",
>>> column30 character varying(256) COLLATE pg_catalog."default",
>>> column31 character varying(256) COLLATE pg_catalog."default",
>>> column32 character varying(256) COLLATE pg_catalog."default",
>>> column33 character varying(256) COLLATE pg_catalog."default",
>>> column34 character varying(256) COLLATE pg_catalog."default",
>>> column35 character varying(256) COLLATE pg_catalog."default",
>>> entrytype integer,
>>> column37 bigint,
>>> column38 bigint,
>>> column39 bigint,
>>> column40 bigint,
>>> column41 bigint,
>>> column42 bigint,
>>> column43 bigint,
>>> column44 bigint,
>>> column45 bigint,
>>> column46 bigint,
>>> column47 character varying(128) COLLATE pg_catalog."default",
>>> timestampcol timestamp without time zone,
>>> column49 timestamp without time zone,
>>> column50 timestamp without time zone,
>>> column51 timestamp without time zone,
>>> column52 timestamp without time zone,
>>> archivestatus integer,
>>> column54 integer,
>>> column55 character varying(20) COLLATE pg_catalog."default",
>>> CONSTRAINT pkey PRIMARY KEY (key)
>>> USING INDEX TABLESPACE tablespace
>>> )
>>>
>>> TABLESPACE tablespace;
>>>
>>> ALTER TABLE schema.logtable
>>> OWNER to user;
>>>
>>> CREATE INDEX idx_timestampcol
>>> ON schema.logtable USING btree
>>> ( timestampcol ASC NULLS LAST )
>>> TABLESPACE tablespace ;
>>>
>>> CREATE INDEX idx_test2
>>> ON schema.logtable USING btree
>>> ( entrytype ASC NULLS LAST)
>>> TABLESPACE tablespace
>>> WHERE archivestatus <= 1;
>>>
>>> CREATE INDEX idx_arcstatus
>>> ON schema.logtable USING btree
>>> ( archivestatus ASC NULLS LAST)
>>> TABLESPACE tablespace;
>>>
>>> CREATE INDEX idx_entrytype
>>> ON schema.logtable USING btree
>>> ( entrytype ASC NULLS LAST)
>>> TABLESPACE tablespace ;
>>>
>>>
>>> The table contains 14.000.000 entries and has about 3.3 GB of data:
>>> No triggers, inserts per day, probably 5-20 K per day.
>>>
>>> SELECT relname, relpages, reltuples, relallvisible, relkind, relnatts,
>>> relhassubclass, reloptions, pg_table_size(oid) FROM pg_class WHERE
>>> relname='logtable';
>>>
>>> relname
>>> |relpages|reltuples|relallvisible|relkind|relnatts|relhassubclass|reloptions|pg_table_size|
>>>
>>> ------------------|--------|---------|-------------|-------|--------|--------------|----------|-------------|
>>> logtable | 405988| 14091424| 405907|r |
>>> 54|false |NULL | 3326803968|
>>>
>>>
>>> The slow running query:
>>>
>>> SELECT column1,..., column54 where ((entrytype = 4000 or entrytype =
>>> 4001 or entrytype = 4002) and (archivestatus <= 1)) order by timestampcol
>>> desc;
>>>
>>>
>>> This query runs in about 45-60 seconds.
>>> The same query runs in about 289 ms Oracle and 423 ms in SQL-Server.
>>> Now I understand that actually loading all results would take a while.
>>> (about 520K or so rows)
>>> But that shouldn't be exactly what happens right? There should be a
>>> resultset iterator which can retrieve all data but doesn't from the get go.
>>>
>>> With the help of some people in the slack and so thread, I've found a
>>> configuration parameter which helps performance :
>>>
>>> set random_page_cost = 1;
>>>
>>> This improved performance from 45-60 s to 15-35 s. (since we are using
>>> ssd's)
>>> Still not acceptable but definitely an improvement.
>>> Some maybe relevant system parameters:
>>>
>>> effective_cache_size 4GB
>>> maintenance_work_mem 1GB
>>> shared_buffers 2GB
>>> work_mem 1GB
>>>
>>>
>>> Currently I'm accessing the data through DbBeaver (JDBC -
>>> postgresql-42.2.5.jar) and our JAVA application (JDBC -
>>> postgresql-42.2.19.jar). Both use the defaultRowFetchSize=5000 to not load
>>> everything into memory and limit the results.
>>> The explain plan:
>>>
>>> EXPLAIN (ANALYZE, BUFFERS, SETTINGS, VERBOSE)...
>>> (Above Query)
>>>
>>>
>>> Gather Merge (cost=347142.71..397196.91 rows=429006 width=2558) (actual
>>> time=21210.019..22319.444 rows=515841 loops=1)
>>> Output: column1, .. , column54
>>> Workers Planned: 2
>>> Workers Launched: 2
>>> Buffers: shared hit=141487 read=153489
>>> -> Sort (cost=346142.69..346678.95 rows=214503 width=2558) (actual
>>> time=21148.887..21297.428 rows=171947 loops=3)
>>> Output: column1, .. , column54
>>> Sort Key: logtable.timestampcol DESC
>>> Sort Method: quicksort Memory: 62180kB
>>> Worker 0: Sort Method: quicksort Memory: 56969kB
>>> Worker 1: Sort Method: quicksort Memory: 56837kB
>>> Buffers: shared hit=141487 read=153489
>>> Worker 0: actual time=21129.973..21296.839 rows=166776 loops=1
>>> Buffers: shared hit=45558 read=49514
>>> Worker 1: actual time=21114.439..21268.117 rows=165896 loops=1
>>> Buffers: shared hit=45104 read=49506
>>> -> Parallel Bitmap Heap Scan on schema.logtable
>>> (cost=5652.74..327147.77 rows=214503 width=2558) (actual
>>> time=1304.813..20637.462 rows=171947 loops=3)
>>> Output: column1, .. , column54
>>> Recheck Cond: ((logtable.entrytype = 4000) OR
>>> (logtable.entrytype = 4001) OR (logtable.entrytype = 4002))
>>> Filter: (logtable.archivestatus <= 1)
>>> Heap Blocks: exact=103962
>>> Buffers: shared hit=141473 read=153489
>>> Worker 0: actual time=1280.472..20638.620 rows=166776
>>> loops=1
>>> Buffers: shared hit=45551 read=49514
>>> Worker 1: actual time=1275.274..20626.219 rows=165896
>>> loops=1
>>> Buffers: shared hit=45097 read=49506
>>> -> BitmapOr (cost=5652.74..5652.74 rows=520443 width=0)
>>> (actual time=1179.438..1179.438 rows=0 loops=1)
>>> Buffers: shared hit=9 read=1323
>>> -> Bitmap Index Scan on idx_entrytype
>>> (cost=0.00..556.61 rows=54957 width=0) (actual time=161.939..161.940
>>> rows=65970 loops=1)
>>> Index Cond: (logtable.entrytype = 4000)
>>> Buffers: shared hit=1 read=171
>>> -> Bitmap Index Scan on idx_entrytype
>>> (cost=0.00..2243.22 rows=221705 width=0) (actual time=548.849..548.849
>>> rows=224945 loops=1)
>>> Index Cond: (logtable.entrytype = 4001)
>>> Buffers: shared hit=4 read=576
>>> -> Bitmap Index Scan on idx_entrytype
>>> (cost=0.00..2466.80 rows=243782 width=0) (actual time=468.637..468.637
>>> rows=224926 loops=1)
>>> Index Cond: (logtable.entrytype = 4002)
>>> Buffers: shared hit=4 read=576
>>> Settings: random_page_cost = '1', search_path = '"$user", schema,
>>> public', temp_buffers = '80MB', work_mem = '1GB'
>>> Planning Time: 0.578 ms
>>> Execution Time: 22617.351 ms
>>>
>>> As mentioned before, oracle does this much faster.
>>>
>>>
>>> -------------------------------------------------------------------------------------------------------------------------
>>> | Id | Operation | Name
>>> | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
>>>
>>> -------------------------------------------------------------------------------------------------------------------------
>>> | 0 | SELECT STATEMENT |
>>> | 6878 | 2491K| | 2143 (1)| 00:00:01 |
>>> | 1 | SORT ORDER BY |
>>> | 6878 | 2491K| 3448K| 2143 (1)| 00:00:01 |
>>> | 2 | INLIST ITERATOR |
>>> | | | | | |
>>> |* 3 | TABLE ACCESS BY INDEX ROWID BATCHED| logtable
>>> | 6878 | 2491K| | 1597 (1)| 00:00:01 |
>>> |* 4 | INDEX RANGE SCAN | idx_entrytype
>>> | 6878 | | | 23 (0)| 00:00:01 |
>>>
>>> -------------------------------------------------------------------------------------------------------------------------
>>>
>>> Is there much I can analyze, any information you might need to further
>>> analyze this?
>>>
>>

--
Thanks,
Vijay
Mumbai, India