From: | Konstantin Knizhnik <k(dot)knizhnik(at)postgrespro(dot)ru> |
---|---|
To: | Tomas Vondra <tomas(dot)vondra(at)2ndquadrant(dot)com>, Andres Freund <andres(at)anarazel(dot)de> |
Cc: | Robert Haas <robertmhaas(at)gmail(dot)com>, Thomas Munro <thomas(dot)munro(at)enterprisedb(dot)com>, PostgreSQL Hackers <pgsql-hackers(at)postgresql(dot)org>, Sean Chittenden <seanc(at)joyent(dot)com> |
Subject: | Re: WAL prefetch |
Date: | 2018-06-21 14:01:09 |
Message-ID: | 3389fbf4-d293-92e8-0815-e6d77ea8a1fd@postgrespro.ru |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-hackers |
I continue my experiments with WAL prefetch.
I have embedded prefetch in Postgres: now walprefetcher is started
together with startup process and is able to help it to speedup recovery.
The patch is attached.
Unfortunately result is negative (at least at my desktop: SSD, 16Gb
RAM). Recovery with prefetch is 3 times slower than without it.
What I am doing:
Configuration:
max_wal_size=min_wal_size=10Gb,
shared)buffers = 1Gb
Database:
pgbench -i -s 1000
Test:
pgbench -c 10 -M prepared -N -T 100 -P 1
pkill postgres
echo 3 > /proc/sys/vm/drop_caches
time pg_ctl -t 1000 -D pgsql -l logfile start
Without prefetch it is 19 seconds (recovered about 4Gb of WAL), with
prefetch it is about one minute. About 400k blocks are prefetched.
CPU usage is small (<20%), both processes as in "Ds" state.
vmstat without prefetch shows the following output:
procs -----------memory---------- ---swap-- -----io---- -system--
------cpu-----
r b swpd free buff cache si so bi bo in cs us sy
id wa st
0 2 2667964 11465832 7892 2515588 0 0 344272 2 6129 22290
8 4 84 5 0
3 1 2667960 10013900 9516 3963056 6 0 355606 8772 7412 25228
12 6 74 8 0
1 0 2667960 8526228 11036 5440192 0 0 366910 242 6123 19476
8 5 83 3 0
1 1 2667960 7824816 11060 6141920 0 0 166860 171638 9581
24746 4 4 79 13 0
0 4 2667960 7822824 11072 6143788 0 0 264 376836 19292
49973 1 3 69 27 0
1 0 2667960 7033140 11220 6932400 0 0 188810 168070 14610
41390 5 4 72 19 0
1 1 2667960 5739616 11384 8226148 0 0 254492 57884 6733 19263
8 5 84 4 0
0 3 2667960 5024380 11400 8941532 0 0 8 398198 18164
45782 2 5 70 23 0
0 0 2667960 5020152 11428 8946000 0 0 168 69128 3918 10370
2 1 91 6 0
with prefetch:
procs -----------memory---------- ---swap-- -----io---- -system--
------cpu-----
r b swpd free buff cache si so bi bo in cs us sy
id wa st
0 2 2651816 12340648 11148 1564420 0 0 178980 96 4411 14237
5 2 90 3 0
2 0 2651816 11771612 11712 2132180 0 0 169572 0 6388
18244 5 3 72 20 0
2 0 2651816 11199248 12008 2701960 0 0 168966 162 6677
18816 5 3 72 20 0
1 3 2651816 10660512 12028 3241604 0 0 162666 16 7065
21668 6 5 69 20 0
0 2 2651816 10247180 12052 3653888 0 0 131564 18112 7376
22023 6 3 69 23 0
0 2 2651816 9850424 12096 4064980 0 0 133158 238 6398 17557
4 2 71 22 0
2 0 2651816 9456616 12108 4459456 0 0 134702 44 6219 16665
3 2 73 22 0
0 2 2651816 9161336 12160 4753868 0 0 111168 74408 8038 20440
3 3 69 25 0
3 0 2651816 8810336 12172 5106068 0 0 134694 0 6251 16978
4 2 73 22 0
0 2 2651816 8451924 12192 5463692 0 0 137546 80 6264 16930
3 2 73 22 0
1 1 2651816 8108000 12596 5805856 0 0 135212 10 6218 16827
4 2 72 22 0
1 3 2651816 7793992 12612 6120376 0 0 135072 0 6233 16736
3 2 73 22 0
0 2 2651816 7507644 12632 6406512 0 0 134830 90 6267 16910
3 2 73 22 0
0 2 2651816 7246696 12776 6667804 0 0 122656 51820 7419 19384
3 3 71 23 0
1 2 2651816 6990080 12784 6924352 0 0 121248 55284 7527 19794
3 3 71 23 0
0 3 2651816 6913648 12804 7000376 0 0 36078 295140 14852
37925 2 3 67 29 0
0 2 2651816 6873112 12804 7040852 0 0 19180 291330 16167
41711 1 3 68 28 0
5 1 2651816 6641848 12812 7271736 0 0 107696 68 5760 15301
3 2 73 22 0
3 1 2651816 6426356 12820 7490636 0 0 103412 0 5942 15994
3 2 72 22 0
0 2 2651816 6195288 12824 7720720 0 0 104446 0 5605 14757
3 2 73 22 0
0 2 2651816 5946876 12980 7970912 0 0 113340 74 5980 15678
3 2 71 24 0
1 2 2651816 5655768 12984 8262880 0 0 137290 0 6235 16412
3 2 73 21 0
2 0 2651816 5359548 13120 8557072 0 0 137608 86 6309 16658
3 2 73 21 0
2 0 2651816 5068268 13124 8849136 0 0 137386 0 6225 16589
3 2 73 21 0
2 0 2651816 4816812 13124 9100600 0 0 120116 53284 7273 18776
3 2 72 23 0
0 2 2651816 4563152 13132 9353232 0 0 117972 54352 7423 19375
3 2 73 22 0
1 2 2651816 4367108 13144 9549712 0 0 51994 239498 10846
25987 3 5 73 19 0
0 0 2651816 4366356 13164 9549892 0 0 168 294196 14981
39432 1 3 79 17 0
So as you can see, read speed with prefetch is smaller: < 130Mb/sec,
while without prefetch up to 366Mb/sec.
My hypothesis is that prefetch flushes dirty pages from cache and as a
result, more data has to be written and backends are more frequently
blocked in write.
In any case - very upsetting result.
Any comments are welcome.
--
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company
Attachment | Content-Type | Size |
---|---|---|
walprefetch.patch | text/x-patch | 30.9 KB |
From | Date | Subject | |
---|---|---|---|
Next Message | Tom Lane | 2018-06-21 14:01:46 | Re: partition table and stddev() /variance() behaviour |
Previous Message | Tom Lane | 2018-06-21 13:51:35 | Re: server crashed with TRAP: FailedAssertion("!(!parallel_aware || pathnode->path.parallel_safe)" |