Petits ennuis

Petits ennuis jpp

Un petit chapitre sur quelques "ennuis".

 

MariaDB binlog non supprimés !

MariaDB binlog non supprimés ! jpp

Un petit ennui : les fichiers "binlog" ne sont plus supprimés malgré la présence du paramètre adéquat : expire_logs_days        = 3 
Ce phénomène m'a été montré par l'augmentation anormale de la taille de la partition qui supporte ces fichiers et son approche des 100% fatidiques. 
Après quelques recherches sur Internet je ne trouve rien à ce sujet. 
J'essaye de purger ces fichus binlog avec la commande "purge binlog until '2022-06-14' " ou "purge binlog to '0000xxxxxxxxxx' ". 
Ces commandes me répondent invariablement "fichier log non trouvé dans l'index" .... ???? .... 
J'allais me résoudre à une manip hasardeuse de destruction "manuelle avec rm ..." et mise à jour du fichier d'index, lorsque j'ai remarqué que le fichier index, "mysql-binlog.index" chez moi, comportait une ligne blanche en tête. 
Je stoppe MariaDB et supprime cette fichue ligne "blanche" et, miracle, lors du redémarrage de MariaDB tous les vieux binlog disparaissent en respectant bien la limite à trois jours et la partition revient à un pourcentage et un nombre de fichiers bien plus sympathique. 
Depuis 2 jours tout est normal et aucun fichier ne date de plus de 3 jours .... le problème semble donc réglé.

Mysql se plante inopinément

Mysql se plante inopinément jpp

J'ai eu récemment un plantage violent de Mysql suite à une mise à jour d'une Debian 9. Le process Mysql avait une fâcheuse tendance à consommer tout le CPU et manifestait son mécontentement par de nombreux messages, le total fait plus de 4000 lignes, j'en ai extrait les parties les plus typiques :

InnoDB: Warning: a long semaphore wait: 
--Thread 140616820184832 has waited at row0ins.cc line 2338 for 241.00 seconds the semaphore: 
X-lock (wait_ex) on RW-latch at 0x7fe4bf71d740 created in file buf0buf.cc line 1069 
a writer (thread id 140616820184832) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff 
Last time read locked in file buf0flu.cc line 1056 
Last time write locked in file /build/mysql-5.6-dqP7lI/mysql-5.6-5.6.30/storage/innobase/btr/btr0sea.cc line 931 
InnoDB: Warning: a long semaphore wait: 
--Thread 140616820987648 has waited at trx0sys.ic line 103 for 241.00 seconds the semaphore: 
X-lock (wait_ex) on RW-latch at 0x7fe4bf6419c0 created in file buf0buf.cc line 1069 
a writer (thread id 140616820987648) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff 
Last time read locked in file buf0flu.cc line 1056 
Last time write locked in file /build/mysql-5.6-dqP7lI/mysql-5.6-5.6.30/storage/innobase/include/trx0sys.ic line 103 
...... 
===================================== 
2018-05-02 16:22:23 7fe3eab6b700 INNODB MONITOR OUTPUT 
===================================== 
..... 
OS WAIT ARRAY INFO: reservation count 2825 
--Thread 140616820184832 has waited at row0ins.cc line 2338 for 259.00 seconds the semaphore: 
X-lock (wait_ex) on RW-latch at 0x7fe4bf71d740 created in file buf0buf.cc line 1069 
a writer (thread id 140616820184832) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff 
Last time read locked in file buf0flu.cc line 1056 
Last time write locked in file /build/mysql-5.6-dqP7lI/mysql-5.6-5.6.30/storage/innobase/btr/btr0sea.cc line 931 
--Thread 140616820987648 has waited at trx0sys.ic line 103 for 259.00 seconds the semaphore: 
X-lock (wait_ex) on RW-latch at 0x7fe4bf6419c0 created in file buf0buf.cc line 1069 
a writer (thread id 140616820987648) has reserved it in mode  wait exclusive 
number of readers 1, waiters flag 1, lock_word: ffffffffffffffff 
Last time read locked in file buf0flu.cc line 1056 
Last time write locked in file /build/mysql-5.6-dqP7lI/mysql-5.6-5.6.30/storage/innobase/include/trx0sys.ic line 103 
.... 
---TRANSACTION 453618943, not started 
mysql tables in use 3, locked 0 
MySQL thread id 18313, OS thread handle 0x7fe3e5cc0700, query id 223424 localhost 127.0.0.1 ossec preparing 
..... 
-------- 
FILE I/O 
-------- 
I/O thread 0 state: waiting for completed aio requests (insert buffer thread) 
I/O thread 1 state: waiting for completed aio requests (log thread) 
I/O thread 2 state: waiting for completed aio requests (read thread) 
I/O thread 3 state: waiting for completed aio requests (read thread) 
I/O thread 4 state: waiting for completed aio requests (write thread) 
...... 
2018-05-02 19:40:33 4690 [ERROR] InnoDB: Failed to find tablespace for table '"snorby"."delayed_jobs"' in the cache. Attempting to load the tablespace with space id 6766. 
2018-05-02 19:40:33 4690 [ERROR] InnoDB: Failed to find tablespace for table '"snorby"."tcphdr"' in the cache. Attempting to load the tablespace with space id 6787. 
...... 
2018-05-02 19:40:33 4690 [Note] Recovering after a crash using /var/log/mysql/mysql-bin 
2018-05-02 19:40:34 4690 [Note] Starting crash recovery... 
2018-05-02 19:40:34 4690 [Note] Crash recovery finished. 
17:40:34 UTC - mysqld got signal 11 ; 
This could be because you hit a bug. It is also possible that this binary 
or one of the libraries it was linked against is corrupt, improperly built, 
or misconfigured. This error can also be caused by malfunctioning hardware. 
We will try our best to scrape up some info that will hopefully help 
diagnose the problem, but since we have already crashed,  
something is definitely wrong and this may fail.

key_buffer_size=524288 
read_buffer_size=2097152 
max_used_connections=0 
max_threads=32 
thread_count=0 
connection_count=0 
It is possible that mysqld could use up to  
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 131992 K  bytes of memory 
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0 
Attempting backtrace. You can use the following information to find out 
where mysqld died. If you see no messages after this, something went 
terribly wrong... 
stack_bottom = 0 thread_stack 0x30000 
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0x90742b] 
/usr/sbin/mysqld(handle_fatal_signal+0x36a)[0x666f1a] 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x110c0)[0x7fef467060c0] 
/usr/sbin/mysqld(_ZN9MYSQL_LOG17generate_new_nameEPcPKc+0x74)[0x64eab4] 
/usr/sbin/mysqld(_ZN9MYSQL_LOG26init_and_set_log_file_nameEPKcS1_13enum_log_type10cache_type+0x3f)[0x64eb5f] 
/usr/sbin/mysqld(_ZN13MYSQL_BIN_LOG11open_binlogEPKcS1_10cache_typembbbP28Format_description_log_event+0x72)[0x8a6a82] 
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0xc87)[0x5981c7] 
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)[0x7fef450772e1] 
/usr/sbin/mysqld[0x58c34a] 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains 
information that should help you find out what is causing the crash. 
180502 19:40:34 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

J'ai commencé par copier l'intégralité des fichiers de la base sur un autre disque afin de préserver leur état. 
Après recherche sur Internet et plusieurs essais de redémarrage infructueux, y compris par l'utilisation de "innodb_force_recovery = 1". 
J'ai alors songé à examiner le syslog et j'y ai trouvé de nombreux messages tels que :

....apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/MYSQL_DATA/mysql/" pid=4690 comm="mysqld" requested_mask="r" denied_mask="r" 

Note : chez moi les données de Mysql sont stockées dans une partition spécifique (sur SSD) montée sur /MYSQL_DATA/mysql.

J'ai alors cherché un fichier "usr.sbin.mysqld", vainement, dans /etc/apparmor.d, aucune trace d'un tel fichier !  
Je n'ai pas pu trouver l'origine de cette disparition, probablement la dernière mise à jour et j'ai du récupérer ce fichier "usr.sbin.mysqld" et son copain dans "/etc/apparmor.d/local" sur une autre machine et le personnaliser à nouveau car cette base utilise une partition séparée ... 
J'ai aussi voulu mettre apparmor en mode "complain" pour mysqld mais je me suis aperçu que le paquet "apparmor-utils" qui contient, entre autres, la fonction "aa-complain" qui permet de gérer cela brillait par son absence, j'ai donc du installer ce paquet pour placer /usr/sbin/mysqld en mode "complain" en attendant d'analyser les données fournies par les logs. 
Ensuite Mysql a démarré sans encombres et fonctionne normalement depuis.

En fait les messages de Mysql sont le reflet des erreurs induites par les blocages effectués par Apparmor suite à l'absence (inexpliquée à ce jour d'un fichier de paramétrage de Apparmor) et non dus à un dysfonctionnement de Mysql ou d'un problème système quelconque (librairies, disque ....). 
Enfin ce type d'erreur est de plus en plus rare, les "paquets" sont, en général, bien configurés coté "apparmor".

Mysql : refus demarrage

Mysql : refus demarrage jpp

Juste avant de partir une semaine en congés, j'ai effectué une mise à jour du système qui "supporte", entre autres choses, la machine virtuelle (KVM) de ce site, j'ai eu le malheur de ré-démarrer le machine, petit nettoyage de la mémoire avant de partir ... 
Je n'ai pas vérifié que tout se passait bien au redémarrage et, quelques heures après en consultant mes mails j'ai constaté que la base de données de ce système était inaccessible et que certains logiciels ne fonctionnaient plus car ils utilisent cette base Mysql ... 
Dans le coin où j'étais en congés les liaisons téléphoniques étaient tellement mauvaises que je n'ai pas pu prendre la main à distance pour étudier ce phénomène. J'ai du attendre le retour pour me pencher sur cet ennui. 
Mysql ne se lançait plus et, comme d'habitude, les renseignements fournis par systemd étaient insuffisants pour toute analyse sérieuse : le service a retourné une erreur ... ce n'est pas très informatif sur la nature de l'erreur et donc franchement inutile ! 
Une erreur c'est bien de le savoir, mais il serait mieux de savoir laquelle en ayant un message sensé aidant à comprendre le pourquoi ! 
En lançant Mysql "à la main" en tant qu'utilisateur "mysql" (il faut modifier le shell de démarrage dans /etc/password de /bin/false à /bin/bash) j'ai tout de suite eu un message "fichier my.cnf inexistant", ce qui était beaucoup plus clair que "le service a retourné une erreur'. Ne pas oublier de repasser cet utilisateur à "/bin/false" après la manip ! 
Je me précipite dans /etc/mysql et ... le fichier "my.cnf" est présent sous la forme d'un lien vers /etc/alternatives/my.cnf", or en tentant de le lister j'obtiens un message de fichier inexistant ... et dans /etc/alternatives il existe bien un fichier "my.cnf" mais sous la forme d'un lien vers /etc/mysql/my.cnf !!! 
Je crée donc un "vrai" fichier "my.cnf" contenant :

[mysqld] 
!includedir /etc/mysql/mysql.conf.d/

Et systemd lance la base de données sans aucun message alarmant, mais je ne saurais jamais comment et par qui ce lien "en boucle" a été mis en place.