2012年10月14日日曜日

ダメです!MySQL起動しません!

タイトルから何か連想した人は友達になれそうです(ΦωΦ)フフフ…

さて、いつかの記事で大量なレコード作る実験をしていた時に、
実験をしておきながらせっかちな自分は
SQLが終わるのを待てずに、SQLのプロセスをkillしてしまいました。(`・ω・´)シャキーン
またなぜかkillしたのにずっとSHOW PROCESSLISTに残ってしまっていたので、
MySQLの再起動すれば消えるだろう?的な発想でMySQLを再起動したときの泣ける話です(´;ω;`)ウッ…

MySQLを停止しようとしたら、
# /etc/init.d/mysqld stop
Timeout error occurred trying to stop MySQL Daemon.
Stopping mysqld:                                           [FAILED]
となり、停止に失敗してしまいました。
プロセスを見てみると、
# ps aux|grep -i [m]ysql
root     13943  0.0  0.0 106108  1492 pts/2    S    17:30   0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --socket=/var/lib/mysql/mysql.sock --pid-file=/var/run/mysqld/mysqld.pid --basedir=/usr --user=mysql
mysql    14744 43.5 23.8 3277100 1957400 pts/2 Sl   17:30   2:50 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/data/mysql-log/mysql-error.log --open-files-limit=8192 --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock --port=3306
K1-admin 16048  0.0  0.0 100848   616 pts/0    S+   17:36   0:00 tail -f /data/mysql-log/mysql-error.log
プロセスが存在しているので、ログインできるのか試してみたら
ログインができませんでした・・・(´;ω;`)ウッ…
# mysql -u root -p shutdown
Enter password:
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
もちろん起動を行ってもエラーになります。
# /etc/init.d/mysqld start
MySQL Daemon failed to start.
Starting mysqld:                                           [FAILED]
調べてみたら、mysql_install_dbやると(・∀・)イイネ!!ってのをいくつか見つけたので
実行してみましたが、うまくいきませんでした。
後は、手動でmysql.sockを作ってしまえとか!

他にも調べていたら、正常にMySQLがシャットダウンされなかった場合に、
sockだけが削除されてしまって、プロセスだけが生きているような状態になり、
ログインが出来なくなるみたいでした。

確認してみるとmysql.sockが無くなっている状態でした。これだっ!(σ・∀・)σ
# ls -alt /var/lib/mysql/mysql.sock
ls: cannot access /var/lib/mysql/mysql.sock: No such file or directory
とりあえずコマンドで停止出来るか確認。
# mysqladmin -u root shutdown
Enter password:
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
# mysqladmin -u root --host=IP Address shutdown
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
どちらもできなかったので、killをしてしまいますよ!奥さんっ!!ヾ(・д・` )ネェネェ
# ps aux|grep -i [m]ysql
root     16664  0.0  0.0 106108  1496 pts/2    S    17:44   0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --socket=/var/lib/mysql/mysql.sock --pid-file=/var/run/mysqld/mysqld.pid --basedir=/usr --user=mysql
mysql    17465 47.3 28.1 3540304 2307332 pts/2 Sl   17:44   5:59 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/data/mysql-log/mysql-error.log --open-files-limit=8192 --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock --port=3306
K1-admin 18643  0.0  0.0 100848   616 pts/0    S+   17:49   0:00 tail -f /data/mysql-log/mysql-error.log
# kill -9 16664
# kill -9 17465
killしちゃって大丈夫・・・!?って思ったそこの奥さん!!!
こちらを参考にしてみてください。
Doing recoveryがリカバリの本体で、読んでいるのはバイナリログではなくてInnoDBログ。innodb_doublewriteはPartial Write対策で、kill -9程度ならOFFでも壊れないはず。 doublewriteなしで壊れうるのはリアル電プチのとき http://bit.ly/q8SuDB


killしたことによってプロセスは見事に全部消えましたので、
今度は起動を行っています。
# /etc/init.d/mysqld start
MySQL Daemon failed to start.
Starting mysqld:                                           [FAILED]
( ´゚д゚`)エー・・・起動できませんでした。
ログを確認してみると以下のエラーが発生していました。
/usr/libexec/mysqld: File './mysql-bin.000121' not found (Errcode: 13)
mysql-bin000121が見つからないよ!ってことなので確認してみると、
mysql-bin.000121は存在していたが、所有者がrootになってしまっているので、mysqlに変更する
# ls -alt /data/mysql/
-rw-rw----  1 root  root      1031892 Oct 14 17:07 mysql-bin.000121
-rw-rw----  1 mysql mysql        2299 Oct 14 17:07 mysql-bin.index
-rw-rw----  1 root  root        26239 Oct 14 17:07 mysql-bin.000120
drwx------  2 root  root         4096 Oct 14 17:07 performance_schema

# chown mysql:mysql /data/mysql/mysql-bin.*

# ls -alt /data/mysql/
-rw-rw----  1 mysql mysql     1031892 Oct 14 17:07 mysql-bin.000121
-rw-rw----  1 mysql mysql        2299 Oct 14 17:07 mysql-bin.index
-rw-rw----  1 mysql mysql       26239 Oct 14 17:07 mysql-bin.000120
drwx------  2 root  root         4096 Oct 14 17:07 performance_schema
-rw-rw----  1 mysql mysql         226 Oct 14 15:54 mysql-bin.000119
-rw-rw----  1 mysql mysql  1131533376 Oct 14 15:05 mysql-bin.000118
-rw-rw----  1 mysql mysql         150 Oct 14 03:48 mysql-bin.000117
再度起動!
# /etc/init.d/mysqld start
Starting mysqld:                                           [  OK  ]

# mysql -u root
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.5.22-log MySQL Community Server (GPL) by Remi

Copyright (c) 2000, 2011, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> Ctrl-C -- exit!
Aborted
復旧キタ*・゜゚・*:.。..。.:*・゜(゚∀゚)゚・*:.。. .。.:*・゜゚・*!!!!

一応、ログファイルを見てみると何かたくさん書かれていました。
21014 17:44:28 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
121014 17:44:28 [Note] Plugin 'FEDERATED' is disabled.
121014 17:44:28 InnoDB: The InnoDB memory heap is disabled
121014 17:44:28 InnoDB: Mutexes and rw_locks use GCC atomic builtins
121014 17:44:28 InnoDB: Compressed tables use zlib 1.2.3
121014 17:44:28 InnoDB: Using Linux native AIO
121014 17:44:28 InnoDB: Initializing buffer pool, size = 2.0G
121014 17:44:28 InnoDB: Completed initialization of buffer pool
121014 17:44:28 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 123207224542
121014 17:44:28  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: Doing recovery: scanned up to log sequence number 123212467200
InnoDB: Doing recovery: scanned up to log sequence number 123217710080
InnoDB: Doing recovery: scanned up to log sequence number 123222952960
InnoDB: Doing recovery: scanned up to log sequence number 123228195840
InnoDB: Doing recovery: scanned up to log sequence number 123233438720
InnoDB: Doing recovery: scanned up to log sequence number 123238681600
InnoDB: Doing recovery: scanned up to log sequence number 123243924480
InnoDB: Doing recovery: scanned up to log sequence number 123249167360
InnoDB: Doing recovery: scanned up to log sequence number 123254410240
InnoDB: Doing recovery: scanned up to log sequence number 123259653120
InnoDB: Doing recovery: scanned up to log sequence number 123264896000
InnoDB: Doing recovery: scanned up to log sequence number 123270138880
InnoDB: Doing recovery: scanned up to log sequence number 123275381760
InnoDB: Doing recovery: scanned up to log sequence number 123280624640
InnoDB: Doing recovery: scanned up to log sequence number 123285867520
InnoDB: Doing recovery: scanned up to log sequence number 123291110400
InnoDB: Doing recovery: scanned up to log sequence number 123296353280
InnoDB: Doing recovery: scanned up to log sequence number 123301596160
InnoDB: Doing recovery: scanned up to log sequence number 123306839040
InnoDB: Doing recovery: scanned up to log sequence number 123312081920
InnoDB: Doing recovery: scanned up to log sequence number 123317324800
InnoDB: Doing recovery: scanned up to log sequence number 123322567680
InnoDB: Doing recovery: scanned up to log sequence number 123327810560
InnoDB: Doing recovery: scanned up to log sequence number 123333053440
InnoDB: Doing recovery: scanned up to log sequence number 123338296320
InnoDB: Doing recovery: scanned up to log sequence number 123343539200
InnoDB: Doing recovery: scanned up to log sequence number 123348782080
InnoDB: Doing recovery: scanned up to log sequence number 123354024960
InnoDB: Doing recovery: scanned up to log sequence number 123359267840
InnoDB: Doing recovery: scanned up to log sequence number 123364510720
InnoDB: Doing recovery: scanned up to log sequence number 123369753600
InnoDB: Doing recovery: scanned up to log sequence number 123374996480
InnoDB: Doing recovery: scanned up to log sequence number 123380239360
InnoDB: Doing recovery: scanned up to log sequence number 123385482240
InnoDB: Doing recovery: scanned up to log sequence number 123390725120
InnoDB: Doing recovery: scanned up to log sequence number 123395968000
InnoDB: Doing recovery: scanned up to log sequence number 123401210880
InnoDB: Doing recovery: scanned up to log sequence number 123406453760
InnoDB: Doing recovery: scanned up to log sequence number 123411696640
InnoDB: Doing recovery: scanned up to log sequence number 123416939520
InnoDB: Doing recovery: scanned up to log sequence number 123422182400
InnoDB: Doing recovery: scanned up to log sequence number 123427425280
InnoDB: Doing recovery: scanned up to log sequence number 123432668160
InnoDB: Doing recovery: scanned up to log sequence number 123437911040
InnoDB: Doing recovery: scanned up to log sequence number 123443153920
InnoDB: Doing recovery: scanned up to log sequence number 123448396800
InnoDB: Doing recovery: scanned up to log sequence number 123453639680
InnoDB: Doing recovery: scanned up to log sequence number 123458882560
InnoDB: Doing recovery: scanned up to log sequence number 123464125440
InnoDB: Doing recovery: scanned up to log sequence number 123469368320
InnoDB: Doing recovery: scanned up to log sequence number 123474611200
InnoDB: Doing recovery: scanned up to log sequence number 123479854080
InnoDB: Doing recovery: scanned up to log sequence number 123485096960
InnoDB: Doing recovery: scanned up to log sequence number 123490339840
InnoDB: Doing recovery: scanned up to log sequence number 123495582720
InnoDB: Doing recovery: scanned up to log sequence number 123500825600
InnoDB: Doing recovery: scanned up to log sequence number 123506068480
InnoDB: Doing recovery: scanned up to log sequence number 123511311360
InnoDB: Doing recovery: scanned up to log sequence number 123516554240
InnoDB: Doing recovery: scanned up to log sequence number 123521797120
InnoDB: Doing recovery: scanned up to log sequence number 123527040000
InnoDB: Doing recovery: scanned up to log sequence number 123532282880
InnoDB: Doing recovery: scanned up to log sequence number 123537525760
InnoDB: Doing recovery: scanned up to log sequence number 123542768640
InnoDB: Doing recovery: scanned up to log sequence number 123548011520
InnoDB: Doing recovery: scanned up to log sequence number 123553254400
InnoDB: Doing recovery: scanned up to log sequence number 123558497280
InnoDB: Doing recovery: scanned up to log sequence number 123563740160
InnoDB: Doing recovery: scanned up to log sequence number 123568983040
InnoDB: Doing recovery: scanned up to log sequence number 123574225920
InnoDB: Doing recovery: scanned up to log sequence number 123579468800
InnoDB: Doing recovery: scanned up to log sequence number 123584711680
InnoDB: Doing recovery: scanned up to log sequence number 123589954560
InnoDB: Doing recovery: scanned up to log sequence number 123595197440
InnoDB: Doing recovery: scanned up to log sequence number 123600440320
InnoDB: Doing recovery: scanned up to log sequence number 123605683200
InnoDB: Doing recovery: scanned up to log sequence number 123610926080
InnoDB: Doing recovery: scanned up to log sequence number 123616168960
InnoDB: Doing recovery: scanned up to log sequence number 123621411840
InnoDB: Doing recovery: scanned up to log sequence number 123626654720
InnoDB: Doing recovery: scanned up to log sequence number 123631897600
InnoDB: Doing recovery: scanned up to log sequence number 123637140480
InnoDB: Doing recovery: scanned up to log sequence number 123642383360
InnoDB: Doing recovery: scanned up to log sequence number 123647626240
InnoDB: Doing recovery: scanned up to log sequence number 123652869120
InnoDB: Doing recovery: scanned up to log sequence number 123658112000
InnoDB: Doing recovery: scanned up to log sequence number 123663354880
InnoDB: Doing recovery: scanned up to log sequence number 123668597760
InnoDB: Doing recovery: scanned up to log sequence number 123673840640
InnoDB: Doing recovery: scanned up to log sequence number 123679083520
InnoDB: Doing recovery: scanned up to log sequence number 123684326400
InnoDB: Doing recovery: scanned up to log sequence number 123689569280
InnoDB: Doing recovery: scanned up to log sequence number 123694812160
InnoDB: Doing recovery: scanned up to log sequence number 123700055040
InnoDB: Doing recovery: scanned up to log sequence number 123705297920
InnoDB: Doing recovery: scanned up to log sequence number 123710540800
InnoDB: Doing recovery: scanned up to log sequence number 123715783680
InnoDB: Doing recovery: scanned up to log sequence number 123721026560
InnoDB: Doing recovery: scanned up to log sequence number 123726269440
InnoDB: Doing recovery: scanned up to log sequence number 123731512320
InnoDB: Doing recovery: scanned up to log sequence number 123736755200
InnoDB: Doing recovery: scanned up to log sequence number 123738696720
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 9797229 row operations to undo
InnoDB: Trx id counter is 4C8700
121014 17:45:27  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 1131533333, file name ./mysql-bin.000118
InnoDB: Starting in background the rollback of uncommitted transactions
121014 17:46:25  InnoDB: Rolling back trx with id 4C84FE, 9797229 rows to undo

InnoDB: Progress in percents: 1121014 17:46:25  InnoDB: Waiting for the background threads to start
121014 17:46:26 InnoDB: 1.1.8 started; log sequence number 123738696720
121014 17:46:26 [Warning] 'user' entry 'root@db01' ignored in --skip-name-resolve mode.
121014 17:46:26 [Warning] 'user' entry '@db01' ignored in --skip-name-resolve mode.
121014 17:46:26 [Warning] 'proxies_priv' entry '@ root@db01' ignored in --skip-name-resolve mode.
121014 17:46:26 [Note] Event Scheduler: Loaded 0 events
121014 17:46:26 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.22-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL) by Remi
ただ、また停止を行ってプロセスを見てみると、
停止しているはずのプロセスが存在してる事に・・・Why!?
MySQLが壊れたか・・・(゜∀。)ワヒャヒャヒャヒャヒャヒャ
# /etc/init.d/mysqld stop
Timeout error occurred trying to stop MySQL Daemon.
Stopping mysqld:                                           [FAILED]
# ps aux|grep -i [m]ysql
root     16664  0.0  0.0 106108  1496 pts/2    S    17:44   0:00 /bin/sh /usr/bin/mysqld_safe --datadir=/var/lib/mysql --socket=/var/lib/mysql/mysql.sock --pid-file=/var/run/mysqld/mysqld.pid --basedir=/usr --user=mysql
mysql    17465 49.5 28.1 3540304 2307476 pts/2 Sl   17:44   3:23 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/data/mysql-log/mysql-error.log --open-files-limit=8192 --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock --port=3306
K1-admin 18643  0.0  0.0 100848   616 pts/0    S+   17:49   0:00 tail -f /data/mysql-log/mysql-error.log
ログを確認してみる。
 8 9 10121014 17:50:06 [Note] /usr/libexec/mysqld: Normal shutdown
121014 17:50:06 [Note] Event Scheduler: Purging the queue. 0 events
121014 17:50:06 [Note] unregister_replicator OK
121014 17:50:06  InnoDB: Starting shutdown...
 11 12 13 14 15
特に異常がなさそうなので、また手動でkillしてから起動する。
再度停止、起動を試してみる。
# /etc/init.d/mysqld start
問題なく動く。そして停止を試してみるが、 今までとは別の方法で
mysqladmin -u root -p shutdown
Enter password:
でやってみることに。その結果、view /data/mysql-log/mysql-error.logには、
21014 18:32:23 [Note] Event Scheduler: Purging the queue. 0 events
121014 18:32:24 [Note] unregister_replicator OK
121014 18:32:24  InnoDB: Starting shutdown...
 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100
InnoDB: Rolling back of trx id 4C84FE completed
121014 18:34:05  InnoDB: Rollback of non-prepared transactions completed
121014 18:34:11  InnoDB: Shutdown completed; log sequence number 126756814674
121014 18:34:11 [Note] /usr/libexec/mysqld: Shutdown complete

121014 18:34:11 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
という、感じになり、最後の行に今までなかった、
mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended
という行が追加されていました。( `_ゝ´)ムッ

良く分からないけど、endedだから終わりって事!なんだと思います(; ・`д・´)
また、プロセスを確認してみると(/ω・\)チラッ
# ps aux|grep -i [m]ysql
無事にプロセスが全部終わってます(゚∀゚)キタコレ!!

何でこっちの停止の時はうまくいくのかな?と思い、
再度/etc/init.d/mysqldの方をやってみたら、
こっちも同じようにログにかかれるようになって、正常に終了する事が出来ました・・・Σ(゚Д゚ υ) アリャ

結果として、良く分からなかったですけど、
とりあえず問題は解決できました(`・ω・´)ゞビシッ!!

■まとめる
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
のエラーが出た場合には、次の手順で解決できると思われます!

手順1.mysql.sockがあるか確認する。
手順2.MySQLのプロセスを確認してみて、残っている場合にはmysqladmin -u root -p shutdownなどでシャットダウンを試してみる。(シャットダウンが出来たら起動をしてみる)
手順3.手順2でプロセスを殺せない場合には、kill -9 プロセスIDで殺してしまう。ワイルドだぜぇ!

参考URL

0 件のコメント:

コメントを投稿