MySQLがサーバ再起動時にクラッシュして起動しなくなってしまった

Question

いつもお世話になっております。

標記の件につきまして、phpのあるスクリプトの不具合で
MySQLでトランザクションのロックが大量に発生してしまい、
手動でプロセスを削除したのですが、削除し切れず
MySQL自体をいったん停止させようとしたところ、
何回かトライしても停止に失敗してしまったので、
サーバの方で再起動をかけてみました。

OS: CentOS6.4
mysql Ver 14.14 Distrib 5.5.47, for Linux (x86_64) using readline 5.1

その後、MySQLが正常に起動せず、エラーログに以下のように
出力されております。

161110 10:04:01 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
161110 10:04:01 [Warning] Using unique option prefix thread_cache instead of thread_cache_size is deprecated and will be removed in a future release. Please use the full name instead.
161110 10:04:01 [Note] /usr/libexec/mysqld (mysqld 5.5.47-log) starting as process 6785 ...
161110 10:04:01 [Note] Plugin 'FEDERATED' is disabled.
161110 10:04:01 InnoDB: The InnoDB memory heap is disabled
161110 10:04:01 InnoDB: Mutexes and rw_locks use GCC atomic builtins
161110 10:04:01 InnoDB: Compressed tables use zlib 1.2.3
161110 10:04:01 InnoDB: Using Linux native AIO
161110 10:04:01 InnoDB: Initializing buffer pool, size = 1000.0M
161110 10:04:01 InnoDB: Completed initialization of buffer pool
161110 10:04:01 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
161110 10:04:01  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Last MySQL binlog file position 0 1065103915, file name ./mysql-bin.002966
161110 10:04:01  InnoDB: Waiting for the background threads to start
161110 10:04:02 InnoDB: 5.5.47 started; log sequence number 6110248889894
01:04:02 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=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=2000
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 = 4383254 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 0x40000
/usr/libexec/mysqld(my_print_stacktrace+0x2e)[0x78e06e]
/usr/libexec/mysqld(handle_fatal_signal+0x493)[0x6765d3]
/lib64/libpthread.so.0[0x3a1d40f710]
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.
161110 10:04:02 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

エラー内容を元に検索してみたのですが、キーワードが悪いのか
解決に至るような事例にたどり着けませんでした。

なお、my.cnfの設定は以下のようになっており、
サーバの再起動前は特に問題なく動いておりました。

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock

symbolic-links=0
character-set-server = utf8

user=mysql

max_connections = 2000
thread_cache = 600
thread_cache_size = 50
table_open_cache = 512
wait_timeout = 300
max_connect_errors = 10000
query_cache_type = 0
query_cache_size = 0
tmp_table_size = 1024M
max_heap_table_size = 1024M
innodb_buffer_pool_size = 1000M

slow_query_log=1
slow_query_log_file=mysql-slow.log
long_query_time=10

log-bin=mysql-bin
expire_logs_days=3

[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

つきましては、何か解決のヒントになるようなことがございましたら、
ご教授いただけると助かります。

それでは、よろしくお願いいたします。

Answer 1

ざっくり検索した感じだと、以下の事案に類似しているかなぁと...
記事内では自己解決しているようですが、自分では解決方法を読んでも意味がよくわかりませんでした...。
mysqld got signal 11 - it's my fault but how do I fix it?

※ロック絡みだし、ログの出力(backtrace)が同じなので、参考になれば幸いです...

Comments

[chapter]

icchiiさん、ご回答ありがとうございます。

ご提示いただいたリンク先から、下記ページの内容を試してみました。

http://notesonit.blogspot.jp/2013/05/innodb-unable-to-lock-ibdata1-error-11.html

上記に書かれているように、「ibdata1」と「ib_logfile* (実際にはib_logfile0,
ib_logfile1の2つ)」のファイルをバックアップフォルダに移してから、
cpコマンドで-aを付けて元のフォルダに戻したところ、
起動はしなかったのですが、試しに「ibdata1」だけ戻して、
「ib_logfile0」「ib_logfile1」がない状態でMySQLを起動したところ、
データも全て復旧して稼働させることができました！

アドバイスありがとうございました。

[popobot]

リカバリできてよかったです。
cp -aにどんな意味があるのかよくわからないですが...
logfileがなければ動いたのであれば、logfileが壊れていたんですかね
もしかしたら、完全にはクラッシュリカバリできていなかったかもしれませんが、
確認する範囲でデータに問題なければ大丈夫な気がします。

[chapter]

icchiiさん、ありがとうございました。

確かにcp -aは機能的に見ても、あまり意味はなさそうな気はしますね。

icchiiさんが仰るようにlogfileが壊れていたのが原因だと私も思いますので、
恐らく今回はibdata1をcp -aで戻したことより、logfileを削除したことが
復旧の鍵なのかなと思っています。

なので、ibdata1はそのままで、ib_logfileだけバックアップフォルダに
移動させて、MySQLを再起動するだけで復旧できたのかも知れません。

また、データの方は重要なものは全て問題ないことが確認できました。

細かい更新データはリカバリできていないものもあると思われますが、
数時間で更新処理が一周りする感じなので、すぐに新しい更新データに
置き換わるので問題ない感じです。

アドバイスありがとうございました。

Answer 2

有償サポートに問い合わせるか、環境を再構築するのが早そうな気がします。

参考となりそうな情報
http://dev.mysql.com/doc/refman/5.6/ja/crashing.html
http://www.ark-web.jp/sandbox/wiki/228.html

innodb_force_recoveryについて、コメントがあったので参考までに補足します。
5でUNDOログの未参照、6でREDOログのロールフォワード未実施での起動となります。
https://dev.mysql.com/doc/refman/5.6/ja/forcing-innodb-recovery.html

Comments

[chapter]

yodelさん、ご回答ありがとうございます。

MySQLのデータフォルダ(innodb)を退避することで、
MySQL自体の起動はできたので再構築まではしなくても
大丈夫そうでしたが、バックアップを取っているデータが
数日前のものだったので、できる限り最新のデータで
復旧したいと試行錯誤しておりました。

なお、２つ目のリンク先に記載されていた以下の記述を
追加しても起動できなかったので、残念ながらその先には
進めませんでしたが、アドバイスありがとうございました。

[mysqld]
innodb_force_recovery=3

[chapter]

yodelさん、補足コメントありがとうございます。

お陰さまでinnodb_force_recoveryの数値の意味が分かりました。

3より大きい数値で試してみれば、何か進展があったかも知れないですね。

今後、何か問題が発生した時は、innodb_force_recoveryの数値を少しずつ
上げて試してみようと思います。

Answer 3

同じような質問がきのうもあります。
MySQLの起動に失敗します
エラーメッセーなどでググるとかなり解決策が見つかりますよ。

Comments

[chapter]

Orlofskyさん、ご回答ありがとうございます。

Google検索でも、ご紹介いただいた質問と同じように
インストール後の初回起動時から起動しない問題についての内容が
ほとんどで、今回の私のように以前は正常に起動していて、
途中でクラッシュしたケースの事例で解決できる内容のものが
見つけられなかったため、こちらに質問させていただいた
次第でございます。