MySQL not starting after reboot

[Jimmster]

Hello everybody,

I've noticed strange behavior when rebooting our VPS that are running Plesk 12.5.30 and Ubuntu 14.04.4. Whenever they're rebooting, MySQL's error_log shows a crash. When issueing /etc/init.d/mysql restart directly afterwards, MySQL starts absolutely fine. This affects three different servers, all running the same versions of Plesk and Ubuntu.

I'm posting on this forum because a server setup the very same way but not running Plesk, doesn't show this behavior. I also noticed MySQL isn't being started from /etc/rc*.d but from somewhere else. I'm figuring maybe the way (timing?) the other servers (with Plesk) are trying to start MySQL has something to do with it.

Here's the relevant part of /var/log/mysql/error_log:

[Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
[Warning] option 'innodb-buffer-pool-size': signed value 2097152 adjusted to 5242880
[Warning] option 'innodb-additional-mem-pool-size': signed value 512000 adjusted to 524288
[Note] Plugin 'FEDERATED' is disabled.
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Compressed tables use zlib 1.2.8
InnoDB: Using Linux native AIO
InnoDB: Initializing buffer pool, size = 5.0M
InnoDB: Completed initialization of buffer pool
InnoDB: highest supported file format is Barracuda.
InnoDB: Waiting for the background threads to start
InnoDB: 5.5.47 started; log sequence number 62921204727
[Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
[Note]   - '0.0.0.0' resolves to '0.0.0.0';
[Note] Server socket created on IP: '0.0.0.0'.

Status information:

Current dir: /var/lib/mysql/
Running threads: 0  Stack size: 196608
Current locks:
lock: 0x7f135b0add00:

lock: 0x7f135b0ae240:

lock: 0x7f135b0ae300:

lock: 0x7f135b0ae3c0:

lock: 0x7f135b0addc0:

lock: 0x7f135b0ade80:

lock: 0x7f135b0adc40:

lock: 0x7f135b0adac0:

lock: 0x7f135b0adb80:

lock: 0x7f135b0ae480:

lock: 0x7f135b0adf40:

lock: 0x7f135b0ae180:

lock: 0x7f135b0ae0c0:

lock: 0x7f135b0ae000:

lock: 0x7f135b0ad880:

lock: 0x7f135b0ad940:

lock: 0x7f135b0ada00:


Key caches:
default
Buffer_size:      16777216
Block_size:           1024
Division_limit:        100
Age_limit:             300
blocks used:             0
not flushed:             0
w_requests:              0
writes:                  0
r_requests:              0
reads:                   0


handler status:
read_key:            0
read_next:           0
read_rnd             0
read_first:          0
write:               0
delete               0
update:              0

Table status:
Opened tables:          1
Open tables:            0
Open files:             1
Open streams:           0

Alarm status:
Active alarms:   0
Max used alarms: 0
Next alarm time: 0
21:59:26 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

key_buffer_size=16777216
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 346701 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x20)[0x7f135a8426b0]
/usr/sbin/mysqld(handle_fatal_signal+0x3d5)[0x7f135a72c1c5]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f13594bb340]
/usr/sbin/mysqld(_ZN15Event_scheduler20dump_internal_statusEv+0x1f)[0x7f135a82340f]
/usr/sbin/mysqld(_ZN6Events20dump_internal_statusEv+0xaa)[0x7f135a6ce2ba]
/usr/sbin/mysqld(_Z18mysql_print_statusv+0x4b0)[0x7f135a6a9cc0]
/usr/sbin/mysqld(signal_hand+0x2b5)[0x7f135a5d9845]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f13594b3182]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f1358bd647d]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.

And here's the log of the sucessful startup after issueing /etc/init.d/mysql restart directly after the automatic startup try:

mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
[Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
[Note] /usr/sbin/mysqld (mysqld 5.5.47-0ubuntu0.14.04.1) starting as process 3563 ...
[Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
[Warning] option 'innodb-buffer-pool-size': signed value 2097152 adjusted to 5242880
[Warning] option 'innodb-additional-mem-pool-size': signed value 512000 adjusted to 524288
[Note] Plugin 'FEDERATED' is disabled.
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Compressed tables use zlib 1.2.8
InnoDB: Using Linux native AIO
InnoDB: Initializing buffer pool, size = 5.0M
InnoDB: Completed initialization of buffer pool
InnoDB: highest supported file format is Barracuda.
InnoDB: Waiting for the background threads to start
InnoDB: 5.5.47 started; log sequence number 62921204727
[Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
[Note]   - '0.0.0.0' resolves to '0.0.0.0';
[Note] Server socket created on IP: '0.0.0.0'.
[Note] Event Scheduler: Loaded 0 events
[Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.47-0ubuntu0.14.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)

Any help is greatly appreciated!

 

[Jimmster]

No one got any suggestions?

 

[Jimmster]

One more try to push this upwards...

 

[Amin Taheri]

These two lines make it seem like it started OK

[Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.47-0ubuntu0.14.04.1' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (Ubuntu)


I have the same entries when I restart mysql


160229 15:18:36 [Note] Plugin 'FEDERATED' is disabled.
160229 15:18:36 InnoDB: The InnoDB memory heap is disabled
160229 15:18:36 InnoDB: Mutexes and rw_locks use GCC atomic builtins
160229 15:18:36 InnoDB: Compressed tables use zlib 1.2.3
160229 15:18:36 InnoDB: Using Linux native AIO
160229 15:18:36 InnoDB: Initializing buffer pool, size = 128.0M
160229 15:18:36 InnoDB: Completed initialization of buffer pool
160229 15:18:36 InnoDB: highest supported file format is Barracuda.
160229 15:18:37 InnoDB: Waiting for the background threads to start
160229 15:18:38 InnoDB: 5.5.47 started; log sequence number 701359075
160229 15:18:38 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
160229 15:18:38 [Note] - '0.0.0.0' resolves to '0.0.0.0';
160229 15:18:38 [Note] Server socket created on IP: '0.0.0.0'.
160229 15:18:38 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.47-cll-lve' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL) by Atomicorp

 

[Jimmster]

These lines are from the lower log, which is after successfully starting MySQL manually. Only the upper one shows the crash.

 

[Amin Taheri]

This looks like your issue reported here - there is a potential fix listed in the mysql bug link
http://stackoverflow.com/questions/23272721/mysqld-crashed-utc-mysqld-got-signal-11

 

[Jimmster]

Thank you very much for your reply.

I see a few differences to the problem described in the post and bug-link:
* We can start MySQL normally. It just doesn't work on system startup. Even a simple 'sleep 30 && /etc/init.d/mysql restart' in /etc/rc.local does the trick (which is dirty, of course)
* We didn't do any importing of old dumps of system tables like the guy in the Bug-link did.

It's also notable that this happens on every of our Ubuntu + Plesk server we're running. Even the ones that only use MySQL for Plesk (small internal DNS server, for example - no hosted sites or anything).

 

[Amin Taheri]

hmm thats interesting, that makes me think that there may be a dependancy issue or a load order issue.

One way you can do this (which is not the way I would do this) would be you could edit the mysql start up file in init.d to contain

/bin/bash sleep 300

You could also rename the file from mysql to S99mysql so that it would be executed last upon boot.

 

[Jimmster]

Yes, I was also thinking about dependency / order problems. Could you explain to me how exactly MySQL is started? I can't find anything in /etc/rc*.d and it still (tries to) start. I also tried 'update-rc.d defaults mysql' at some point, but that didn't change anything.
Is there some kind of PSA script that tries to start everything that's needed for Plesk to work?

 

[trialotto]

@Jimmster and @Amin Taheri

Interesting discussion, even though it gets focused on work-arounds.

@Jimmster, I am not sure what kind of VPS you have and what the type of hypervisor is, but you should have a look at that: the rebooting process is somewhat strange, in the sense that your system is up and running after reboot, but somehow "locks" specific processes, such as processes allowing mysql to start directly.

Can it be the case that your VPS is on a system with KVM overcommitment?

Or, did you ever check whether a reboot actually closes down processes properly? After all, it can be the case that your reboot is essentially a restart, instead of a stop/start sequence.

If you ask me, the socket of the new mysqld cannot be created after a reboot, which often is related to the previously running mysqld (that either has not been shutdown properly or is still active during some short period of time, which is only possible in the case of some resource sharing, i.e. resources from the host).

Anyway, it is a rare situation and it surprises me that this situation occurs.

In short, have a good look at what happens and/or is configured to happen on a reboot.

Finally, it is very unlikely that your issue is related to the issue, discussed in the stackoverflow article.

Keep me posted, I am rather intrigued!

Regards......

 

[Jimmster]

Thanks for your reply! Unfortunately, I don't have the information you're asking for, as the VPS are rented from the German company Host Europe. Does that tell you something already? Or do you have specific questions I can relay to Host Europe directly to find out everything that could help this?

Also, is there something in specific that makes you think the socket can not be created? When googling this issue up and down, I got the impression that socket problems are quite obviously stated in the error_log, which doesn't seem to be happening in our error_log.

 

[trialotto]

@Jimmster

You asked

Also, is there something in specific that makes you think the socket can not be created?

and there are some indications that, given that

1 - some issues occur with the start/stop or restart of processes,
2 - the start upon reboot has a "hickup" at the socket creation time and/or the event(s) loading time, as follows from your initial output,
3 - zero events are or should be loaded when starting the daemon,

a socket related issue is present.

Actually, the reboot is a nice "test", given the facts that processes should be stopped and/or memory should be flushed, implying that startup problems are often related to

a - processes are not stopped properly: even with a "software reboot", this will not (often) occur.
b - memory not being flushed: this can occur in the case of a "software reboot" on a host machine that has some form of memory sharing (overcommitment for instance) configured.
c - sockets are not established: a specific .sock file cannot be created for a process started upon reboot.

It often is insightful to do a "hardware reboot", since this can exclude scenario´s a and b: if a "hardware reboot" still fails to start mysqld, then a socket related issue is very, very likely.

Any bugs related to MySQL server are (probably) out of the question, since any start, stop or restart will be succesful (as you demonstrated already).

I have had a look at the (quite nice) startup scripts for Plesk and there are no strange things in the contents of these scripts.

However, if I am not mistaken, the startup scripts involve a check for an existing socket for the mysqld process.

The only problems with this "socket check" are that it

i) does a check for ALL existing sockets, that are commonly used: this implies that a second mysql instance can also be running after a reboot.

ii) does "set the socket" (i.e. export the unix port) to the socket that is checked, for each socket that exists: this implies that a specific mysql instance, that has not been closed down properly, will try to establish the connection via the socket of a "previous" mysql instance.

The conflicts that can be the endresult are therefore:

- a potential continuation of 2 mysql instances after reboot,
- a potential situation in which 2 mysql instances are trying to use one and the same socket,
- a potential situation in which a specific mysql instance is trying to use a socket of a process that has not been shutdown properly,

and, in essence, this boils down to the issue that a second mysql instance (read: a previous OR a simultaneous instance) is not shutdown.

In fact, Plesk has a default my.cnf (i.e. the mysql configuration file) that should only have and therefore allow a "mysqld_safe" instance, i.e. one mysqld instance.

I have done some testing with Ubuntu based Plesk instances and the issue of mysql not starting does not occur, if the my.cnf only defines one mysqld (i.e. mysqld_safe).

In conclusion, I would recommend you to have a look at your my.cnf file.

It can be the case that you have some additional definitions in the my.cnf file, that should not be there by default.

Can you provide some feedback, if you have a deviating my.cnf file?

Furthermore, if your my.cnf is "standard", can you run the commands (in chronological order)

- service psa stop
- service psa start
- ps aux | grep mysql

and check whether the ps command only yields one mysqld instance. If this is the case, try to reboot again and check whether the issue persists.

Regards

 

[Jimmster]

Thank you very much for your very illuminating reply!

Unfortunately, we are not all the way there yet: When testing this a few weeks ago, I already came across the problem of having multiple MySQL daemons running. That's why I already checked that this is not the problem: my.cnf does only contain one section for mysqld_safe. Also, ps aux | grep mysql yields only one mysqld and one mysqld_safe.

Is there something else that I could check?

 

[trialotto]

@Jimmster,

To be honest, there are some things that can be checked, but that would certainly result in very dirty work-arounds for your problem.

It seems to be the case that your problem has less to do with Plesk related scripts and more with init scripts and/or (re-)boot related scripts and timing thereof.

I would certainly try to run a "service psa stop" and executing a reboot afterwards: if the problem persists, then it is very likely that the "boot settings of the VPS" are out of order.

Note that, if you are doing this test, you should have a look at (after executing the "service psa stop" command and before the reboot command)

- the presence of the .sock file (and recheck after a couple of minutes)
- the status of the mysql instance (down or running)
- the presence of active mysqld processes (do a ps aux | grep mysqld)

and all of these "checks" should be performed.

It is important to note that you have to remove the 'sleep 30 && /etc/init.d/mysql restart' or similar lines, if you still have them present in your /etc/rc.local file.

After all, when doing some tests on the mysqld behaviour, the presence of 'sleep 30 && /etc/init.d/mysql restart' can actually cause the problem you are dealing with.

It is also quite convenient that often (but not always) a linux reboot from the command line differs from a software reboot via the control panel of the hosting provider.

If there is no difference between a "linux reboot" and a "control panel reboot", well, that is strange (and a bad omen).

If there is a difference between a "linux reboot" and a "control panel reboot", if often involves a difference that is the result of specific boot settings of the VPS.

In short, a "linux reboot" can (often) be used to execute some tests without interference of boot settings of the VPS, implying that you can (primitively) test for "out of order" boot settings due to some particular configuration of the VPS and underlying hypervisor settings.

In general, if the boot settings are out of order, you can do barely anything, except for contacting support of your hosting provider and ask them to resolve the issue (if they can).

Hope the above helps....

Regards

PS Really make sure that the customizations in /etc/rc.local are removed!

 

[Jimmster]

Very interesting reply again, thanks trialotto!

The customizations in /etc/rc.local are long gone. I just had them in there for one test.
The last time I was testing this issue, I actually always rebooted via the control panel of my hosting provider. Very interesting to think about the differences to issueing a 'reboot' via SSH.

I will do all the tests and checks you listed as soon as I can. Unfortunately, I can't just reboot these servers in the middle of the day, but I hope I'll be able to get around to this on the weekend!