Vous n'êtes pas identifié(e).
Pages : 1
Bonjour,
Nous faisons des tests de charge sur un moteur 9.2.4 sous Cent-OS 5.9.
La machine dispose de 12Go de RAM.
Les paramètres sont :
max_connections = 100
shared_buffers = 3072MB
work_mem = 10MB
maintenance_work_mem = 1536MB
checkpoint_segments = 32
checkpoint_completion_target = 0.9
random_page_cost = 2.0
effective_cache_size = 8192MB
La base de données fait 11Go.
Nous avons développé une application Java qui doit faire 4000 inserts/seconde dans une table.
Nous constatons à certains moments des chutes d'insertion, voir des timeout, voir le blocage de certains SELECT fait en parallèle.
Nous soupçonnons les écritures disque.
Dans les logs, nous avons les checkpoints de ce style :
2-17.log:2013-09-17 17:54:03 CEST [23900]: [56-1] user=,db= LOG: checkpoint complete: wrote 50354 buffers (12.8%); 0 transaction log file(s) added, 0 removed, 13 recycled; write=90.259 s, sync=0.246 s, total=90.539 s; sync files=26, longest=0.050 s, average=0.009 s
2-17.log:2013-09-17 17:55:43 CEST [23900]: [58-1] user=,db= LOG: checkpoint complete: wrote 45218 buffers (11.5%); 0 transaction log file(s) added, 0 removed, 32 recycled; write=88.169 s, sync=0.027 s, total=88.221 s; sync files=25, longest=0.012 s, average=0.001 s
2-17.log:2013-09-17 17:57:32 CEST [23900]: [60-1] user=,db= LOG: checkpoint complete: wrote 46817 buffers (11.9%); 0 transaction log file(s) added, 0 removed, 32 recycled; write=97.904 s, sync=0.019 s, total=98.523 s; sync files=25, longest=0.007 s, average=0.000 s
2-17.log:2013-09-17 17:59:12 CEST [23900]: [62-1] user=,db= LOG: checkpoint complete: wrote 43594 buffers (11.1%); 0 transaction log file(s) added, 0 removed, 32 recycled; write=88.331 s, sync=0.530 s, total=89.196 s; sync files=25, longest=0.327 s, average=0.021 s
2-18.log:2013-09-17 18:01:04 CEST [23900]: [64-1] user=,db= LOG: checkpoint complete: wrote 47125 buffers (12.0%); 0 transaction log file(s) added, 0 removed, 32 recycled; write=101.708 s, sync=0.126 s, total=101.916 s; sync files=24, longest=0.105 s, average=0.005 s
2-18.log:2013-09-17 18:03:09 CEST [23900]: [66-1] user=,db= LOG: checkpoint complete: wrote 47780 buffers (12.2%); 0 transaction log file(s) added, 0 removed, 32 recycled; write=111.658 s, sync=0.159 s, total=112.161 s; sync files=25, longest=0.128 s, average=0.006 s
2-18.log:2013-09-17 18:05:35 CEST [23900]: [68-1] user=,db= LOG: checkpoint complete: wrote 44482 buffers (11.3%); 0 transaction log file(s) added, 0 removed, 32 recycled; write=131.572 s, sync=0.270 s, total=131.915 s; sync files=26, longest=0.103 s, average=0.010 s
Comment interprêter ces informations ?
Comment régler les paramètres : checkpoint_segments, checkpoint_completion_target, peut être checkpoint_timeout.
Quels outils, côtè système, pouvons-nous mettre en place pour mesurer les I/O pendant nos tests ?
D'avance merci pour votre aide.
Hors ligne
Dommage que vous n'ayez pas indiqué les autres traces de CHECKPOINT (checkpoint start, de mémoire), ça nous aurait donné plus de pistes.
Quelle est la valeur du checkpoint_timeout ?
À priori, à la lecture des traces, vous atteignez très rapidement les 32 journaux (à la louche toutes les deux minutes). Il serait donc bon d'augmenter le checkpoint_segments fortement. Une valeur de 100 semblerait plus raisonnable. Cela revient à tripler la quantité d'informations à écrire par checkpoint, ce qui voudrait dire écrire 3*50000 blocs de 8 Ko, soit en gros 1,1 Go toutes les deux minutes. Cela donne du 9 Mo / seconde. Je ne suis certainement pas le plus expérimenté sur la rapidité des disques mais il me semble que c'est déjà un taux d'écriture assez fort s'il est constant. Vous avez donc intérêt à avoir un bon système disque.
Il serait bon aussi de superviser le contenu de la table statistiques pg_stat_bgwriter. Ce que vous pouvez faire par exemple est de récupérer le contenu de cette table une fois toutes lees cinq minutes pendant une heure où l'activité est habituelle. Et postez ici cette information pour qu'on aille plus en avant dans la réponse.
Guillaume.
Hors ligne
Bonjour Guillaume,
Que voulez-vous dire par "de mémoire" dans la première phrase ?
La valeur de checkpoint_timeout est à 5min, valeur par défaut.
Notre système de disques : 2 X 146Go, 15000 tours, en mirroir. Système de fichiers EXT3. Data et log sur le même disque.
Ci-dessous, les infos de pg_stat_bg_writer :
heure;checkpoints_timed;checkpoints_req;checkpoint_write_time;checkpoint_sync_time;buffers_checkpoint;buffers_clean;maxwritten_clean;buffers_backend;buffers_backend_fsync;buffers_alloc
10:16:01;12059;204;112089788;150359;13502185;441021;1794;7301346;0;18822180
10:21:01;12060;205;112302880;150664;13541836;441021;1794;7301346;0;18853178
10:26:01;12061;205;112572854;150711;13580054;441021;1794;7301346;0;18874515
10:31:01;12061;206;112801087;150790;13618469;441021;1794;7301348;0;18905104
10:36:01;12062;207;113208877;150984;13669970;441021;1794;7301348;0;18940260
10:41:01;12062;208;113435843;151067;13695950;441021;1794;7301348;0;18960017
10:46:01;12062;209;113695787;151154;13740952;441021;1794;7301348;0;18990678
10:51:01;12062;210;113922471;151259;13779518;441021;1794;7301348;0;19016722
10:56:01;12063;210;114192057;151285;13821844;441021;1794;7301382;0;19043989
11:01:01;12063;211;114436233;151330;13907447;441021;1794;7314779;0;19077678
11:06:01;12064;211;114702661;151653;13946186;441021;1794;7325706;0;19101146
Merci pour votre aide.
Dernière modification par mortimer.pw (18/09/2013 11:14:27)
Hors ligne
> Que voulez-vous dire par "de mémoire" dans la première phrase ?
de mémoire == de ce que je me rappelle
> La valeur de checkpoint_timeout est à 5min, valeur par défaut.
Si vous augmentez fortement checkpoint_segments comme je vous le conseille, vous devrez aussi augmenter checkpoint_timeout.
> Infos bgwriter
Les infos de pg_stat_bgwriter montre que les CHECKPOINT supportent toutes les écritures dans les fichiers de données. C'est très bien ainsi. Ça pourrait changer en augmentant checkpoint_timeout. Si c'est le cas, il faudra procéder à quelques ajustements au niveau de la configuration de PostgreSQL, et notamment au niveau de la taille du cache disque (shared_buffers)... ce qui sous-entend une augmentation de la quantité de mémoire.
Guillaume.
Hors ligne
Ah, désolé, j'étais parti sur mémoire RAM.
Pourriez-vous m'expliquer un peu les chiffres de pg_stat_bgwriter car j'ai un peu de mal avec les seules infos de la doc (http://docs.postgresql.fr/9.1/monitoring-stats.html) ?
Nous allons refaire des tests en augmentant le nombre de fichiers journaux. Comment doit évoluer la valeur de checkpoint_timeout en fonction du checkpoint_segments ?
Merci encore.
Hors ligne
J'ai regardé principalement les colonnes buffers_checkpoint (nombre de pages disques écrites par le processus checkpointer), buffers_clean (nombre de pages disques écrites par le processus writer) et buffers_backend (nombre de pages disques écrites par les processus postgres, ceux chargés de l'exécution des requêtes des clients). Évidemment, il faut que les pages ne soient pas écrites par ce dernier, sinon cela ralentit considérablement l'exécution des requêtes dont ils ont la charge.
Dans votre cas, buffers_backend augmente un peu (24360 pages de tête), buffers_clean reste tout plat, et buffers_checkpoint augmente fortement (444001 pages). Donc les pages disques sont écrites majoritairement par les CHECKPOINT. Et c'est une excellente chose.
Les seuls moyens d'éviter les lenteurs sont donc de diminuer le nombre d'écriture (ce qui est possible pour les journaux de transactions en distanciant plus fortement les checkpoints, donc en augmentant checkpoint_timeout et checkpoint_segments), d'avoir un cache plus disque PostgreSQL plus gros et d'avoir des disques plus rapides.
Guillaume.
Hors ligne
D'accord, je comprend mieux.
Et pour le paramètre checkpoint_timeout, comment le mettre en adéquation avec chechpoint_segments ?
j'espère ne pas être trop pénible, désolé.
Hors ligne
Personnellement, je le mettrais à 15 minutes. C'est plus une estimation basée sur l'expérience et sur vos dires que le résultat d'un long calcul 
Guillaume.
Hors ligne
Ok, nous allons faire de nouveaux tests et je posterai les nouveaux résultats.
Merci bien pour toutes vos précisions Guillaume.
Hors ligne
Bonjour Guillaume,
Ci_dessous , de nouveaux snapshots de pg_stat_bgwriter, avec les paramètres checkpoint_segments=96 et checkpoint_timeout=15min.
heure;checkpoints_timed;checkpoints_req;checkpoint_write_time;checkpoint_sync_time;buffers_checkpoint;buffers_clean;maxwritten_clean;buffers_backend;buffers_backend_fsync;buffers_alloc
10:51:01;316;28;19337293;25282;3521091;459471;1030;1541770;0;2929658
10:56:01;316;28;19337293;25282;3521091;459471;1030;1541770;0;2929675
11:01:02;316;28;19337293;25282;3521091;459471;1030;1541770;0;2978513
11:06:01;316;29;19337293;25282;3529302;459471;1030;1628640;0;3034187
11:11:01;316;29;19337293;25282;3600768;459471;1030;1684346;0;3091079
11:16:01;316;30;19752191;25837;3664021;459471;1030;1740367;0;3148297
11:21:01;316;31;20148730;26307;3725269;459471;1030;1796230;0;3204318
11:26:01;316;31;20148730;26307;3791590;459471;1030;1850437;0;3258570
11:31:02;316;32;20673627;26743;3826632;459471;1030;1889652;0;3292731
11:36:01;316;32;20673627;26743;3899837;468494;1106;1944418;0;3349061
11:41:01;316;33;21076172;27247;3947253;501546;1432;1997440;0;3403601
11:46:01;316;34;21406996;27821;3980948;501546;1432;2051070;0;3457259
11:51:01;316;34;21406996;27821;4047716;501546;1432;2105696;0;3511891
11:56:01;316;35;21819855;28326;4107106;501546;1432;2159904;0;3566082
Il y a apparemment beaucoup plus d'écriture pour buffer_backend.
Cela veut-il dire qu'il faudrait davantage de RAM ?
Hors ligne
En effet, les CHECKPOINT font pratiquement autant de travail que les processus postgres. J'aurais tendance à dire que le cache n'est pas assez gros. Un moyen de le voir serait de surveiller le ratio de lecture en cache. La requête suivante peut nous donner cette information :
SELECT sum(blks_read), sum(blks_hit) FROM pg_stat_database;À exécuter à intervalle régulier, comme pour pg_stat_bgwriter.
Guillaume.
Hors ligne
Bonjour Guillaume,
Ci-dessous les résultats sur PG_STAT_DATABASE :
heure;READ;HIT
09:35:01;29223623;2544099460
09:40:01;29257522;2562154346
09:45:01;29284915;2576842450
09:50:01;29341336;2607236054
09:55:01;29398037;2637633471
10:00:01;29453790;2667425846
10:05:01;29510769;2697697800
10:10:01;29566685;2727351685
10:15:01;29623731;2757451193
10:20:01;29681053;2787702569
10:25:01;29737825;2817813247
10:30:01;29795877;2847435737
10:35:01;29853321;2876407729
Ci-dessous les résultats sur PG_STAT_BGWRITER correspondant :
heure;checkpoints_timed;checkpoints_req;checkpoint_write_time;checkpoint_sync_time;buffers_checkpoint;buffers_clean;maxwritten_clean;buffers_backend;buffers_backend_fsync;buffers_alloc
09:35:01;35557;100;150716125;136778;16563831;471371;970;12589379;0;23067894
09:40:01;35558;100;150716125;136778;16563876;471371;970;12602578;0;23101797
09:45:01;35558;100;150716125;136778;16577535;471371;970;12613156;0;23129260
09:50:01;35558;101;151270124;136870;16601616;471371;970;12635026;0;23185648
09:55:01;35558;101;151270124;136870;16669066;471371;970;12656920;0;23242370
10:00:01;35558;102;151666701;137179;16727738;471465;970;12678354;0;23298134
10:05:01;35558;103;152064749;137241;16787130;471467;970;12700180;0;23355087
10:10:01;35558;103;152064749;137241;16855578;471467;970;12721497;0;23410958
10:15:01;35558;104;152464721;137332;16919730;471504;970;12743234;0;23468059
10:20:01;35558;105;152860202;137403;16984027;471504;970;12765032;0;23525363
10:25:01;35558;105;152860202;137403;17054927;471504;970;12786737;0;23582154
10:30:01;35558;106;153260144;137614;17122641;471504;970;12808080;0;23638204
10:35:01;35558;107;153663921;137807;17189013;471504;970;12829017;0;23693408
Est-ce que cela confirme un cache trop petit ? et pourquoi ?
Merci encore pour votre support.
Hors ligne
Donc en moyenne, toutes les cinq minutes, vous lisez 52474 blocs en dehors du cache de PostgreSQL (soit 410 Mo), et 27 millions dans le cache (soit 216 Go). C'est à la fois excellent et effrayant. Excellent parce que votre taux de lecture en cache est très haut (99,81%). Effrayant parce que vous touchez 216 Go toutes les cinq minutes.. carrément impressionnant. Pour résumer, au niveau des lectures, votre cache est suffisant.
Pour les écritures, on voit que les CHECKPOINT écrivent en moyenne 55000 blocs (429 Mo) toutes les cinq minutes, que le bgwriter n'en est qu'à 12 blocs (ce qui n'est pas étonnant vu que tout le boulot est fait par les CHECKPOINT), et les processus postgres à 20000 blocs (156 Mo). Là par contre, les processus postgres n'ont pas assez de place en mémoire pour stocker les blocs nécessaires à l'exécution des requêtes, ce qui oblige les processus postgres à écrire sur disque.
Du coup, mon avis est qu'il faudrait augmenter la taille du cache (ie, shared_buffers).
Guillaume.
Hors ligne
Bonjour Guillaume,
Dans le cadre de l'amélioration des performances suite aux premiers tests de charge, nous allons :
- passer la RAM à 32Go.
- réinstaller le serveur en CentOS 6 pour avoir un système de fichiers EXT4 sur le disque pour les data et le disque pour les xlog, ainsi qu'un système de fichiers en RAM pour les stats.
- Installer la version 9.3.
Nous ferons ensuite de nouveaux tests de charge.
Merci encore pour les infos et toute l'aide que vous nous apportez.
Hors ligne
Bonjour "mortimer",
Je veux bien participer à ce sujet malheureusement pas pour apporter une solution mais pour demander qq chose (car moi aussi je galère derrière les perfs). Je voudrai savoir comment faire pour les FS en ram car ce sujet m’intéresse.
Bien à vous
Hors ligne
Pages : 1