Re: UPDATEDs slowing SELECTs in a fully cached database

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 07/12/2011 08:13 AM, Ivan Voras wrote:
On 12/07/2011 02:09, lars wrote:

Oh, and iowait hovers around 20% when SELECTs are slow:

avg-cpu: %user %nice %system %iowait %steal %idle
1.54 0.00 0.98 18.49 0.07 78.92

When SELECTs are fast it looks like this:
avg-cpu: %user %nice %system %iowait %steal %idle
8.72 0.00 0.26 0.00 0.00 91.01

Note that this is a 12 core VM. So one core at 100% would show as 8.33%
CPU.

Now only if you could do an "iostat -x" and show the output in both cases...


Sure (sorry for missing details):

iostat -x during selects when all's fine:
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           8.25    0.00    0.00    0.00    0.00   91.75

Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap1 0.00 1.00 0.00 2.00 0.00 24.00 12.00 0.00 0.00 0.00 0.00 xvdf 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdg 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

xvdap1 is OS volumn.
xvdf holds the database files
xvdg holds the WAL

No IO on database/WAL volumes, one core is pegged close to 100% CPU.

------------------------------------

iostat -x during update:
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.05    0.00    0.58    4.00    0.00   94.37

Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdf 0.00 0.00 7.00 0.00 128.00 0.00 18.29 0.00 0.00 0.00 0.00 xvdg 0.00 7352.00 0.00 804.00 0.00 62368.00 77.57 66.07 68.83 0.86 69.20

Just updating the WAL.

-----------------------------------

and while it's checkpointing:
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.64    0.00    0.32    8.88    0.00   90.16

Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdf 0.00 2548.00 2.00 1658.00 32.00 33408.00 20.14 144.18 86.69 0.60 100.00 xvdg 0.00 5428.00 0.00 778.00 0.00 58480.00 75.17 77.44 100.22 1.21 94.00

Updating the WAL, and database volume due to checkpointing.

----------------------------------

iostat -x after I stopped the update process and checkpointing is done:
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.00    0.00    0.00    0.00    0.00  100.00

Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdf 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdg 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00

No activity at all.

---------------------------------

iostat -x after I started the select queries after the updates:
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           2.09    0.00    1.49   12.15    0.00   84.26

Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util xvdap1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 xvdf 0.00 8.00 0.00 2.00 0.00 80.00 40.00 0.00 2.00 2.00 0.40 xvdg 0.00 7844.00 1.00 1098.00 8.00 82336.00 74.93 58.27 59.39 0.70 77.20

Heavy writes to the WAL volume.

select * from pg_stat_activity;
datid | datname | procpid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | qu
ery_start          | waiting |                         current_query
-------+---------+---------+----------+----------+------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+------------
-------------------+---------+---------------------------------------------------------------
16385 | lars | 2654 | 16384 | lars | | 127.0.0.1 | | 44972 | 2011-07-12 18:44:09.479581+00 | 2011-07-12 18:50:32.629412+00 | 2011-07-12 18:50:32.629473+00 | f | select count(*) from test where tenant = $1 and created_date = $2 16385 | lars | 2658 | 10 | postgres | psql | | | -1 | 2011-07-12 18:49:02.675436+00 | 2011-07-12 18:50:32.631013+00 | 2011-07-12
18:50:32.631013+00 | f       | select * from pg_stat_activity;
16385 | lars | 2660 | 16384 | lars | psql | | | -1 | 2011-07-12 18:49:45.711643+00 | |
                   | f       | <IDLE>
(3 rows)


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


[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux