【Mysql、PHP】mysql.sockが消えてしまう

Question

お世話になります。
CakePHP+Mysqlで開発をしています。

ある時ページを読み込んでいると、

Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)

というエラーが表示されてしまいました。
調べると、mysql.sockがあるべき場所にない場合に起こるエラーということだったので、

touch /var/lib/mysql/mysql.sock

のあとmysqlを再起動することでまた動くようになったのですが、その後もいくつかのページを読み込むとmysql.sockが消えてしまうという状況が頻発するようになりました。

直近の変更がなにか影響しているのではないかと思い、元に戻したりしているのですが状況は改善しません。

また同じページでも問題なく読み込める時とそうでない時があり、ちょっと原因がわからず行き詰まってしまっています。。。

どんな時にmysql.sockが消えてしまうのか、どうすればこれは解決するのか、お心当たりのある方がいらっしゃればお力を貸していただきたいです。

よろしくお願いします。

Answer 1

DB接続のあるページでの症状だとすると、正しいソケット接続指定しているコードと、そうでないコードが混在しているために発生していると思われます。DBへの接続方法を揃えるように修正することで解決できると思います。DB接続設定ファイルConfig/database.phpも確認してみてください。

下記のソケットファイルの場所確認も行って、MySQLの設定（/etc/my.cnf or /var/lib/mysql/my.cnf）、php.iniの設定、CakePHPのDB設定もすべて揃えるように修正を行います。

また、MySQLへの接続方法には、ソケットで接続を行う方法の他に、TCP 3306番ポートを使って接続する方法もあります。

サーバー環境に左右されにくいので変更が面倒でなければ、TCP接続が良いと思います。（個人的に馴染んでいるだけが理由かもしれませんが）記憶が定かではありませんが、コンパイルインストールするとソケットファイルは/var/lib/mysql/mysql.sockがデフォルトだった気がします。

ちなみに、ソケットは普通のファイルではないので、touch /var/lib/mysql/mysql.sockのように作成してはいけません。普通のファイルはレギュラーファイルと呼ばれ、ソケットはソケットファイルと呼ばれます。

SSHなどのターミナルで下記のようなコマンドを実行すると、ファイル名の後に=と表示されるファイルはソケットファイルです。

ls -lF /tmp/ /var/run

ソケットファイルの場所確認

普通、MySQLをパッケージからインストールした場合は、ソケットファイルは/tmp/mysql.sockにあります。ソケットファイルを確認するにはMySQLにログインして、下記SQLコマンドを実行してみてください。

SHOW VARIABLES LIKE 'sock%';

下記は、私の環境での実行結果です。

+---------------+-----------------+
| Variable_name | Value           |
+---------------+-----------------+
| socket        | /tmp/mysql.sock |
+---------------+-----------------+
1 row in set (0.00 sec)

ターミナルで下記コマンドを実行して実際のファイルパスを確認してみます。

ls -lF /tmp/mysql.sock

#---- ↓実行結果↓ ----
srwxrwxrwx 1 mysql mysql 0 Dec 19 17:03 /tmp/mysql.sock=

Comments

[katsuo77]

Tomak様

さっそく丁寧なご回答をいただきありがとうございます。
まず、ソケットファイルの場所を確認すると、私の環境では
/var/lib/mysql/mysql.sock
にありました。

その上で教えていただいたファイルを確認し、以下の変更をしました。

・/etc/my.cnf
クライアント側のソケット指定がなかったので、以下を追記。

[client]
socket=/var/lib/mysql/mysql.sock

・/etc/php.ini
mysql.default_socketが指定されていなかったので、以下のように変更。

mysql.default_socket = /var/lib/mysql/mysql.sock

ここまでした上でhttpdおよびmysqlの再起動をしましたが、まだ改善は見られませんでした。
ちなみに同じサーバー上にCakeを使っていない別のサイトも載っており、Cakeの方は触らず別サイトの読み込みを行っただけでソケットファイルが消えていたので、Cake側以外に問題があるのかもしれません。

またソケットファイルが消える際コマンドラインに以下のログが出力されていることに気が付いたのですが、何か関係があるのでしょうか？

/usr/bin/mysqld_safe: line 181: 492 Killed nohup /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib64/mysql/plugin --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock < /dev/null > /dev/null 2>&1

お聞きしてばかりで恐縮ですが、これでもしまた何かわかりましたらご教授いただけますと幸いです。

[Tomak]

このエラーログからすると、単純にPHPソースが悪いわけではなく、MySQLがクラッシュしているために起きている現象のようです。MySQLがクラッシュすると当然ソケットファイルもなくなります。下記のMySQLエラーログをみてクラッシュする原因を見つけてみてください。
----
エラーログ：/var/log/mysqld.log

下記も参考になるかもしれません。
----
https://teratail.com/questions/60699

[Tomak]

上記コメントの追加です。MySQLクラッシュの原因はログファイルを見てみないとわかりませんが、下記も確認してみると良いかもしれません。

私の環境の「/usr/bin/mysqld_safe」と同じでないようなので何とも言えませんが、MySQLエラーログパスのオーナー権限は大丈夫でしょうか？　普通はオーナー、グループともに「mysql」です。
----
オーナー権限：mysql:mysql /var/log/mysqld.log

また、ファイルサイズも確認したほうが良いかもしれません。ログローテートされていないと、ログファイルが肥大化してOSで扱える最大サイズになり、書き込みできないことがあります。

私の環境だと「mysqld_safe」の181行目は、shスクリプトの「eval_log_error()」という関数です。なんらかのエラーが出たけれと、エラーを吐き出せないためにMySQLがクラッシュしているとも考えられます。

[katsuo77]

Tomak様

返信が遅れて申し訳ありません。
詳しいコメントありがとうございます。

結論からいうと、まだ問題の解決には至っておりません。
以下のようなことを確認、変更しました。

・エラーログ/var/log/mysqld.logの確認
mysqlの立ち上げからクラッシュまで、以下のようなログが出力されていました。

2017-12-21 18:07:03 9067 [Note] Plugin 'FEDERATED' is disabled.
2017-12-21 18:07:03 9067 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-12-21 18:07:03 9067 [Note] InnoDB: The InnoDB memory heap is disabled
2017-12-21 18:07:03 9067 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-12-21 18:07:03 9067 [Note] InnoDB: Memory barrier is not used
2017-12-21 18:07:03 9067 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-12-21 18:07:03 9067 [Note] InnoDB: Using Linux native AIO
2017-12-21 18:07:03 9067 [Note] InnoDB: Using CPU crc32 instructions
2017-12-21 18:07:03 9067 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2017-12-21 18:07:03 9067 [Note] InnoDB: Completed initialization of buffer pool
2017-12-21 18:07:03 9067 [Note] InnoDB: Highest supported file format is Barracuda.
2017-12-21 18:07:03 9067 [Note] InnoDB: The log sequence numbers 2231251817 and 2231251817 in ibdata files do not match the log sequence number 2231766984 in the ib_logfiles!
2017-12-21 18:07:03 9067 [Note] InnoDB: Database was not shutdown normally!
2017-12-21 18:07:03 9067 [Note] InnoDB: Starting crash recovery.
2017-12-21 18:07:03 9067 [Note] InnoDB: Reading tablespace information from the .ibd files...
2017-12-21 18:07:03 9067 [Note] InnoDB: Restoring possible half-written data pages
2017-12-21 18:07:03 9067 [Note] InnoDB: from the doublewrite buffer...
2017-12-21 18:07:04 9067 [Note] InnoDB: 128 rollback segment(s) are active.
2017-12-21 18:07:04 9067 [Note] InnoDB: Waiting for purge to start
2017-12-21 18:07:04 9067 [Note] InnoDB: 5.6.36 started; log sequence number 2231766984
2017-12-21 18:07:04 9067 [Note] Server hostname (bind-address): '*'; port: 3306
2017-12-21 18:07:04 9067 [Note] IPv6 is available.
2017-12-21 18:07:04 9067 [Note] - '::' resolves to '::';
2017-12-21 18:07:04 9067 [Note] Server socket created on IP: '::'.
2017-12-21 18:07:04 9067 [Note] Event Scheduler: Loaded 0 events
2017-12-21 18:07:04 9067 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.36' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL)

気になるログは検索にかけてみましたが、特に問題になるようなものはこちらでは見つかりませんでした。

・/var/log/mysqld.logのオーナー権限
こちらはmysql:mysqlに設定されています。

・ログファイルのファイルサイズ
一度/var/log/mysqld.logのバックアップを取った上で、新しくmysqld.logを作成してmysqlの再起動を行いましたが、同じようにクラッシュしました。

・メモリの確認
free -hの結果は以下のようになりました。

total used free shared buffers cached
Mem: 490M 307M 183M 60K 12M 33M
-/+ buffers/cache: 260M 229M
Swap: 2.0G 446M 1.6G

メモリの使用状況は60%程度で、スワップ領域も残っているので、ここもそれほど問題はないかと思っています。

何かmysqlの設定がおかしくなっているのかな、とは思うのですが、もう少しやってみてダメなら最悪バックアップを取った上でのmysqlの入れ直しも検討しています。

[Tomak]

ログは多分「クラッシュ後～立ち上げ」のログだと思います。注目しなければならないのは「クラッシュ前」のログです。多分「[Note] InnoDB ...」じゃなくて「[error] InnoDB ...」のようなログが残っているかと思います。

> 2017-12-21 18:07:03 9067 [Note] InnoDB: The log sequence numbers 2231251817 and 2231251817 in ibdata files do not match the log sequence number 2231766984 in the ib_logfiles!

これは、ざっくり言うとMySQLがクラッシュしたことにより、LSN（Log Sequence Number）が違うというメッセージですが、下記のように正常にリカバリーできているようなのでMySQLの設定ファイルが問題かもしれません。

> 2017-12-21 18:07:03 9067 [Note] InnoDB: Restoring possible half-written data pages
> 2017-12-21 18:07:03 9067 [Note] InnoDB: from the doublewrite buffer...
> 2017-12-21 18:07:04 9067 [Note] InnoDB: 128 rollback segment(s) are active.
> 2017-12-21 18:07:04 9067 [Note] InnoDB: Waiting for purge to start
> 2017-12-21 18:07:04 9067 [Note] InnoDB: 5.6.36 started; log sequence number 2231766984

[katsuo77]

Tomak様

コメントありがとうございます。
こちらの問題解決いたしました。

ログにはなぜかエラーが吐き出されておらず、クラッシュ前後を見ても上に貼ったようなログが繰り返し出力されているだけでした。

しかしdf -hTしてみると、
Filesystem Type Size Used Avail Use% Mounted on
/dev/vda3 ext4 18G 17G 16M 100% /
tmpfs tmpfs 246M 0 246M 0% /dev/shm
/dev/vda1 ext4 239M 129M 97M 58% /boot

とディスクの使用率が100％になっていたので、不要ファイルを削除して空きを作ったところ、mysqlは正常に動くようになりました。

おかげさまで問題を解決でき、また解決の手法についても勉強することができました。
本当にありがとうございました。

[Tomak]

解決できたようでよかったです。思わぬ落とし穴といったところですね。