Vous n'êtes pas identifié(e).
Bonjour à tous,
suite à une modification de la conf :
avant :
work_mem = '8MB'
maintenance_work_mem = '64MB'
min_wal_size = '80GB'
max_wal_size = '1GB'
checkpoint_timeout = '5min'
checkpoint_completion_target = '0.5'
effective_io_concurrency = '0'
wal_buffers = '16MB'
default_statistics_target = '100'
random_page_cost='1'
après :
work_mem = '16MB'
maintenance_work_mem = '128MB'
min_wal_size = '1GB'
max_wal_size = '2GB'
checkpoint_timeout = '10min'
checkpoint_completion_target = '0.9'
effective_io_concurrency = '20'
wal_buffers = '32MB'
default_statistics_target = '100'
random_page_cost='1'
puis un arrêt relance de l'instance, il est à noter une baisse générale des performances...
contexte :
centOS7
PgSQL 10.9
ram 32go
ssd
les requêtes en générale sont plus longues (environ 20%)
à noter : l'extension pg_stat_statements a été ajoutée et donc après le redémarrage prise en compte
cette extension a été installée sur toutes les BDD du cluster (environ une dizaine).
elle vient d'être retirée et laissée que sur la base postgres.
quelques exemples :
une requête exécutée environ 100 fois avant et après changement (average selon pgbadger) :
avant : 16s
après : 21s
J'ai pensé au cache, mais cela fait un moment que les modifs ont eu lieu
les paramètres positionnés ne me paraissaient pas incohérent et pouvant jouer sur les perfs de manière négative...
devant de nombreux message de type "checkpoint occurs too frequently", les paramètres suivant ont été modifié et depuis beaucoup moins de ces messages remontent.
Cependant en comparant les stats de checkpoint AVANT/APRES on remarque une grande différence
je mets ci dessous ces éléments.
je me demandais si la cause pouvais provenir de là ?
sinon y aurait-il d'autres pistes ?
Merci
Hors ligne
AVANT
checkpoint Buffers (Avant)
Hour Writtenbuff Write time Sync time total time
00 76,944 1,798.573s 0.324s 1,799.007s
01 39,530 1,798.737s 0.293s 1,799.135s
02 718,466 1,871.054s 3.284s 1,876.312s
03 18,302 1,699.691s 0.226s 1,700.043s
04 19,647 1,789.159s 0.282s 1,789.548s
05 33,108 1,798.794s 0.272s 1,799.198s
06 50,323 1,049.209s 0.259s 1,049.563s
07 354,060 1,592.803s 1.499s 1,595.214s
08 147,032 1,798.437s 0.544s 1,799.16s
09 367,928 1,799.438s 1.82s 1,802.035s
10 136,695 1,648.45s 0.661s 1,649.252s
11 396,898 1,779.29s 2.407s 1,782.55s
12 145,238 1,648.39s 0.511s 1,649.049s
13 402,781 1,589.767s 4.784s 1,597.161s
14 149,037 1,537.378s 0.488s 1,538.025s
15 377,475 1,702.605s 1.752s 1,705.394s
16 136,494 1,648.52s 0.446s 1,649.112s
17 386,866 1,727.155s 1.92s 1,730.011s
18 148,072 1,798.109s 0.584s 1,798.885s
19 410,002 1,791.737s 1.654s 1,794.337s
20 136,358 1,648.363s 0.458s 1,648.982s
21 364,881 1,689.253s 1.587s 1,691.557s
22 130,534 1,648.495s 0.462s 1,649.086s
23 323,463 1,661.115s 1.456s 1,663.406s
checkpoint Files (Avant)
Hour Added Removed Recycled Synced files Longest sync Average sync
00 0 2 1 3,694 0.002s 0s
01 0 2 0 3,494 0.005s 0s
02 0 27 329 5,255 0.345s 0.011s
03 0 1 0 3,244 0.001s 0s
04 0 2 0 3,291 0.011s 0s
05 0 2 0 3,467 0.002s 0s
06 0 2 0 2,124 0.012s 0s
07 0 24 112 6,029 0.307s 0.002s
08 0 13 3 4,185 0.013s 0s
09 0 18 123 5,489 0.340s 0.002s
10 0 11 3 3,907 0.142s 0s
11 0 28 121 5,321 0.303s 0.005s
12 0 11 2 3,897 0.007s 0s
13 0 57 284 5,835 0.338s 0.023s
14 0 11 3 4,162 0.005s 0s
15 1 18 131 5,289 0.339s 0.002s
16 0 12 3 3,865 0.004s 0s
17 1 18 136 5,329 0.364s 0.003s
18 0 14 4 4,228 0.005s 0s
19 0 18 135 5,285 0.351s 0.001s
20 0 12 3 3,812 0.020s 0s
21 0 16 129 4,857 0.338s 0.003s
22 0 11 3 3,757 0.005s 0s
23 0 20 123 4,673 0.343s 0.003s
Checkpoint distance (Avant)
Hour Mean distance Mean estimate
00 4,033.42 kB 108,453.75 kB
01 3,061.17kB 32,970.17kB
02 242,456.58kB 336,763.71kB
03 2,398.25kB 98,734.67kB
04 2,088.92kB 29,334.50kB
05 2,658.42kB 10,019.00kB
06 4,753.43kB 5,205.29kB
07 148,187.27kB 274,071.27kB
08 20,668.58kB 118,129.83kB
09 144,975.44kB 275,189.75kB
10 20,425.36kB 110,141.64kB
11 152,172.00kB 283,053.12kB
12 19,264.09kB 112,095.00kB
13 254,369.09kB 350,192.45kB
14 18,184.83kB 85,746.92kB
15 152,992.31kB 273,168.19kB
16 21,704.18kB 112,962.55kB
17 157,885.50kB 283,809.44kB
18 23,407.75kB 119,352.75kB
19 157,613.25kB 284,452.19kB
20 21,806.00kB 115,358.09kB
21 148,911.75kB 281,283.19kB
22 19,415.36kB 109,655.55kB
23 147,320.44kB 279,706.44kB
Hors ligne
APRES
checkpoint Buffers (Après)
Hour Writtenbuff Write time Sync time total time
00 26,090 2,629.624s 0.074s 2,629.776s
01 10,112 1,015.087s 0.054s 1,015.194s
02 509,723 1,707.737s 3.514s 1,713.973s
03 8,176 820.223s 0.063s 820.348s
04 9,590 962.338s 0.059s 962.467s
05 12,205 1,237.05s 0.056s 1,237.174s
06 18,731 1,870.826s 0.083s 1,870.978s
07 193,220 3,192.259s 0.739s 3,193.688s
08 65,681 3,239.389s 1.42s 3,240.953s
09 209,692 3,295.966s 0.416s 3,296.78s
10 48,928 3,239.478s 0.176s 3,239.766s
11 198,633 3,205.858s 0.302s 3,206.714s
12 49,349 2,699.409s 0.208s 2,699.714s
13 191,865 3,343.705s 0.377s 3,344.59s
14 53,720 3,239.282s 0.178s 3,239.582s
15 354,375 2,764.578s 21.612s 2,789.415s
16 43,360 3,239.447s 0.136s 3,239.699s
17 197,167 3,206.193s 0.45s 3,207.402s
18 53,132 3,239.213s 0.164s 3,239.522s
19 208,049 3,331.313s 0.779s 3,332.996s
20 56,148 3,239.465s 0.129s 3,239.696s
21 208,698 3,280.648s 0.375s 3,281.531s
22 54,738 3,239.615s 0.128s 3,239.837s
23 192,719 3,202.159s 0.218s 3,203.031s
checkpoint Files (Après)
Hour Added Removed Recycled Synced files Longest sync Average sync
00 0 0 9 725 0.004s 0s
01 0 0 4 478 0.002s 0s
02 0 45 312 1,332 0.617s 0.031s
03 0 0 3 573 0.003s 0s
04 0 0 3 583 0.001s 0s
05 0 0 4 521 0.002s 0s
06 0 0 8 451 0.010s 0s
07 0 27 117 1,044 0.459s 0.002s
08 0 1 59 1,127 1.179s 0.003s
09 0 1 156 1,262 0.114s 0s
10 0 0 35 911 0.004s 0s
11 0 27 119 1,088 0.030s 0s
12 0 0 25 798 0.004s 0s
13 0 22 124 1,068 0.101s 0s
14 0 0 33 951 0.004s 0s
15 0 80 1,079 3,293 0.923s 0.215s
16 0 0 39 625 0.005s 0s
17 0 28 129 767 0.212s 0.002s
18 0 0 43 545 0.005s 0s
19 0 34 119 689 0.223s 0.005s
20 0 0 33 581 0.004s 0s
21 0 24 120 614 0.226s 0.002s
22 0 0 26 576 0.004s 0s
23 0 23 107 594 0.096s 0.001s
Checkpoint distance (Après)
Hour Mean distance Mean estimate
00 23,871.86kB 392,501.00kB
01 12,313.80kB 213,910.80kB
02 450,065.77kB 613,053.46kB
03 8,064.33kB 380,585.17kB
04 8,092.00kB 196,842.00kB
05 11,238.80kB 108,033.20kB
06 28,279.75kB 67,693.75kB
07 327,846.14kB 499,900.71kB
08 110,796.33kB 446,377.33kB
09 413,389.57kB 617,772.43kB
10 95,371.67kB 448,853.17kB
11 343,002.71kB 578,550.57kB
12 83,067.60kB 431,125.00kB
13 338,891.29kB 567,086.57kB
14 91,190.83kB 441,394.83kB
15 655,227.24kB 701,119.41kB
16 101,639.67kB 450,092.50kB
17 367,085.43kB 580,830.43kB
18 118,485.00kB 457,990.00kB
19 360,727.57kB 602,285.43kB
20 90,360.33kB 465,769.50kB
21 340,111.29kB 578,125.43kB
22 71,693.33kB 434,594.00kB
23 308,283.86kB 568,864.57kb
Hors ligne
Ce que je remarque ce sont des :
checkpoint Buffers:
Write time ==> beaucoup plus élevés APRES (x2)
Total time ==> beaucoup plus élevé APRES (x2)
checkpoint Files
Synced files ==> beaucoup MOINS nombreux APRES
Checkpoint distance
Mean distance ==> Des valeurs beaucoup PLUS élevés APRES (idem pour le mean estimate).
Je comprends que le temps d'écriture des buffers par heure est beaucoup plus long APRES.
iostat :
avg-cpu: %user %nice %system %iowait %steal %idle
3,99 0,00 2,70 2,15 0,01 91,15
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
sdb 0,00 0,00 0,01 4,17 0,37 1774,12 850,12 0,30 66,76 0,89 66,87 3,95 1,65
sda 0,00 0,02 0,52 0,32 16,75 5,01 51,94 0,28 1,52 0,54 3,13 327,67 27,46
sdd 0,00 0,29 882,75 50,79 13733,84 2040,19 33,79 0,06 0,07 0,48 2,80 0,32 30,08
sdc 0,00 0,01 0,00 110,49 0,13 1402,73 25,39 0,25 2,11 0,23 2,11 0,77 8,46
Je précises que les graphes APRES (checkpoint distance et checkpoint write buffers par exemple) présentent beaucoup plus de "dentitions" entre les pics qu'auparavant qui était plus lisse entre les pics mais avec des MAX différents (j'essaie de m'exprimer correctement
Que pourrais-je tirer d'autres comme conclusion à partir de ces éléments?
Merci beaucoup.
Hors ligne
Le "write time" représente une valeur un peu naive, car il s'agit du temps écoulé entre le moment ou le checkpoit commence à écrire les buffers sur disque et le moment où il arrête, avant de passer à la partie fsync. Ce temps prend donc en compte le checkpoint_completion_target et le checkpoint_timeout, donc j'aurais tendance à dire que tout est normal de ce point de vue là.
Julien.
https://rjuju.github.io/
Hors ligne
Julien ,
Merci j'imagine que le Checkpoint distance se retrouve par le même calcul augmenté (espacement des checkpoints) donc ce qui est normal...
Hors ligne
Juste un truc que je vois en lisant votre message:
à noter : l'extension pg_stat_statements a été ajoutée et donc après le redémarrage prise en compte
cette extension a été installée sur toutes les BDD du cluster (environ une dizaine).
elle vient d'être retirée et laissée que sur la base postgres.
En fait, tant que pg_stat_statements est en shared_preload_library, il fonctionne, que l'extension (qui permet d'interroger ce que pg_stat_statements collecte) soit installée ou non dans une base. C'est global à l'instance.
Par contre, je doute que ça soit lui, 20% d'impact serait énorme, par rapport à ce qu'on voit d'habitude (plutôt de l'ordre du pourcent). Malgré tout, si vous voulez en avoir le cœur net, redémarrez avec la librairie déchargée...
Dernière modification par Marc Cousin (19/07/2019 19:13:38)
Marc.
Hors ligne