Réplication et Log binaires
Qui n’a jamais utilisé MySQL sans la réplication? La réplication permet à votre application de supporter un nombre de lecture beaucoup plus important. Les updates se font sur une base de donnée “maître” (master) et sont ensuite répliquées sur plusieurs “esclaves” (slaves). Le maître n’a pas à supporter les requêtes venant de clients qui sont gérées par les esclaves. Un autre jour je rentrerai plus en détails la dessus mais en résumé, le maître écrit dans des fichiers toutes les requêtes qui ont modifié ses informations (insert, update et delete). Les slaves viennent à leur tour récupérer ces fichiers (binary logs) et les “copie” localement (relay logs) avant de les rejouer.
Il est conseillé en général de dédier un disque pour ces fichiers car beaucoup d’écriture entraîne une baisse de vos performances. Dans le cas qui nous intéresse, l’activité du CPU m’a très étonné. En effet jusqu’à 60% du temps CPU étaient utilisé par ‘USER’ juste en activant la réplication.
Suite à cela j’ai décidé avec mon ami Laurent de faire un peu de profiling… sommes nous un peu DBCSI? (comprenez database crime scene investigators ;)) Pour cela un outil intéressant est oprofile.
Pour tester ça, nous avons un DELL 2850 sous RHEL4 1 disque (hélas) et 2Go de RAM. Le programme de test à été exécuté pendant 30 minutes, et voila les résultats surprenant.
- Avec binlog
- Sans binlog
Profiling through timer interrupt
samples % image name symbol name
1680924 47.9708 /lib64/tls/libc-2.3.4.so __ctype_toupper_loc
1651101 47.1197 /usr/libexec/mysqld dict_create_foreign_constraints_low
54986 1.5692 /usr/libexec/mysqld yylex(void*, void*)
9083 0.2592 /usr/libexec/mysqld __do_global_ctors_aux
8541 0.2437 /usr/libexec/mysqld buf_pool_init
8284 0.2364 /lib64/tls/libc-2.3.4.so memcpy
5918 0.1689 /usr/libexec/mysqld my_snprintf_ucs2
4934 0.1408 /usr/libexec/mysqld log_buffer_flush_to_disk
4640 0.1324 /usr/libexec/mysqld my_strntod_ucs2
4268 0.1218 /usr/libexec/mysqld MD5Transform
3650 0.1042 /usr/libexec/mysqld my_parse_charset_xml
Profiling through timer interrupt
samples % image name symbol name
34847 9.7094 /usr/libexec/mysqld __do_global_ctors_aux
30416 8.4748 /lib64/tls/libc-2.3.4.so memcpy
30041 8.3703 /usr/libexec/mysqld buf_pool_init
20615 5.7439 /usr/libexec/mysqld my_snprintf_ucs2
17065 4.7548 /usr/libexec/mysqld my_strntod_ucs2
16656 4.6408 /usr/libexec/mysqld log_buffer_flush_to_disk
14908 4.1538 /usr/libexec/mysqld dict_create_foreign_constraints_low
9154 2.5506 /lib64/tls/libpthread-2.3.4.so pthread_mutex_trylock
8354 2.3277 /lib64/tls/libc-2.3.4.so __ctype_toupper_loc
8216 2.2892 /lib64/tls/libpthread-2.3.4.so pthread_mutex_unlock
5347 1.4898 /usr/lib/debug/lib/modules/2.6.9-22.ELsmp/vmlinux copy_user_generic
3380 0.9418 /usr/libexec/mysqld buf_flush_try_page
On remarque que lorsque les logs binaires sont activés, beaucoup de temps CPU est utilisé par cette fonction “dict_create_foreign_constraints_low”. Ce qui très étrange, car elle est supposé être utilisé lorsque d’une modification de DDL (création de tables,…) pour effectuer des vérifications sur les clés étrangères. Et sur cette application, même si nous sommes en InnoDB, il n’y en a aucune.
Des que nous aurons un peu de temps devant nous, nous referons le test sous MySQL 5.0.