Gros plantage de mon serveur mysql.

[Tom23]

Salut !

Je me tourne vers vous pour chercher une solution à un gros soucis :

Je virtualise un serveur web sous proxmox 3. Il est sous debian 7 avec LAMP et virtualmin pour héberger 5-6 sites. Ce midi après un reboot, impossible de démarrer mysql. Et comme j'ai beaucoup de chance mes sauvegardes locales et distantes gérées par virtualmin ne sont pas utilisable.

Donc le soucis c'est que mysql ne démarre pas, et je voilà le contenu du syslog:

Nov  4 22:33:07 chicago mysqld_safe: Starting mysqld daemon with databases from /var/lib/mysql
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 [Note] Plugin 'FEDERATED' is disabled.
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: The InnoDB memory heap is disabled
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: Mutexes and rw_locks use GCC atomic builtins
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: Compressed tables use zlib 1.2.7
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: Using Linux native AIO
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: Initializing buffer pool, size = 128.0M
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: Completed initialization of buffer pool
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07 InnoDB: highest supported file format is Barracuda.
Nov  4 22:33:07 chicago mysqld: InnoDB: The log sequence number in ibdata files does not match
Nov  4 22:33:07 chicago mysqld: InnoDB: the log sequence number in the ib_logfiles!
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07  InnoDB: Database was not shut down normally!
Nov  4 22:33:07 chicago mysqld: InnoDB: Starting crash recovery.
Nov  4 22:33:07 chicago mysqld: InnoDB: Reading tablespace information from the .ibd files...
Nov  4 22:33:07 chicago mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
Nov  4 22:33:07 chicago mysqld: InnoDB: buffer...
Nov  4 22:33:07 chicago mysqld: 131104 22:33:07  InnoDB: Waiting for the background threads to start
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 InnoDB: 5.5.31 started; log sequence number 189014041
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 [Note] Server hostname (bind-address): '192.168.0.202'; port: 3306
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 [Note]   - '192.168.0.202' resolves to '192.168.0.202';
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 [Note] Server socket created on IP: '192.168.0.202'.
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08  InnoDB: Assertion failure in thread 140519055632128 in file trx0purge.c line 840
Nov  4 22:33:08 chicago mysqld: InnoDB: Failing assertion: purge_sys->purge_trx_no <= purge_sys->rseg->last_trx_no
Nov  4 22:33:08 chicago mysqld: InnoDB: We intentionally generate a memory trap.
Nov  4 22:33:08 chicago mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Nov  4 22:33:08 chicago mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Nov  4 22:33:08 chicago mysqld: InnoDB: immediately after the mysqld startup, there may be
Nov  4 22:33:08 chicago mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Nov  4 22:33:08 chicago mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
Nov  4 22:33:08 chicago mysqld: InnoDB: about forcing recovery.
Nov  4 22:33:08 chicago mysqld: 21:33:08 UTC - mysqld got signal 6 ;
Nov  4 22:33:08 chicago mysqld: This could be because you hit a bug. It is also possible that this binary
Nov  4 22:33:08 chicago mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Nov  4 22:33:08 chicago mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Nov  4 22:33:08 chicago mysqld: We will try our best to scrape up some info that will hopefully help
Nov  4 22:33:08 chicago mysqld: diagnose the problem, but since we have already crashed, 
Nov  4 22:33:08 chicago mysqld: something is definitely wrong and this may fail.
Nov  4 22:33:08 chicago mysqld: 
Nov  4 22:33:08 chicago mysqld: key_buffer_size=16777216
Nov  4 22:33:08 chicago mysqld: read_buffer_size=262144
Nov  4 22:33:08 chicago mysqld: max_used_connections=0
Nov  4 22:33:08 chicago mysqld: max_threads=151
Nov  4 22:33:08 chicago mysqld: thread_count=0
Nov  4 22:33:08 chicago mysqld: connection_count=0
Nov  4 22:33:08 chicago mysqld: It is possible that mysqld could use up to 
Nov  4 22:33:08 chicago mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 134074 K  bytes of memory
Nov  4 22:33:08 chicago mysqld: Hope that's ok; if not, decrease some variables in the equation.
Nov  4 22:33:08 chicago mysqld: 
Nov  4 22:33:08 chicago mysqld: Thread pointer: 0x0
Nov  4 22:33:08 chicago mysqld: Attempting backtrace. You can use the following information to find out
Nov  4 22:33:08 chicago mysqld: where mysqld died. If you see no messages after this, something went
Nov  4 22:33:08 chicago mysqld: terribly wrong...
Nov  4 22:33:08 chicago mysqld: stack_bottom = 0 thread_stack 0x40000
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x29)[0x7fcd38476569]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x3d8)[0x7fcd3835e748]
Nov  4 22:33:08 chicago mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf030)[0x7fcd37b10030]
Nov  4 22:33:08 chicago mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7fcd363a3475]
Nov  4 22:33:08 chicago mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7fcd363a66f0]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x57f8e5)[0x7fcd384be8e5]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x57fce9)[0x7fcd384bece9]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x64180f)[0x7fcd3858080f]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x63825b)[0x7fcd3857725b]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x580e39)[0x7fcd384bfe39]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x57299c)[0x7fcd384b199c]
Nov  4 22:33:08 chicago mysqld: /usr/sbin/mysqld(+0x576b63)[0x7fcd384b5b63]
Nov  4 22:33:08 chicago mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7fcd37b07b50]
Nov  4 22:33:08 chicago mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fcd3644ba7d]
Nov  4 22:33:08 chicago mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Nov  4 22:33:08 chicago mysqld: information that should help you find out what is causing the crash.
Nov  4 22:33:08 chicago mysqld_safe: Number of processes running now: 0
Nov  4 22:33:08 chicago mysqld_safe: mysqld restarted
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 [Note] Plugin 'FEDERATED' is disabled.
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 InnoDB: The InnoDB memory heap is disabled
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 InnoDB: Mutexes and rw_locks use GCC atomic builtins
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 InnoDB: Compressed tables use zlib 1.2.7
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 InnoDB: Using Linux native AIO
Nov  4 22:33:08 chicago mysqld: 131104 22:33:08 InnoDB: Initializing buffer pool, size = 128.0M
Nov  4 22:33:09 chicago mysqld: 131104 22:33:09 InnoDB: Completed initialization of buffer pool
Nov  4 22:33:09 chicago mysqld: 131104 22:33:09 InnoDB: highest supported file format is Barracuda.
Nov  4 22:33:09 chicago mysqld: InnoDB: The log sequence number in ibdata files does not match
Nov  4 22:33:09 chicago mysqld: InnoDB: the log sequence number in the ib_logfiles!
Nov  4 22:33:09 chicago mysqld: 131104 22:33:09  InnoDB: Database was not shut down normally!
Nov  4 22:33:09 chicago mysqld: InnoDB: Starting crash recovery.
Nov  4 22:33:09 chicago mysqld: InnoDB: Reading tablespace information from the .ibd files...
Nov  4 22:33:09 chicago mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
Nov  4 22:33:09 chicago mysqld: InnoDB: buffer...
Nov  4 22:33:09 chicago mysqld: 131104 22:33:09  InnoDB: Waiting for the background threads to start
Nov  4 22:33:10 chicago mysqld: 131104 22:33:10 InnoDB: 5.5.31 started; log sequence number 189014041
Nov  4 22:33:10 chicago mysqld: 131104 22:33:10 [Note] Server hostname (bind-address): '192.168.0.202'; port: 3306
Nov  4 22:33:10 chicago mysqld: 131104 22:33:10 [Note]   - '192.168.0.202' resolves to '192.168.0.202';
Nov  4 22:33:10 chicago mysqld: 131104 22:33:10 [Note] Server socket created on IP: '192.168.0.202'.
Nov  4 22:33:10 chicago mysqld: 131104 22:33:10  InnoDB: Assertion failure in thread 140701765019392 in file trx0purge.c line 840
Nov  4 22:33:10 chicago mysqld: InnoDB: Failing assertion: purge_sys->purge_trx_no <= purge_sys->rseg->last_trx_no
Nov  4 22:33:10 chicago mysqld: InnoDB: We intentionally generate a memory trap.
Nov  4 22:33:10 chicago mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Nov  4 22:33:10 chicago mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Nov  4 22:33:10 chicago mysqld: InnoDB: immediately after the mysqld startup, there may be
Nov  4 22:33:10 chicago mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Nov  4 22:33:10 chicago mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
Nov  4 22:33:10 chicago mysqld: InnoDB: about forcing recovery.
Nov  4 22:33:10 chicago mysqld: 21:33:10 UTC - mysqld got signal 6 ;
Nov  4 22:33:10 chicago mysqld: This could be because you hit a bug. It is also possible that this binary
Nov  4 22:33:10 chicago mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Nov  4 22:33:10 chicago mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Nov  4 22:33:10 chicago mysqld: We will try our best to scrape up some info that will hopefully help
Nov  4 22:33:10 chicago mysqld: diagnose the problem, but since we have already crashed, 
Nov  4 22:33:10 chicago mysqld: something is definitely wrong and this may fail.
Nov  4 22:33:10 chicago mysqld: 
Nov  4 22:33:10 chicago mysqld: key_buffer_size=16777216
Nov  4 22:33:10 chicago mysqld: read_buffer_size=262144
Nov  4 22:33:10 chicago mysqld: max_used_connections=0
Nov  4 22:33:10 chicago mysqld: max_threads=151
Nov  4 22:33:10 chicago mysqld: thread_count=0
Nov  4 22:33:10 chicago mysqld: connection_count=0
Nov  4 22:33:10 chicago mysqld: It is possible that mysqld could use up to 
Nov  4 22:33:10 chicago mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 134074 K  bytes of memory
Nov  4 22:33:10 chicago mysqld: Hope that's ok; if not, decrease some variables in the equation.
Nov  4 22:33:10 chicago mysqld: 
Nov  4 22:33:10 chicago mysqld: Thread pointer: 0x0
Nov  4 22:33:10 chicago mysqld: Attempting backtrace. You can use the following information to find out
Nov  4 22:33:10 chicago mysqld: where mysqld died. If you see no messages after this, something went
Nov  4 22:33:10 chicago mysqld: terribly wrong...
Nov  4 22:33:10 chicago mysqld: stack_bottom = 0 thread_stack 0x40000
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x29)[0x7ff7c29b6569]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x3d8)[0x7ff7c289e748]
Nov  4 22:33:10 chicago mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf030)[0x7ff7c2050030]
Nov  4 22:33:10 chicago mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7ff7c08e3475]
Nov  4 22:33:10 chicago mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7ff7c08e66f0]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x57f8e5)[0x7ff7c29fe8e5]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x57fce9)[0x7ff7c29fece9]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x64180f)[0x7ff7c2ac080f]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x63825b)[0x7ff7c2ab725b]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x580e39)[0x7ff7c29ffe39]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x57299c)[0x7ff7c29f199c]
Nov  4 22:33:10 chicago mysqld: /usr/sbin/mysqld(+0x576b63)[0x7ff7c29f5b63]
Nov  4 22:33:10 chicago mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7ff7c2047b50]
Nov  4 22:33:10 chicago mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ff7c098ba7d]
Nov  4 22:33:10 chicago mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Nov  4 22:33:10 chicago mysqld: information that should help you find out what is causing the crash.
Nov  4 22:33:10 chicago mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
Nov  4 22:33:21 chicago /etc/init.d/mysql[11053]: 0 processes alive and '/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf ping' resulted in
Nov  4 22:33:21 chicago /etc/init.d/mysql[11053]: #007/usr/bin/mysqladmin: connect to server at 'localhost' failed
Nov  4 22:33:21 chicago /etc/init.d/mysql[11053]: error: 'Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)'
Nov  4 22:33:21 chicago /etc/init.d/mysql[11053]: Check that mysqld is running and that the socket: '/var/run/mysqld/mysqld.sock' exists!

J'ai testé 2 ou 3 trucs mais rien de probant. Et comme je connais mal mysql je galère sérieusement.

Je cherche dans 2 directions :

-D'une part remettre en service ce serveur pour éviter un tas de manipulations des bases de données qui sont compliquées vu que le serveur mysql ne fonctionne pas (je préfèrerai partir sur cette solution)

-Ou d'autre part mettre en place un autre serveur et bidouiller pour importer les fichiers et bases de données sans l'aide de mysql.

Si vous avez des idées je suis preneur. J'ai quelques heures d'essais infructueux derrière moi je ne vois pas trop comment m'en sortir.

Merci d'avance !

[seboss666]

As-tu tenté ce qu'un des messages de ce log te propose, à savoir http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html ?

En gros l'idée est démarrer avec la base en l'état, sans chercher à la mettre à jour suite au plantage, dans une sorte de mode lecture seule. Ca permet ensuite de faire un dump dans un fichier, de tout refaire et de réintroduire les données, ce qui devrait à priori limiter d'éventuelles pertes. Je conseille malgré tout de le faire sur une copie du dossier contenant les bases au cas où.

[Tom23]

Je l'avais fait sans succès hier mais je ne vois pas trop pourquoi.

Ce matin j'ai ressorti une sauvegarde de la VM que j'avais faite juste avant d'attaquer le gros chantier de dépannage. J'ai réessayé l'ajout de cette ligne avec succès et les sites re-fonctionnent tous juste en redémarrant mysql. C'est bancale, mais le service est rétabli.

Il faut que je me penche sur la suite du programme quand j'aurai le temps de le faire tranquillement.

Question : j'ai jamais pratiqué ce type de manip avec mysql. Si j'applique cette méthode, vais-je retrouver des sites fonctionnels directement comme avant ou je dois me préparer à une réinstallation de ceux-ci ?

(je pars du principe que tout se passera bien)

[seboss666]

Ca dépend s'il arrive à recaler correctement les index ou pas. S'il trouve trop d'incohérences, y'a des chances qu'il faille réinstaller les sites, et tenter de réinjecter les données "à la main" par la suite. C'est pas impossible, mais tellement lourd à faire qu'il est difficile de prédire un résultat. Je ferais quand même un bon gros checkup. Et attention, normalement, mysql fonctionne dans un mode semi-lecture seule, pas recommandé pour les sites. A moins qu'un démarrage en checkup, puis un redémarrage standard aie résolu le problème, mais j'ai un doute (remarque Windows 98 marchait comme ça quand ça déconnait).

Mais à mon avis t'as un autre problème qui traine. Si les sauvegardes sont aussi dans les choux, c'est qu'il devait trainer une belle saloperie là-dedans. J'ai le tour avec le site de ma team, une des tables arrive apparemment à se taper des index dupliqués. Youhou, ça vautrait l'export, et quand je changeais de méthode pour avoir un export complet, ça merdait à l'import. J'ai pu contourner en vidant la table (qui ne servait que pour des stats non vitales), mais c'est pas propre malgré tout.

[Tom23]

La soluce de Seboss666 m'a bien aidée.

En mettant InnoDB en mode recovery les sites se sont mis à re-fonctionner presque normalement. Plutôt que d'attaquer la suite de la solution j'ai profité de ce que mysql tourne pour récupérer proprement les BDD et les sites et les envoyer vers une nouvelle VM avec un serveur web tout frais.

Tout est à nouveau en ligne sans perte de données.

J'en ai profiter pour revoir complètement mon système de sauvegarde.

[seboss666]

Encore une victoire de canard Tom23