MySQL: troubleshooting an Instance for beginners

Posted in: MySQL, Technical Track

IMG_1299

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.

[user-lab@ip-10-10-10-1 ~]$ 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
[user-lab@ip-10-10-10-1 ~]$ id mysql
id: mysql: no such user
[user-lab@ip-10-10-10-1 ~]$ 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.

[user-lab@ip-10-10-10-1 ~]$ 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.
[root@ip-10-10-10-1 ~]# 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.

[root@ip-10-10-10-1 ~]# 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.

[root@ip-10-10-10-1 ~]# cat /usr/etc/my.cnf
[mysqld]
tmpd1r=/var/tmp
[root@ip-10-10-10-1 ~]# sed -i -e 's/tmpd1r/tmpdir/' /usr/etc/my.cnf
[root@ip-10-10-10-1 ~]# 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.

[root@ip-10-10-10-1 ~]# service mysqld start
MySQL Daemon failed to start.
Starting mysqld:                                           [FAILED]
[root@ip-10-10-10-1 ~]# 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
[root@ip-10-10-10-1 ~]# perror 13
Error code 13: Permission denied
[root@ip-10-10-10-1 ~]# 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
[root@ip-10-10-10-1 ~]# 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.

[root@ip-10-10-10-1 ~]# 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
[root@ip-10-10-10-1 ~]# grep 100 /etc/my.cnf
innodb_buffer_pool_size=100G
[root@ip-10-10-10-1 ~]# sed -i -e 's/100G/256M/' /etc/my.cnf
[root@ip-10-10-10-1 ~]# 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.

[root@ip-10-10-10-1 ~]# service mysqld start
MySQL Daemon failed to start.
Starting mysqld:                                           [FAILED]
root@ip-10-10-10-1 ~]# 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
[root@ip-10-10-10-1 ~]# ls -l /var/lib/mysql/ibdata1
-rw-rw---- 1 27 27 18874368 Mar 13  2014 /var/lib/mysql/ibdata1
[root@ip-10-10-10-1 ~]# 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
[root@ip-10-10-10-1 ~]# 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!

[root@ip-10-10-10-1 ~]# 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

[root@ip-10-10-10-1 ~]# mysql
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)
[root@ip-10-10-10-1 ~]# service mysql status
mysql: unrecognized service
[root@ip-10-10-10-1 ~]# service mysqld status
mysqld (pid  5666) is running...
[root@ip-10-10-10-1 ~]# ls -l /tmp/mysql.sock
ls: cannot access /tmp/mysql.sock: No such file or directory
[root@ip-10-10-10-1 ~]# 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)
[root@ip-10-10-10-1 ~]# lsof -n | grep mysqld | grep unix
mysqld    5666    mysql   12u     unix 0xffff880066fbea40       0t0     981919 /var/lib/mysql/mysql.sock
[root@ip-10-10-10-1 ~]# 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
[root@ip-10-10-10-1 ~]# vi /etc/my.cnf
[root@ip-10-10-10-1 ~]# service mysqld restart
Stopping mysqld:                                           [  OK  ]
Starting mysqld:                                           [  OK  ]
[root@ip-10-10-10-1 ~]# 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.

email

Author

Interested in working with Rene? Schedule a tech call.

About the Author

Currently I am an Oracle ACE ; Speaker at Oracle Open World, Oracle Developers Day, OTN Tour Latin America and APAC region and IOUG Collaborate ; Co-President of ORAMEX (Mexico Oracle User Group); At the moment I am an Oracle Project Engineer at Pythian. In my free time I like to say that I'm Movie Fanatic, Music Lover and bringing the best from México (Mexihtli) to the rest of the world and in the process photographing it ;)

No comments

Leave a Reply

Your email address will not be published. Required fields are marked *