MySQL Cluster : Analyse Incident

Contexte

Les commandes suivantes, loin d’être exhaustive permettent de diagnostiquer un cluster Mysql, ou une instance seule.

Elle peuvent également être utilisées dans le cadre d’un audit.

Je ne traiterais pas de méthodologie ici car c’est dépendant du type de problème rencontré ou de l’expérience de l’auditeur. Je vous recommande https://www.percona.com/downloads/percona-toolkit

Pour le .deb installation

dpkg -i percona-toolkit-x-x-x.deb

Analyse des binlog

Lors de la récupération de l’epoch lors d’un problème de réplication, on récupère également un numéro de binlog et une position dans celui-ci. Pour voir la requête incriminée on peut faire.

mysqlbinlog -u root -p /var/lib/mysql/mysql-bin.00yyyy -j xxxxxxx --base64-output=decode-rows -v

où mysql-bin.00yyyy est le fichier binlog et -j xxxxxxx la position. Ceci est valable pour des binlog en RAW.

Ça renvoi la requête précise.

De manière plus générale, lorsque qu’on ne connait pas le binlog et la position, on requête autour de la date de l’incident. Ici entre le 31/10/2015 à 00h20 et 00h27.

Essayer d’être le plus proche possible de la fenêtre d’incident car le résultat peut être très volumineux.

mysqlbinlog -u root -p /var/lib/mysql/mysql-bin.00**** --base64-output=decode-rows -v  --start-datetime="2015-10-31 00:20:00" --stop-datetime="2015-10-31 00:27:00" >> /root/binlog.txt

Ensuite utiliser le parser suivant pour formater tout ça en un truc lisible.

cat /root/binlog.txt | awk \
'BEGIN {s_type=""; s_count=0;count=0;insert_count=0;update_count=0;delete_count=0;flag=0;} \
{if(match($0, /#15.*Table_map:.*mapped to number/)) {printf "Timestamp : " $1 " " $2 " Table : " $(NF-4); flag=1} \
else if (match($0, /(### INSERT INTO .*..*)/)) {count=count+1;insert_count=insert_count+1;s_type="INSERT"; s_count=s_count+1;}  \
else if (match($0, /(### UPDATE .*..*)/)) {count=count+1;update_count=update_count+1;s_type="UPDATE"; s_count=s_count+1;} \
else if (match($0, /(### DELETE FROM .*..*)/)) {count=count+1;delete_count=delete_count+1;s_type="DELETE"; s_count=s_count+1;}  \
else if (match($0, /^(# at) /) && flag==1 && s_count>0) {print " Query Type : "s_type " " s_count " row(s) affected" ;s_type=""; s_count=0; }  \
else if (match($0, /^(COMMIT)/)) {print "[Transaction total : " count " Insert(s) : " insert_count " Update(s) : " update_count " Delete(s) : " \
delete_count "] \n+----------------------+----------------------+----------------------+----------------------+"; \
count=0;insert_count=0;update_count=0; delete_count=0;s_type=""; s_count=0; flag=0} } '

Ça renvoi un truc du style :

Timestamp : #151031 0:20:11 Table : `base1`.`PRICE`Timestamp : #151031 0:20:11 Table : `base1`.`SYNCINFO`Timestamp : #151031 0:20:11 Table : `base1`.`SERVICESTATS`Timestamp : #151031 0:20:11 Table : `mysql`.`ndb_apply_status` Query Type : UPDATE 1651 row(s) affected
[Transaction total : 1651 Insert(s) : 2 Update(s) : 1649 Delete(s) : 0]

 Timestamp : #151031 0:21:36 Table : `base1`.`PRICE`Timestamp : #151031 0:21:36 Table : `base1`.`SYNCINFO`Timestamp : #151031 0:21:36 Table : `mysql`.`ndb_apply_status` Query Type : UPDATE 1220 row(s) affected
[Transaction total : 1220 Insert(s) : 1 Update(s) : 1219 Delete(s) : 0] 

Timestamp : #151031 0:21:36 Table : `base1`.`PRICE`Timestamp : #151031 0:21:36 Table : `base1`.`SYNCINFO`Timestamp : #151031 0:21:36 Table : `mysql`.`ndb_apply_status` Query Type : UPDATE 1214 row(s) affected
[Transaction total : 1214 Insert(s) : 1 Update(s) : 1213 Delete(s) : 0] 

Ca c’est pour la méthode arawak, sinon j’ai découvert un toolkit fourni par Percona qui est pas mal.

https://www.percona.com/software/mysql-tools/percona-toolkit

On s’en servira dans l’analyse des slow query.

Analyse de slow query

Attention : on n’effectuera pas l’analyse sur le serveur car cela peut le surcharger. Ces commandes sont gourmandes.

Si les slow query ne sont pas activées faire ( Mysql >5.1 ) :

mysql> set global slow_query_log=1;
mysql> set global long_query_time=5;

Les slow query logguées seront d’un temps supérieur ou égal à 5 sec

Avec outils fournit par Mysql ( mysql-client package ) Trier par occurrence ( -s c ) et affichage du top 10 ( -t 10 ).

 mysqldumpslow -s c -t 10 mysql.slow

trier par le temps en sec qu’a mis chaque requête (-s t ) sinon voir man mysqldumpslow

 mysqldumpslow -s t -t 10 mysql.slow

Le fichier mysql.slow peut être très volumineux

Pour l’avoir sur une journée :

grep -A5  "151031" mysql.slow  > mysql_day_31.slow
mysqldumpslow -s t -t 10 mysql_day_31.slow

Exemple de rendu

Count: 22  Time=72.40s (1592s)  Lock=0.00s (0s)  Rows=0.0 (0), exportXML[exportXML]@xxxx.xxxxx.fr
  update XML_STAY set state=N, lastModif=null where state!=N limit N

Count: 1  Time=746.53s (746s)  Lock=0.00s (0s)  Rows=0.0 (0), base1[base1]@yxxxx.xxxxx.fr
  call base1.resetPrice()

Percona toolkit

pt-query-digest mysql.slow | less

Beaucoup plus lent que mysqldumpslow sur un gros fichier.

Analyse sur une plage réduite, beaucoup plus rapide que mysqldumpslow -g REGEXP qui est bug (grep)

pt-query-digest --since '2015-10-31 00:20:00' --until '2015-10-31 00:30:00' mysql.slow

Exemple de rendu :

# 164.8s user time, 980ms system time, 35.91M rss, 99.38M vsz
# Current date: Sun Nov  8 16:59:39 2015
# Hostname: xxxxxxx
# Files: mysql.slow
# Overall: 46 total, 9 unique, 0.08 QPS, 2.02x concurrency _______________
# Time range: 2015-10-31 00:20:06 to 00:29:48
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# Exec time          1177s      1s    747s     26s      3s    115s      1s
# Lock time             4s    33us      1s    87ms   356ms   215ms   972us
# Rows sent            690       0     669      15    0.99   95.12       0
# Rows examine       2.13M       0   2.11M  47.52k   2.06k 305.93k   26.08
# Query size        22.85k      23   1.25k  508.72  511.45  209.51  511.45

# Profile
# Rank Query ID           Response time  Calls R/Call   V/M   Item
# ==== ================== ============== ===== ======== ===== ============
#    1 0xF909A1007AFA8E5F 746.5286 63.4%     1 746.5286  0.00 CALL base.resetPrice
#    2 0x18DE522EBCC5AA94 360.0182 30.6%     1 360.0182  0.00 SELECT
#    3 0x65972C267C7778A3  43.2164  3.7%    25   1.7287  0.22 SELECT
# MISC 0xMISC              27.4046  2.3%    19   1.4423   0.0 <6 ITEMS>

Ensuite vient le détails de toutes les requêtes qui font parti du top. Les CALL sont des procédures stockées.

les requêtes contenant SQL_NO_CACHE sont des sauvegardes à moins que le dév soit complétement con.

Analyse de configuration

Voir la configuration live du cluster, fonctionne que sur un node de management.

#ndb_mgm
 ndb_mgm> show

20 est l’ID d’un datanodes.

ndb_mgm> 20 REPORT MEMORYUSAGE

donne la mémoire ( RAM ) utilisée pour le stockage des databases

voir

 pt-mysql-summary

config.ini est le fichier du cluster il est présent sur tous les nodes

my.cnf est la configuration d’un node Mysql ou API

Voici les paramètres intéressants :

log-error=/var/log/mysql.err
ndb-cluster-connection-pool=16
ndb_cache_check_time=2     // check cohérence des données en sec
long_query_time=5
slow_query_log=1
slow_query_log_file=/var/log/mysql.slow
query_cache_type=0  // désactive le cache les autres query_cache_* ne sont pas pris en compte.
max-connections=512  // déjà bien 1024 que sur les heavy prod

#binlogs conf
log-bin=mysql-bin
binlog-format=row
ndb-log-update-as-write=0
expire_logs_days=5

#engine
default-storage-engine=NDBCLUSTER
default_tmp_storage_engine=NDBCLUSTER

#Slave R/O 
server-id=1
slave_allow_batching=1
relay-log=mysql-relay-bin
replicate-wild-do-table=database_name.%
replicate-wild-do-table=replication_test.%
replicate-do-table=mysql.ndb_apply_status
slave-exec-mode=IDEMPOTENT
read_only=1

Analyse des logs

Sur les nodes de management

recherche des alertes dans les logs du cluster.

grep ALERT cluster.log

ou

ndb_mgm> 20 REPORT EVENTLOG

Sur les nodes les logs sont généralement dans /var/log/mysql/ et se nomme mysql.err

grep "cluster failure" /var/log/mysql.err |tail

Analyse couche SQL

Renvoi des tables qui n’utilise pas le moteur ndbcluster dans un cluster ndb.

mysql>use information_schema
mysql>select TABLE_CATALOG,TABLE_SCHEMA,TABLE_NAME,ENGINE from tables where ENGINE != "ndbcluster" ;

Exemple avec deux moteurs pour une base :

| def           | exportXML          | XML_FTP                               | InnoDB |
| def           | exportXML          | XML_PARAM                             | InnoDB |
| def           | exportXML          | XML_SITE                              | MyISAM |
| def           | exportXML          | XML_STAY                              | MyISAM |
| def           | exportXML          | XML_TARIFF                            | MyISAM |

Voir la liste des procédures stockées

mysql> select name from mysql.proc where db='database_name';

Voir le contenu d’une procédure

mysql>use information_schema;
mysql>select ROUTINE_DEFINITION FROM ROUTINES WHERE SPECIFIC_NAME='Nom_Procedure' AND ROUTINE_SCHEMA='Nom_Database';

Voir les triggers et les tablespaces en mode brut

mysqldump -p -u root --no-data --no-create-info database_name 

Taille d’une base en mode je connais que awk

mysql  -p database_name -e "show table status" 2>/dev/null |awk ' { SUM += $7; SUM += $9  } END { print SUM/1024/1024 }' | less

Taille en SQL

SELECT
 table_schema AS $DBNAME, 
 ROUND(SUM( data_length + index_length ) / 1024 / 1024, 2) AS BaseDonneesMo 
 FROM information_schema.TABLES
 GROUP BY TABLE_SCHEMA;
 

Autre méthode

SELECT 
 TABLE_NAME,
 CONCAT(ROUND(((DATA_LENGTH + INDEX_LENGTH - DATA_FREE) / 1024 / 1024), 2), 'Mo') AS TailleMo 
FROM information_schema.TABLES 
WHERE TABLE_SCHEMA = '$DBNAME'

Attention dans le cas d’un MysqlCluster, c’est les datanodes qui contiennent vraiment les données. Par conséquent un

du -sf /var/lib/mysql/*

N’aura aucun sens, à part si d’autres bases sont présentes en InnDB ou MyIsam.

Voir les types de moteur supportés

mysql> show engines ;
+--------------------+---------+----------------------------------------------------------------+--------------+------+------------+
| Engine             | Support | Comment                                                        | Transactions | XA   | Savepoints |
+--------------------+---------+----------------------------------------------------------------+--------------+------+------------+
| ndbcluster         | DEFAULT | Clustered, fault-tolerant tables                               | YES          | NO   | NO         |
| CSV                | YES     | CSV storage engine                                             | NO           | NO   | NO         |
| MyISAM             | YES     | MyISAM storage engine                                          | NO           | NO   | NO         |
| ndbinfo            | YES     | MySQL Cluster system information storage engine                | NO           | NO   | NO         |
| PERFORMANCE_SCHEMA | YES     | Performance Schema                                             | NO           | NO   | NO         |
| InnoDB             | YES     | Supports transactions, row-level locking, and foreign keys     | YES          | YES  | YES        |
| ARCHIVE            | YES     | Archive storage engine                                         | NO           | NO   | NO         |
| BLACKHOLE          | YES     | /dev/null storage engine (anything you write to it disappears) | NO           | NO   | NO         |
| FEDERATED          | NO      | Federated MySQL storage engine                                 | NULL         | NULL | NULL       |
| MRG_MYISAM         | YES     | Collection of identical MyISAM tables                          | NO           | NO   | NO         |
| MEMORY             | YES     | Hash based, stored in memory, useful for temporary tables      | NO           | NO   | NO         |
+--------------------+---------+----------------------------------------------------------------+--------------+------+------------+
11 rows in set (0.00 sec)

Analyse couche système

Recherche d’un manque de ressource système, la colonne la plus importante est failcount. marche uniquement sur un container openvz

cat /proc/user_beancounters

Nombre de threads Mysql, utile surtout sur les node mysqld et api

ps -Lfp `pidof mysqld` | wc -l

Les traditionnelles

  top 
  vmstat 
  free -h 
  cat /proc/cpu_info
  df -h 
  iostat -x