Re: [BUGS] BUG #14635: Query is executed slower on hot standby slavedatabase then on master database
Hello,
I didn't found a way how to write a response for your message on Postgresql support web site, I didn't find ant button like "Response" or "New comment" or so. Can you please share this info, maybe there is present an instruction?
Will write my response by mail.
Yes, it happens always.
There is an execution plan from master:
texting=# explain (analyze, verbose, buffers) SELECT "om".* FROM "Table" AS "om" WHERE (om."UserID" = 11111) AND (NOT om."Deleted") AND (om."Status" = 0) ORDER BY "StampToSend" asc LIMIT 11;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------
----------------------------------------------
Limit (cost=3819.29..3819.30 rows=6 width=207) (actual time=139.847..139.847 rows=0 loops=1)
Output: "ID", "MessageTypeID", "ServerID", "UserID", "RecipientsCount", "Credits", "Subject", "Message", "StampToSend", "StampProcessed"
, "SendToNewRecipients", "StampNewRecipientsChecked", "InsufficientCreditsEmailSent", "Deleted", "Status", "CreatedAt", "UpdatedAt", "Code"
, "Source", "MultiplePartsNumber"
Buffers: shared hit=70256
-> Sort (cost=3819.29..3819.30 rows=6 width=207) (actual time=139.845..139.845 rows=0 loops=1)
Output: "ID", "MessageTypeID", "ServerID", "UserID", "RecipientsCount", "Credits", "Subject", "Message", "StampToSend", "StampProc
essed", "SendToNewRecipients", "StampNewRecipientsChecked", "InsufficientCreditsEmailSent", "Deleted", "Status", "CreatedAt", "UpdatedAt",
"Code", "Source", "MultiplePartsNumber"
Sort Key: om."StampToSend"
Sort Method: quicksort Memory: 25kB
Buffers: shared hit=70256
-> Bitmap Heap Scan on public."Table" om (cost=3795.14..3819.21 rows=6 width=207) (actual time=139.836..139.836 rows=
0 loops=1)
Output: "ID", "MessageTypeID", "ServerID", "UserID", "RecipientsCount", "Credits", "Subject", "Message", "StampToSend", "Sta
mpProcessed", "SendToNewRecipients", "StampNewRecipientsChecked", "InsufficientCreditsEmailSent", "Deleted", "Status", "CreatedAt", "Update
dAt", "Code", "Source", "MultiplePartsNumber"
Recheck Cond: ((om."UserID" = 11111) AND (om."Status" = 0))
Filter: (NOT om."Deleted")
Buffers: shared hit=70256
-> BitmapAnd (cost=3795.14..3795.14 rows=6 width=0) (actual time=139.832..139.832 rows=0 loops=1)
Buffers: shared hit=70256
-> Bitmap Index Scan on "OutgoingMessages_UserID" (cost=0.00..237.99 rows=6872 width=0) (actual time=0.032..0.032 ro
ws=12 loops=1)
Index Cond: (om."UserID" = 11111)
Buffers: shared hit=4
-> Bitmap Index Scan on "OutgoingMessages_Status_StampToSend_Deleted" (cost=0.00..3556.90 rows=80249 width=0) (actua
l time=139.761..139.761 rows=9158 loops=1)
Index Cond: ((om."Status" = 0) AND (om."Deleted" = false))
Buffers: shared hit=70252
Total runtime: 139.900 ms
(22 rows)
There is an execution plan from slave:
texting=# explain (analyze, verbose, buffers) SELECT "om".* FROM "Table" AS "om" WHERE (om."UserID" = 11111) AND (NOT om."Deleted") AND (om."Status" = 0) ORDER BY "StampToSend" asc LIMIT 11;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
-------------------------------------------------------------------------------------------------------------------------------------------
----------------------------------------------
Limit (cost=3819.29..3819.30 rows=6 width=207) (actual time=1472.199..1472.199 rows=0 loops=1)
Output: "ID", "MessageTypeID", "ServerID", "UserID", "RecipientsCount", "Credits", "Subject", "Message", "StampToSend", "StampProcessed"
, "SendToNewRecipients", "StampNewRecipientsChecked", "InsufficientCreditsEmailSent", "Deleted", "Status", "CreatedAt", "UpdatedAt", "Code"
, "Source", "MultiplePartsNumber"
Buffers: shared hit=70256
-> Sort (cost=3819.29..3819.30 rows=6 width=207) (actual time=1472.197..1472.197 rows=0 loops=1)
Output: "ID", "MessageTypeID", "ServerID", "UserID", "RecipientsCount", "Credits", "Subject", "Message", "StampToSend", "StampProc
essed", "SendToNewRecipients", "StampNewRecipientsChecked", "InsufficientCreditsEmailSent", "Deleted", "Status", "CreatedAt", "UpdatedAt",
"Code", "Source", "MultiplePartsNumber"
Sort Key: om."StampToSend"
Sort Method: quicksort Memory: 25kB
Buffers: shared hit=70256
-> Bitmap Heap Scan on public."Table" om (cost=3795.14..3819.21 rows=6 width=207) (actual time=1472.191..1472.191 row
s=0 loops=1)
Output: "ID", "MessageTypeID", "ServerID", "UserID", "RecipientsCount", "Credits", "Subject", "Message", "StampToSend", "Sta
mpProcessed", "SendToNewRecipients", "StampNewRecipientsChecked", "InsufficientCreditsEmailSent", "Deleted", "Status", "CreatedAt", "Update
dAt", "Code", "Source", "MultiplePartsNumber"
Recheck Cond: ((om."UserID" = 11111) AND (om."Status" = 0))
Filter: (NOT om."Deleted")
Buffers: shared hit=70256
-> BitmapAnd (cost=3795.14..3795.14 rows=6 width=0) (actual time=1472.186..1472.186 rows=0 loops=1)
Buffers: shared hit=70256
-> Bitmap Index Scan on "OutgoingMessages_UserID" (cost=0.00..237.99 rows=6872 width=0) (actual time=0.025..0.025 ro
ws=12 loops=1)
Index Cond: (om."UserID" = 11111)
Buffers: shared hit=4
-> Bitmap Index Scan on "OutgoingMessages_Status_StampToSend_Deleted" (cost=0.00..3556.90 rows=80249 width=0) (actua
l time=1470.853..1470.853 rows=8671249 loops=1)
Index Cond: ((om."Status" = 0) AND (om."Deleted" = false))
Buffers: shared hit=70252
Total runtime: 1472.253 ms
(22 rows)
The difference is:
-> Bitmap Index Scan on "OutgoingMessages_Status_StampToSend_Deleted" (cost=0.00..3556.90 rows=80249 width=0) (actual time=139.761..139.761 rows=9158 loops=1)
-> Bitmap Index Scan on "OutgoingMessages_Status_StampToSend_Deleted" (cost=0.00..3556.90 rows=80249 width=0) (actual time=1470.853..1470.853 rows=8671249 loops=1)
On Tue, May 2, 2017 at 4:20 PM, Haribabu Kommi <kommi.haribabu@gmail.com> wrote:
On Fri, Apr 28, 2017 at 11:38 PM, <vgomenyuk@callfire.com> wrote:The following bug has been logged on the website:
Bug reference: 14635
Logged by: Vitaliy Gomenyuk
Email address: vgomenyuk@callfire.com
PostgreSQL version: 9.2.14
Operating system: CentOS 6
Description:
Hello,
We have two equal servers (CPU, RAM, HDD).
We are using Postgresql 9.2.14 currently.
Have setup master-slave streaming replication.
Running next query at master and slave databases:
explain analyze SELECT "om".* FROM "Table" AS "om" WHERE (om."UserID" =
11111) AND (NOT om."Deleted") AND (om."Status" = 0) ORDER BY "StampToSend"
asc LIMIT 11;
An execution plans are the same on master and slave databases.
An execution time on master database: 138.116 ms
An execution time on hot standby slave database with working replication:
1623.496 ms
An execution time on slave database with turned off replication (after
creating trigger file): 132.354 ms (equal to an execution time on master
database).
Why there is so huge difference in execution time between Postgresql with
and without working streaming replication?
How to improve the situation: to make an execution time on Hot standby slave
dtabase with working replication equeal to master database?Is the issue happening always or only sometimes?can you please check explain plan output on both the machines with verboseand buffers options.explain (analyze, verbose, buffers) /*query*/The explain output may help in identifying the plan of the query where it is takingmore time compared to master.Regards,Hari BabuFujitsu Australia
Best regards,
 | Vitaliy Gomenyuk Senior DBA vgomenyuk@callfire.com | +380 67 220 5903 email | website | Facebook | Twitter |
В списке pgsql-bugs по дате отправления:
Предыдущее
От: Michael PaquierДата:
Сообщение: Re: [BUGS] Concurrent ALTER SEQUENCE RESTART Regression
Следующее
От: Haribabu KommiДата:
Сообщение: Re: [HACKERS] Re: [BUGS] BUG #14634: On Windows pg_basebackup shouldwrite tar to stdout in binary mode