Mysql の起動時にERROR! The server quit without updating PID fileのエラーが出る。

Question

先日まで起動できていたmysqlですが急に上記のエラーが表示されて、起動もリスタートもできなくなってしまいました。

ネットで調べた所、いくつかの方法が出てきたので、試して見たのですが、どれも解決には至りませんでした。

mysqlコマンド実行後のエラー

sudo mysql.server start
Starting MySQL
. ERROR! The server quit without updating PID file (/usr/local/var/mysql/username.local.pid).

cat /usr/local/var/mysql/user_pc.local.err

InnoDB: Error number 35 means 'Resource temporarily unavailable'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
2016-11-28 14:40:28 59791 [ERROR] InnoDB: Can't open './ibdata1'
2016-11-28 14:40:28 59791 [ERROR] InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created in this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But be careful: do not remove old data files which contain your precious data!
2016-11-28 14:40:28 59791 [ERROR] Plugin 'InnoDB' init function returned error.
2016-11-28 14:40:28 59791 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2016-11-28 14:40:28 59791 [ERROR] Unknown/unsupported storage engine: InnoDB
2016-11-28 14:40:28 59791 [ERROR] Aborting

161128 14:40:29 mysqld_safe mysqld from pid file /usr/local/var/mysql/taniai-no-MBP.local.pid ended
161128 14:40:29 mysqld_safe Starting mysqld daemon with databases from /usr/local/var/mysql
2016-11-28 14:40:29 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2016-11-28 14:40:29 0 [Note] /usr/local/Cellar/mysql56/5.6.29/bin/mysqld (mysqld 5.6.29) starting as process 60025 ...
2016-11-28 14:40:29 60025 [Warning] Setting lower_case_table_names=2 because file system for /usr/local/var/mysql/ is case insensitive
2016-11-28 14:40:29 60025 [Note] Plugin 'FEDERATED' is disabled.
2016-11-28 14:40:29 60025 [Note] InnoDB: Using atomics to ref count buffer pool pages
2016-11-28 14:40:29 60025 [Note] InnoDB: The InnoDB memory heap is disabled
2016-11-28 14:40:29 60025 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-11-28 14:40:29 60025 [Note] InnoDB: Memory barrier is not used
2016-11-28 14:40:29 60025 [Note] InnoDB: Compressed tables use zlib 1.2.3
2016-11-28 14:40:29 60025 [Note] InnoDB: Using CPU crc32 instructions
2016-11-28 14:40:29 60025 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2016-11-28 14:40:29 60025 [Note] InnoDB: Completed initialization of buffer pool
2016-11-28 14:40:29 60025 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2016-11-28 14:40:29 60025 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
2016-11-28 14:40:29 60025 [Note] InnoDB: Retrying to lock the first data file
2016-11-28 14:40:30 60025 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2016-11-28 14:40:30 60025 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
2016-11-28 14:40:31 60025 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2016-11-28 14:40:31 60025 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
2016-11-28 14:40:32 60025 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2016-11-28 14:40:32 60025 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
2016-11-28 14:40:33 60025 [ERROR] InnoDB: Unable to lock ./ibdata1, error: 35
2016-11-28 14:40:33 60025 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.

以下省略

2016-11-28 14:42:15 60025 [Note] InnoDB: Check that you do not already have another mysqld process using the same InnoDB data or log files.
2016-11-28 14:42:15 60025 [Note] InnoDB: Unable to open the first data file
2016-11-28 14:42:15 7fff98bfd3c0  InnoDB: Operating system error number 35 in a file operation.

方法1

権限を全てmysqlに変更する

sudo chown -R _mysql:_mysql /usr/local/var/mysql

/mysql以下のファイルを全て_mysqlに変更しました。
以前はこれで直っていた気がするのですが、今回は治りませんでした。

方法2

権限を全てuser_nameに変更する

/mysql以下のファイルを全てのユーザーをuser_nameに変更しました。
これもまた解決せず…

方法3

sudo mysql.server start
Starting MySQL
. ERROR! The server quit without updating PID file (/usr/local/var/mysql/username.local.pid).

このエラー通り、mysql以下にusername.local.pidが無いので、作りました。（username.pidはあります。）

ｔouch /usr/local/var/mysql/username.local.pid

また、

-rw-r-----    1  [user_name] _mysql   1128581 11 28 14:41 [pc_name].local.err

だったので、

-rw-r-----    1 [user_name] admin    1128581 11 28 14:41 [pc_name].local.err

に変更しました。

その後
sudo mysql.server start

した所、同じくエラーで、更に作ったはずのusername.local.pidが消えていました。

これ以外に何かご存じでしたら、どなたかご教示ください。
よろしくお願いいたします。

Comments

[KiyoshiMotoki]

「先日まで起動できていた」とのことですので、思い出せる範囲で、最後に行なった操作または設定変更などを追記すると、回答が付きやすくなるかも知れません。

[KeisukeTaniai]

昨日brew update を行った際に、権限の変更を行ったと思います。（それがmysql関連のものだったかが不確かですが）それ以外ですと、別のディレクトリにvagrantで環境を構築しましたが、関係はなさそうです。

Answer 1

可能性の一つとして、Check that you do not already have another mysqld process using the same InnoDB data or log files.と書かれているので、すでにmysqldが起動しているということはないでしょうか

同じような事例もありましたので、参考にしてください。

Comments

[KeisukeTaniai]

一応セッションをkillはしましたが、変化はありませんでした...

[popobot]

セッション？　プロセスのことですかね。
少なくともプロセスはいたということでしょうか？

すべてのmysqldのプロセスをkillした状態で再度起動コマンドを実行した場合、どのようなログが出力されるか質問文に別途掲載していただけますでしょうか。現在質問文にあるログは最初が切れている気がしますし、プロセスが重複していることによるメッセージも多数出ているため、根本原因となるエラーがどれだかよくわかりません

[KeisukeTaniai]

再度プロセスをkillし、再起動させた際にmysql.server startが起動するようになりました。私の勘違いもあったかと思いますが、ご丁寧にありがとうございました。