Hello,
I use two dedicated bare metal servers (Online and Kimsufi). The first one takes much longer to execute a procedure that recreates a database by truncating its tables, then copying the data from a set of text files; it is however much faster for more typical SELECT and INSERT queries done by users.
Here is the timing for the procedure :
#Kimsufi server
time psql -f myfile.sql mydb
real 0m12.585s
user 0m0.200s
sys 0m0.076s
#Online server
time psql -f myfile.sql mydb
real 1m15.410s
user 0m0.144s
sys 0m0.028s
As you can see, the Kimsufi server takes 12 seconds to complete the procedure, while the Online one needs 75 seconds.
For more usual queries however, the ratio is reversed, as shown by explain analyze for a typical query:
#Kimsufi server
marica=> explain (analyze, buffers) SELECT t1.id_contentieux, t1.ref_dossier, t1.ref_assureur, noms_des_tiers(t1.id_contentieux) as id_tiers, t1.libelle, t1.affaire, 1 as authorized
FROM tblcontentieux t1 WHERE id_contentieux IN (SELECT id_contentieux FROM tblcontentieux_log WHERE plainto_tsquery('vol') @@ tsv_libelle) AND id_client = 13 ORDER BY 2
;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=543.29..543.56 rows=106 width=116) (actual time=19.870..19.885 rows=75 loops=1)
Sort Key: t1.ref_dossier
Sort Method: quicksort Memory: 35kB
Buffers: shared hit=689
-> Nested Loop (cost=430.59..539.73 rows=106 width=116) (actual time=4.103..19.143 rows=75 loops=1)
Buffers: shared hit=689
-> HashAggregate (cost=430.31..430.49 rows=18 width=4) (actual time=2.077..2.266 rows=124 loops=1)
Group Key: tblcontentieux_log.id_contentieux
Buffers: shared hit=112
-> Bitmap Heap Scan on tblcontentieux_log (cost=29.11..429.95 rows=142 width=4) (actual time=0.712..1.550 rows=147 loops=1)
Recheck Cond: (plainto_tsquery('vol'::text) @@ tsv_libelle)
Heap Blocks: exact=105
Buffers: shared hit=112
-> Bitmap Index Scan on tblcontentieux_log_tvs_libelle_idx (cost=0.00..29.07 rows=142 width=0) (actual time=0.632..0.632 rows=147 loops=1)
Index Cond: (plainto_tsquery('vol'::text) @@ tsv_libelle)
Buffers: shared hit=7
-> Index Scan using tblcontentieux_pkey on tblcontentieux t1 (cost=0.28..4.59 rows=1 width=116) (actual time=0.018..0.019 rows=1 loops=124)
Index Cond: (id_contentieux = tblcontentieux_log.id_contentieux)
Filter: (id_client = 13)
Rows Removed by Filter: 0
Buffers: shared hit=372
Planning time: 3.666 ms
Execution time: 20.176 ms
#Online server
marica=> explain (analyze,buffers) SELECT t1.id_contentieux, t1.ref_dossier, t1.ref_assureur, noms_des_tiers(t1.id_contentieux) as id_tiers, t1.libelle, t1.affaire, 1 as authorized
FROM tblcontentieux t1 WHERE id_contentieux IN (SELECT id_contentieux FROM tblcontentieux_log WHERE plainto_tsquery('vol') @@ tsv_libelle) AND id_client = 13 ORDER BY 2;
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=492.01..492.27 rows=104 width=116) (actual time=10.660..10.673 rows=75 loops=1)
Sort Key: t1.ref_dossier
Sort Method: quicksort Memory: 35kB
Buffers: shared hit=686
-> Nested Loop (cost=390.14..488.52 rows=104 width=116) (actual time=1.363..10.066 rows=75 loops=1)
Buffers: shared hit=686
-> HashAggregate (cost=389.85..390.03 rows=18 width=4) (actual time=0.615..0.725 rows=124 loops=1)
Group Key: tblcontentieux_log.id_contentieux
Buffers: shared hit=109
-> Bitmap Heap Scan on tblcontentieux_log (cost=13.08..389.51 rows=139 width=4) (actual time=0.156..0.465 rows=147 loops=1)
Recheck Cond: (plainto_tsquery('vol'::text) @@ tsv_libelle)
Heap Blocks: exact=106
Buffers: shared hit=109
-> Bitmap Index Scan on tblcontentieux_log_tvs_libelle_idx (cost=0.00..13.04 rows=139 width=0) (actual time=0.126..0.126 rows=147 loops=1)
Index Cond: (plainto_tsquery('vol'::text) @@ tsv_libelle)
Buffers: shared hit=3
-> Index Scan using tblcontentieux_pkey on tblcontentieux t1 (cost=0.28..4.02 rows=1 width=116) (actual time=0.010..0.011 rows=1 loops=124)
Index Cond: (id_contentieux = tblcontentieux_log.id_contentieux)
Filter: (id_client = 13)
Rows Removed by Filter: 0
Buffers: shared hit=372
Planning time: 1.311 ms
Execution time: 10.813 ms
Both are bare metal servers, with 4GB of RAM; the dataset is small (compressed dump is 3MB). The main differences that I found are in disk I/O as shown by hdparm, and processor type :
#Kimsufi server
hdparm -tT /dev/sda
Timing cached reads: 1744 MB in 2.00 seconds = 872.16 MB/sec
Timing buffered disk reads: 482 MB in 3.00 seconds = 160.48 MB/sec
Processor Intel(R) Atom(TM) CPU N2800 @ 1.86GHz (4 cores, cache size : 512 KB)
Disk 2TB, 7200rpm, db on 500MB partition
#Online server
hdparm -tT /dev/sda
Timing cached reads: 2854 MB in 2.00 seconds = 1427.05 MB/sec
Timing buffered disk reads: 184 MB in 3.00 seconds = 61.26 MB/sec
Processor Intel(R) Atom(TM) CPU C2350 @ 1.74GHz (2 cores, cache size : 1024 KB)
Disk 1TB, 7200rpm, db on 1TB partition
I've created two pastebins with the output of the following commands for each server:
# hdparm /dev/sda
# hdparm -i /dev/sda
# df
# cat /proc/cpuinfo
# cat /proc/meminfo
#Kimsufi server
https://pastebin.com/3860hS92
#Online server
https://pastebin.com/FT1HFbD7
My questions:
-Does the difference in 'buffered disk reads' explain the 6 fold increase in execution time for truncate/copy on the Online server?
-Why are regular queries much faster on this same server?
--
Bien à vous, Vincent Veyron
https://legalcase.libremen.com/
Legal case management software
--
Sent via pgsql-performance mailing list (pgsql-performance@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
