I'm trying to get to the bottom of a performance issue on a server
running PostgreSQL 9.3.1 on Centos 5. The machine is a dual quad-core
Xeon E5620 with 24GB ECC RAM and four enterprise SATA Seagate
Constellation ES drives configured as 2 software RAID1 volumes. The
main DB is on one volume and some, more used indexes and WAL logs are on
the other.
Overall, the load doesn't appear to be heavy, but we're still getting
slow queries, for example, here's an extract from the log:
2014-04-28 16:51:02.904 GMT 25998: LOG: checkpoint starting: time
2014-04-28 16:53:37.204 GMT 30053: LOG: duration: 1067.464 ms execute
<unnamed>: select "id" from "ProductSupplier" where
"product"='25553848082928'
2014-04-28 16:54:12.701 GMT 30053: LOG: duration: 1105.844 ms execute
<unnamed>: select "id" from "ProductSupplier" where
"product"='1626407082928'
2014-04-28 16:54:46.789 GMT 30053: LOG: duration: 1060.585 ms execute
<unnamed>: select
"id","updated","ean","frontImagePresent","backImagePresent","jacketScanned","x80ImagePresent","x120ImagePresent","x200ImagePresent","x400ImagePresent","type","brand","manProductCode","name","series","subtitle","keywords","mass","length","width","thickness","releaseDate","originalReleaseDate","firstAvailableDate","stockLevel","stockCost","url","ratingTotal","ratingCount","beta","available","reorderSource","reorderPoint","reorderQuantity","status","replacement","countryOfOrigin","formType","formDetail","formDetail1","formDetail2","formDetail3","formDetail4","contentType","packagingType","ebookType","mixedMedia","mediaCount","shortAnnotationType","longAnnotationType","wikipediaTopic","allMusicId","allMovieId","allGameId","imdbId","boost","salesMovingAverage","movingAverageDate","lifetimeSales","shippingRequirement","shippingSubsidyCalculator","edition","dewey","lcc","lccn","pages","minutes","bicSubjects","bisacSubjects","regionEncoding","audioFormat","videoFormat","platform","audit"
from "Product" where id='6686838082928'
2014-04-28 16:55:58.058 GMT 30053: LOG: duration: 1309.192 ms execute
<unnamed>: select "id" from "ProductCategory" where
"product"='1932872082928'
2014-04-28 16:56:06.019 GMT 25998: LOG: checkpoint complete: wrote 6647
buffers (2.5%); 0 transaction log file(s) added, 0 removed, 2 recycled;
write=298.862 s, sync=4.072 s, total=303.115 s; sync files=155,
longest=0.234 s, average=0.026 s
Although these tables (ProductSupplier, Product, ProductCategory) are
large (millions of rows), all these queries are done via indexes, for
example:
=# explain (analyze, buffers) select "id" from "ProductSupplier" where
"product"='25553848082928';
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
Index Scan using "i433275-productIndex" on "ProductSupplier"
(cost=0.57..15.81 rows=3 width=8) (actual time=0.069..0.105 rows=6 loops=1)
Index Cond: (product = 25553848082928::bigint)
Buffers: shared hit=10
Total runtime: 0.138 ms
(4 rows)
So, I would expect it to be really quick, and > 1 second seems really slow.
Overall the load on the server seems quite low, for example, typical
vmstat -1 is:
procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------
r b swpd free buff cache si so bi bo in cs us sy
id wa st
0 1 304 77740 11960 17709156 0 0 99 82 2 2 2
1 89 8 0
1 0 304 75228 11960 17711164 0 0 1256 635 1418 6498 0
0 94 6 0
0 1 304 73440 11968 17712036 0 0 1232 149 1253 6232 1
0 94 6 0
0 2 304 78472 11968 17706016 0 0 1760 89 1325 6361 1
0 94 5 0
0 1 304 75616 11968 17708480 0 0 2164 72 1371 6855 1
0 94 5 0
0 1 304 73292 11968 17710320 0 0 1760 112 1335 6673 1
0 94 5 0
0 2 304 77956 11964 17703528 0 0 1204 5614 1867 6712 0
0 94 6 0
And iostat also seems okay:
sda sdb sdc sdd
md0 md1 cpu
kps tps svc_t kps tps svc_t kps tps svc_t kps tps svc_t kps tps
svc_t kps tps svc_t us sy wt id
619 64 5.4 1478 96 8.9 1494 98 8.7 542 60 5.5 1998
139 0.0 804 96 0.0 2 1 8 89
1147 151 3.7 5328 88 8.0 5388 90 8.3 1147 145 3.0 5638
171 0.0 2245 284 0.0 0 0 4 95
865 110 4.6 214 24 12.6 214 24 13.1 885 113 4.5 252
28 0.0 1749 222 0.0 4 0 1 95
937 107 5.0 40 5 10.0 40 5 13.0 821 93 6.4 80
10 0.0 1596 193 0.0 9 0 1 90
1206 154 3.2 0 0 0.0 0 0 0.0 1195 153 3.2 0 0
0.0 2401 307 0.0 6 0 0 94
1111 139 3.8 24 3 10.0 16 2 12.0 1115 144 3.8 40
5 0.0 2141 274 0.0 10 0 0 89
1222 156 3.6 101 12 4.8 101 12 4.2 1171 150 4.2 93
10 0.0 1986 252 0.0 10 0 0 90
739 98 5.5 0 0 0.0 0 0 0.0 687 93 5.2 0 0
0.0 1425 191 0.0 7 0 0 93
775 102 5.2 8 1 13.0 8 1 21.0 755 99 5.1 16
2 0.0 1529 201 0.0 10 0 0 89
780 105 5.3 16 2 13.0 16 2 11.0 784 103 5.4 32
4 0.0 1555 205 0.0 6 0 1 92
573 75 6.8 110 32 1.3 110 31 1.1 561 73 7.6 102
30 0.0 1109 143 0.0 10 1 0 89
639 84 7.3 2833 349 2.1 3085 367 2.0 683 90 6.0 4854
592 0.0 1026 135 0.0 2 0 4 93
510 70 7.8 2020 240 4.2 1808 227 4.2 586 81 7.2 40
5 0.0 1077 146 0.0 0 0 7 93
538 75 7.8 24 3 290.0 20 3 239.7 582 81 7.5 40
5 0.0 1066 147 0.0 0 0 6 94
504 69 9.3 132 17 25.8 128 16 14.4 600 81 8.2 256
32 0.0 1083 144 0.0 1 0 6 94
I've tried to optimise postgresql.conf for performance:
max_connections = 1000 # (change requires restart)
shared_buffers = 2GB # min 128kB or max_connections*16kB
work_mem = 100MB # min 64kB
maintenance_work_mem = 100MB # min 1MB
synchronous_commit = off # immediate fsync at commit
wal_buffers = 16MB # min 32kB
checkpoint_segments = 64 # in logfile segments, min 1,
16MB each
checkpoint_timeout = 10min # range 30s-1h
effective_cache_size = 16GB
logging_collector = on # Enable capturing of stderr and
csvlog
log_directory = 'pg_log' # directory where log files are
written,
log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # log file name pattern,
log_rotation_age = 1d # Automatic rotation of logfiles
will
log_min_duration_statement = 1000 # -1 is disabled, 0 logs all
statements
log_checkpoints = on
log_line_prefix = '%m %p: ' # special values:
autovacuum = on # Enable autovacuum subprocess?
'on'
autovacuum_vacuum_threshold = 10000 # min number of row updates before
autovacuum_analyze_threshold = 1000 # min number of row updates before
autovacuum_vacuum_scale_factor = 0.1 # fraction of table size before
vacuum
autovacuum_analyze_scale_factor = 0.05 # fraction of table size before
analyze
autovacuum_vacuum_cost_delay = 5 # default vacuum cost delay for
datestyle = 'iso, dmy'
default_text_search_config = 'pg_catalog.english'
backslash_quote = on # on, off, or safe_encoding
standard_conforming_strings = off
If anyone can see anything amiss in the above info, I'd be grateful for
any suggestions...
Thanks,
Michael.
--
Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
