So as you may know, my new position involves the MySQL world, so I’m in the task of picking up the language and whereabouts of this DBMS, and my teamate Alkin Tezuysal (@ask_dba on Twitter) has a very cool break and fix lab which you should check out if you are going to Percona Live London 2014, he will be running this lab, so be sure to don’t miss out.
So the first thing I tried was to bring up the service, but to my surprise, the MySQL user didn’t exist. So the first thing I did was create the user.
Note: Whenever you see “…”, it is to shorten the output.
[[email protected] ~]$ service mysqld start touch: cannot touch ‘/var/log/mysqld.log’: Permission denied chown: invalid user: ‘mysql:mysql’ chmod: changing permissions of ‘/var/log/mysqld.log’: Operation not permitted mkdir: cannot create directory ‘/var/lib/msql’: Permission denied [[email protected] ~]$ id mysql id: mysql: no such user [[email protected] ~]$ sudo useradd mysql
So now that the user exists, I try to bring it up and we are back at square one as the initial configuration variable in the .cnf file is incorrect. But there is another problem, as there is more than one .cnf file.
[[email protected] ~]$ sudo su - Last login: Thu Jul 31 11:37:21 UTC 2014 on pts/0 Last failed login: Tue Oct 14 05:45:47 UTC 2014 from 60.172.228.40 on ssh:notty There were 1269 failed login attempts since the last successful login. [[email protected] ~]# service mysqld start Initializing MySQL database: Installing MySQL system tables... 141014 17:05:46 [ERROR] /usr/libexec/mysqld: unknown variable 'tmpd1r=/var/tmp' 141014 17:05:46 [ERROR] Aborting 141014 17:05:46 [Note] /usr/libexec/mysqld: Shutdown complete Installation of system tables failed! Examine the logs in /var/lib/msql for more information. ... [FAILED]
In the Oracle world, it is easier to troubleshoot. Here in the MySQL world, the best way to see which .cnf file is being used, we do it with an strace command.
[[email protected] ~]# strace -e trace=open,stat /usr/libexec/mysqld open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 open("/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3 open("/lib64/libaio.so.1", O_RDONLY|O_CLOEXEC) = 3 ... stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=255, ...}) = 0 open("/etc/my.cnf", O_RDONLY) = 3 stat("/etc/mysql/my.cnf", 0x7fffe4b38120) = -1 ENOENT (No such file or directory) stat("/usr/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=25, ...}) = 0 open("/usr/etc/my.cnf", O_RDONLY) = 3 stat("/root/.my.cnf", {st_mode=S_IFREG|0644, st_size=33, ...}) = 0 open("/root/.my.cnf", O_RDONLY) = 3 ... 141014 17:12:05 [ERROR] Fatal error: Please read "Security" section of the manual to find out how to run mysqld as root!
So now I can see that the /usr/etc/my.cnf is the one with the incorrect wording variable, so we modify it to have it the correct one.
[[email protected] ~]# cat /usr/etc/my.cnf [mysqld] tmpd1r=/var/tmp [[email protected] ~]# sed -i -e 's/tmpd1r/tmpdir/' /usr/etc/my.cnf [[email protected] ~]# cat /usr/etc/my.cnf [mysqld] tmpdir=/var/tmp
Another try, but again the same result — but even worse this time, as there is no output. After digging around, I found that the place to look is the /var/log/mysqld.log and the problem was that some libraries belonged to root user, instead of the MySQL user.
[[email protected] ~]# service mysqld start MySQL Daemon failed to start. Starting mysqld: [FAILED] [[email protected] ~]# cat /var/log/mysqld.log 141014 17:16:33 mysqld_safe Starting mysqld daemon with databases from /var/lib/msql 141014 17:16:33 [Note] Plugin 'FEDERATED' is disabled. /usr/libexec/mysqld: Table 'mysql.plugin' doesn't exist 141014 17:16:33 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it. 141014 17:16:33 InnoDB: The InnoDB memory heap is disabled 141014 17:16:33 InnoDB: Mutexes and rw_locks use GCC atomic builtins 141014 17:16:33 InnoDB: Compressed tables use zlib 1.2.7 141014 17:16:33 InnoDB: Using Linux native AIO /usr/libexec/mysqld: Can't create/write to file '/var/tmp/ib1rikjr' (Errcode: 13) 141014 17:16:33 InnoDB: Error: unable to create temporary file; errno: 13 141014 17:16:33 [ERROR] Plugin 'InnoDB' init function returned error. 141014 17:16:33 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 141014 17:16:33 [ERROR] Unknown/unsupported storage engine: InnoDB 141014 17:16:33 [ERROR] Aborting 141014 17:16:33 [Note] /usr/libexec/mysqld: Shutdown complete [[email protected] ~]# perror 13 Error code 13: Permission denied [[email protected] ~]# ls -l /var/lib/mysql/mysql/plugin.* -rw-rw---- 1 root root 8586 Mar 13 2014 /var/lib/mysql/mysql/plugin.frm -rw-rw---- 1 root root 0 Mar 13 2014 /var/lib/mysql/mysql/plugin.MYD -rw-rw---- 1 root root 1024 Mar 13 2014 /var/lib/mysql/mysql/plugin.MYI [[email protected] ~]# chown -R mysql:mysql /var/lib/mysql/mysql/
So I think, yey, I’m set and it will come up! I give it one more shot and, you guessed it, same result and different error :( This time around the problem seemed to be that the memory assigned is incorrect and we don’t have enough on the machine, so we change it.
[[email protected] ~]# service mysqld start MySQL Daemon failed to start. Starting mysqld: [FAILED] 141014 17:36:15 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql 141014 17:36:15 [Note] Plugin 'FEDERATED' is disabled. 141014 17:36:15 InnoDB: The InnoDB memory heap is disabled 141014 17:36:15 InnoDB: Mutexes and rw_locks use GCC atomic builtins 141014 17:36:15 InnoDB: Compressed tables use zlib 1.2.7 141014 17:36:15 InnoDB: Using Linux native AIO 141014 17:36:15 InnoDB: Initializing buffer pool, size = 100.0G InnoDB: mmap(109890764800 bytes) failed; errno 12 141014 17:36:15 InnoDB: Completed initialization of buffer pool 141014 17:36:15 InnoDB: Fatal error: cannot allocate memory for the buffer pool 141014 17:36:15 [ERROR] Plugin 'InnoDB' init function returned error. 141014 17:36:15 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 141014 17:36:15 [ERROR] Unknown/unsupported storage engine: InnoDB 141014 17:36:15 [ERROR] Aborting [[email protected] ~]# grep 100 /etc/my.cnf innodb_buffer_pool_size=100G [[email protected] ~]# sed -i -e 's/100G/256M/' /etc/my.cnf [[email protected] ~]# grep innodb_buffer_pool_size /etc/my.cnf innodb_buffer_pool_size=256M
Now, I’m not even expecting this instance to come up, and I am correct — It seems a filename has incorrect permissions.
[[email protected] ~]# service mysqld start MySQL Daemon failed to start. Starting mysqld: [FAILED] [email protected] ~]# cat /var/log/mysqld.log ... 141014 17:37:15 InnoDB: Initializing buffer pool, size = 256.0M 141014 17:37:15 InnoDB: Completed initialization of buffer pool 141014 17:37:15 InnoDB: Operating system error number 13 in a file operation. InnoDB: The error means mysqld does not have the access rights to InnoDB: the directory. InnoDB: File name ./ibdata1 InnoDB: File operation call: 'open'. InnoDB: Cannot continue operation. 141014 17:37:15 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended [[email protected] ~]# ls -l /var/lib/mysql/ibdata1 -rw-rw---- 1 27 27 18874368 Mar 13 2014 /var/lib/mysql/ibdata1 [[email protected] ~]# ls -l /var/lib/mysql total 83980 -rw-rw---- 1 27 27 18874368 Mar 13 2014 ibdata1 -rw-rw---- 1 27 27 33554432 Mar 13 2014 ib_logfile0 -rw-rw---- 1 27 27 33554432 Mar 13 2014 ib_logfile1 drwx------ 2 mysql mysql 4096 Mar 13 2014 mysql drwx------ 2 root root 4096 Mar 13 2014 performance_schema drwx------ 2 root root 4096 Mar 13 2014 test [[email protected] ~]# chown -R mysql:mysql /var/lib/mysql
Now, I wasn’t even expecting the service to come up, but to my surprise it came up!
[[email protected] ~]# service mysqld start Starting mysqld: [ OK ]
So now, what I wanted to do was connect and start working, but again, there was another error! I saw that it was related to the socket file mysql.sock, so I changed it to the correct value in our .cnf file
[[email protected] ~]# mysql ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2) [[email protected] ~]# service mysql status mysql: unrecognized service [[email protected] ~]# service mysqld status mysqld (pid 5666) is running... [[email protected] ~]# ls -l /tmp/mysql.sock ls: cannot access /tmp/mysql.sock: No such file or directory [[email protected] ~]# grep socket /var/log/mysqld.log | tail -n 1 Version: '5.5.36' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL) [[email protected] ~]# lsof -n | grep mysqld | grep unix mysqld 5666 mysql 12u unix 0xffff880066fbea40 0t0 981919 /var/lib/mysql/mysql.sock [[email protected] ~]# cat /etc/my.cnf [mysqld] datadir=/var/lib/mysql innodb_data_file_path=ibdata1:18M innodb_buffer_pool_size=256M innodb_log_file_size=32M sort_buffer_size=60M [client] socket=/tmp/mysql.sock [[email protected] ~]# vi /etc/my.cnf [[email protected] ~]# service mysqld restart Stopping mysqld: [ OK ] Starting mysqld: [ OK ] [[email protected] ~]# mysql -p Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 3 Server version: 5.5.36 MySQL Community Server (GPL) Copyright (c) 2000, 2014, 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>
Conclusion
As you can see, there are different ways to troubleshoot the startup of a MySQL instance, so hope this helps you out in your journey when you are starting to use this DBMS and also if you know of another way, let me know in the comment section below.
Please note that this blog post was originally published on my personal blog.
No comments